debugging on stdout
mike
I have a perl script which talks to mplayer and stepping through it in
emacs' cperl-db it executes flawlessly; but running "./script video" it
does everything except one crucial step and I'm having a hard time
visualizing what could be the matter.
so is there a way to invoke the perl script such as can be done in bash or
csh (csh -xvf ./script.csh) which would allow me to see what's going on at
full speed?
thanks.
--
Tim Greer
You're going to need to post the relevant code, and provide some details
about the issue, instead of just posting an example of how you run it.
Also, what is the crucial step it's missing? What are you trying to
view/see what's "going on" (what is that?)
--
Tim Greer, CEO/Founder/CTO, BurlyHost.com, Inc.
Shared Hosting, Reseller Hosting, Dedicated & Semi-Dedicated servers
and Custom Hosting. 24/7 support, 30 day guarantee, secure servers.
Industry's most experienced staff! -- Web Hosting With Muscle!
Ben Morrow
mike
On Tue Feb 24, I was peacefully napping until Tim Greer said:
> mike wrote:
>
> >
> > I have a perl script which talks to mplayer and stepping through it in
> > emacs' cperl-db it executes flawlessly; but running "./script video"
> > it does everything except one crucial step and I'm having a hard time
> > visualizing what could be the matter.
> >
> > so is there a way to invoke the perl script such as can be done in
> > bash or csh (csh -xvf ./script.csh) which would allow me to see what's
> > going on at full speed?
> >
> > thanks.
> >
>
> You're going to need to post the relevant code, and provide some details
> about the issue, instead of just posting an example of how you run it.
> Also, what is the crucial step it's missing? What are you trying to
> view/see what's "going on" (what is that?)
$video = $ARGV[0];
$vid_resume = vid_position_file($video);
if (-e $vid_resume) {
$pid = open2(*reader, *writer, "gmplayer-bin -slave -quiet -ss `cat $vid_resume` $video");
$vid_resume returns a valid filename (with valid contents, in this case
"255.1" and nothing more) and its contents are meant to skip to a specific
position in the video when it starts playing.
a) in emacs cperl-db buffer, I load "./script.pl /path/to/video/x" then
"n" line by line and it kicks off mplayer running $video and advanced to
position $vid_resume (iow everything as I expect).
b) "% ./script.pl /path/to/video/x" brings up mplayer stopped, with $video
loaded (I hit "play" and the expected video is there and running, and
incidentally starts at time 0).
so two scenarios, same script, same video, same $vid_resume file but
different outcomes.
I looked through some of what Ben refers to but tbh I'm going in circles
and aren't getting any closer to understanding what's the matter.
ideally (in b)) I'd like to see what mplayer is saying (I removed "-quiet"
but ostensibly because of how it's being run its output seems lost since I
don't see it in the terminal window).
--
Ben Morrow
Quoth mike <no...@nks.org>:
>
> On Tue Feb 24, I was peacefully napping until Tim Greer said:
>
> > mike wrote:
> > >
> > > I have a perl script which talks to mplayer and stepping through it in
> > > emacs' cperl-db it executes flawlessly; but running "./script video"
> > > it does everything except one crucial step and I'm having a hard time
> > > visualizing what could be the matter.
> > >
> > > so is there a way to invoke the perl script such as can be done in
> > > bash or csh (csh -xvf ./script.csh) which would allow me to see what's
> > > going on at full speed?
> >
> > about the issue, instead of just posting an example of how you run it.
> > Also, what is the crucial step it's missing? What are you trying to
> > view/see what's "going on" (what is that?)
>
>
> $video = $ARGV[0];
> $vid_resume = vid_position_file($video);
> if (-e $vid_resume) {
> $pid = open2(*reader, *writer, "gmplayer-bin -slave -quiet -ss
> `cat $vid_resume` $video");
First, why are you using cat(1)? Perl is perfectly capable of reading a
file: see the File::Slurp module for a trivial way to do it. If
vid_position_file is creating the temporary file, I'd change it so it
returns the resume position as a string instead.
You are not checking the return value of open2, and you are apparently
not using strictures. You need to fix both of these if you expect to get
much useful help here.
I would also recommend avoiding global filehandles. Due to an
unfortunate design decision this is not terribly easy with IPC::Open2:
you need something like
use Symbol qw/geniosym/;
my ($READER, $WRITER) = (geniosym, geniosym);
my $pid = open2($READER, $WRITER, "...") or die "...";
I would avoid using Open2 directly in favour of IPC::Run, which has a
much cleaner interface and is more portable to systems like Win32.
> $vid_resume returns a valid filename (with valid contents, in this case
> "255.1" and nothing more) and its contents are meant to skip to a specific
> position in the video when it starts playing.
>
> a) in emacs cperl-db buffer, I load "./script.pl /path/to/video/x" then
> "n" line by line and it kicks off mplayer running $video and advanced to
> position $vid_resume (iow everything as I expect).
>
> b) "% ./script.pl /path/to/video/x" brings up mplayer stopped, with $video
> loaded (I hit "play" and the expected video is there and running, and
> incidentally starts at time 0).
This feels like a race condition of some sort, but I can't see where it
might be. What does your script do next? Can you use ps to examine what
arguments actually get passed to the gmplayer-bin process? What happens
if you take the temporary file out of the equation and just supply a
literal string to mplayer? What happens if you use ordinary mplayer
rather than gmplayer-bin? Can you give us a minimal *complete* script
that reliably fails on your machine? Is there anything else different
between the two environments: different environment vars, different
shells, &c.? Does the program still succeed if you single-step in the
debugger (run it with perl -d) rather than using Emacs?
> ideally (in b)) I'd like to see what mplayer is saying (I removed "-quiet"
> but ostensibly because of how it's being run its output seems lost since I
> don't see it in the terminal window).
Most of mplayer's verbose output goes to stdout rather than stderr,
which means it will show up on the *writer handle. You could try adding
something like '| tee /dev/stderr' or '| tee /dev/tty' to the
commandline as a crude way of getting some output. You could also try
using a one-way piped open or a simple system rather than open2, to see
if that makes a difference.
Ben
mike
thanks for the help and suggestions.
> This feels like a race condition of some sort, but I can't see where it
> might be. What does your script do next? Can you use ps to examine what
> arguments actually get passed to the gmplayer-bin process? What happens
> if you take the temporary file out of the equation and just supply a
> literal string to mplayer? What happens if you use ordinary mplayer
> rather than gmplayer-bin? Can you give us a minimal *complete* script
> that reliably fails on your machine? Is there anything else different
> between the two environments: different environment vars, different
> shells, &c.? Does the program still succeed if you single-step in the
> debugger (run it with perl -d) rather than using Emacs?
$video = $ARGV[0];
$vid_resume = vid_position_file($video);
if (-e $vid_resume) {
$pid = open2(*reader, *writer, "gmplayer-bin -slave -quiet -ss `cat $vid_resume` $video") || die "Unable to open $1: $!";
--> what follows:
unlink $vid_resume;
}
# else {
# $pid = open2(*reader, *writer, "gmplayer-bin -slave -quiet $video") || die "Unable to open $1: $!";
# }
# new position will be recorded here:
open(POS_FH, "> $vid_resume") || die "Unable to open $1: $!";
}
## otherwise bring up mplayer unloaded:
#else {
# $pid = open2(*reader, *writer, 'gmplayer-bin -slave -quiet') || die "Unable to open $1: $!";
#}
clear_mplayer();
.
.
.
sub clear_mplayer {
# ps'ing too fast is missing the "L" ("pages locked in memory"):
sleep 5;
my $video_pid = $pid; $video_pid++;
my $running = `/bin/ps ax`;
if ($running =~ /$video_pid\s+pts\/[0-9]+\s+(S|R)?L/) {
writer->autoflush();
while (! /Starting playback/) {
$_ = <reader>;
}
return 1;
}
else {
return 0;
}
}
-------------
1. once that sequence finishes the prog goes onto to other tasks and
everything from this point on works as expected
2. the rest of the if/else is only commented while I've been looking at
this problem (ensure either invocation uses the same one)
3. the problem isn't unlink - I ran with it commented and no change
4. I don't know what "writer->autoflush();" does but it was in the code I
lifted from a web page so left it in (in or out doesn't seem to impact
this -ss problem)
5. mplayer whether started with a vid arg or not appears to start with two
consecutive pids where the second indicates that a video is loaded or
running - to guarantee I can find mplayer's responses to my queries I
throw away everything up to "Starting..."; to guarantee I'll find
"Starting..." I don't look for it until the "L" in ps shows up.
-------------
wrt some of your easier suggestions:
- I tried plain mplayer, replacing cat with the pathname, added path to
g/mplayer bins and at best the video comes up running but ostensibly
ignoring -ss and at worst just comes up with video loaded but not
running.
- I ordinarily use csh but tried bash and sh, same behavior.
- I did notice a couple times in the past couple days that a specific
invocation repeated would seem to start ok (don't recall if it was using
-ss) and at other times came up with the video stopped; I thought "that
can't be, I must've not been paying attn to how I started it."
so there must be something to this race condition thing; I don't know
anything about the open2 alternative you mentioned but will see if I can
manage using that instead and see what happens.
--
mike
I found the problem if you want to skip reading the rest.
that "clear_mplayer()" is not supposed to be by itself (it's not needed
for the else in if/else since there's no "Starting..." to chk for in
unloaded mplayer).
unlink $vid_resume;
}
# else {
# $pid = open2(*reader, *writer, "gmplayer-bin -slave -quiet $video") || die "Unable to open $1: $!";
# }
--> clear_mplayer();
# new position will be recorded here:
open(POS_FH, "> $vid_resume") || die "Unable to open $1: $!";
}
--> is where it was originally.
but in messing around I had those lines reversed:
# new position will be recorded here:
open(POS_FH, "> $vid_resume") || die "Unable to open $1: $!";
--> clear_mplayer();
for some reason 'open POS_FH' appears to be overwriting $vid_resume (with
its -ss value), even though it follows two instructions - unlink (which
isn't causing the problem because I tried it commented) and the cat in
open2. so open2(... -ss ) is reading an empty file.
when I put the lines back where they were in an earlier incarnation, the
sleep in clear_mplayer ostensibly ensured 'open POS_FH' hadn't written a
new $vid_resume before cat read from it. and the script runs from cmd
line same as it does stepping through in cperl-db.
thanks - I probably never would've noticed this without posting.
--
Ben Morrow
Quoth mike <no...@nks.org>:
>
> > This feels like a race condition of some sort, but I can't see where it
> > might be. What does your script do next? Can you use ps to examine what
> > arguments actually get passed to the gmplayer-bin process? What happens
> > if you take the temporary file out of the equation and just supply a
> > literal string to mplayer? What happens if you use ordinary mplayer
> > rather than gmplayer-bin? Can you give us a minimal *complete* script
> > that reliably fails on your machine? Is there anything else different
> > between the two environments: different environment vars, different
> > shells, &c.? Does the program still succeed if you single-step in the
> > debugger (run it with perl -d) rather than using Emacs?
>
>
> $video = $ARGV[0];
> $vid_resume = vid_position_file($video);
> if (-e $vid_resume) {
> $pid = open2(*reader, *writer, "gmplayer-bin -slave -quiet -ss
> `cat $vid_resume` $video") || die "Unable to open $1: $!";
>
> --> what follows:
>
> unlink $vid_resume;
> }
> # else {
> # $pid = open2(*reader, *writer, "gmplayer-bin -slave -quiet
> $video") || die "Unable to open $1: $!";
> # }
> # new position will be recorded here:
> open(POS_FH, "> $vid_resume") || die "Unable to open $1: $!";
I believe the problem is here. What is probably happening is
open2 starts the shell, which starts successfully, and returns;
perl moves on to unlink $vid_resume;
if you comment out the unlink, perl moves on to delete the
contents of $vid_resume using open ">";
the shell runs cat;
cat opens $vid_resume, which by this point either doesn't exist or
is empty;
mplayer is run with a blank -ss option.
When you are single-stepping, the shell has a chance to run cat and then
mplayer before the file disappears. Can you confirm that when mplayer
fails to start correctly, ps shows the wrong command line?
I will ask you again: why on earth are you keeping the offset in a file
at all? Just keep it in a variable.
Also, while I'm here:
Don't use global filehandles.
Use three-arg open.
$1 doesn't hold anything useful at this point.
Be consistent about your use of parentheses.
&& and || are booleans, 'and' and 'or' are for flow control.
open(my $POS_FH, ">", $vid_resume)
or die("Unable to open '$vid_resume': $!");
(I would omit both sets of parens, but that's a matter of style so
what's important is you pick a style and stick to it.)
> 3. the problem isn't unlink - I ran with it commented and no change
Right, but in any case you are immediately emptying the file, which has
the same effect.
> 4. I don't know what "writer->autoflush();" does but it was in the code I
> lifted from a web page so left it in (in or out doesn't seem to impact
> this -ss problem)
See perldoc IO::Handle. It's a *really* bad idea to include bits of code
you don't understand. If you can't find out what they do, leave them out
and find some way to do what you need that you do understand.
If you are going to use bareword filehandles, I would *strongly*
recommend making them all uppercase. The rules for deciding whether
'writer' there is a filehandle, a package name or a sub call kind of
make my skin crawl, so it's much safer to keep filehandles uppercase,
package names mixed case and sub names lowercase.
> 5. mplayer whether started with a vid arg or not appears to start with two
> consecutive pids where the second indicates that a video is loaded or
> running - to guarantee I can find mplayer's responses to my queries I
> throw away everything up to "Starting..."; to guarantee I'll find
> "Starting..." I don't look for it until the "L" in ps shows up.
You shouldn't need to mess about with ps: just read from mplayer's
output until it gets to "Starting...".
> - I tried plain mplayer, replacing cat with the pathname,
I didn't say 'replace cat with the pathname' I said 'replace cat with
the contents of the file'. That is:
use File::Slurp qw/slurp/;
my $vid_resume_contents = slurp $vid_resume;
my $pid = open2(..., "mplayer ... -ss $vid_resume_contents ...")
...;
or read the file yourself if you don't want to use File::Slurp. I also
said it would be better to rework vid_position_file so that it returns a
string directly rather than a filename.
> - I did notice a couple times in the past couple days that a specific
> invocation repeated would seem to start ok (don't recall if it was using
> -ss) and at other times came up with the video stopped; I thought "that
> can't be, I must've not been paying attn to how I started it."
That's what race conditions do. Sometimes the scheduling happens just so
and the shell gets to read the file before perl kills it.
Ben
Ben Morrow
Quoth mike <no...@nks.org>:
>
> I found the problem if you want to skip reading the rest.
Heh... I just posted a reply with the same answer...
> for some reason 'open POS_FH' appears to be overwriting $vid_resume (with
> its -ss value), even though it follows two instructions - unlink (which
> isn't causing the problem because I tried it commented) and the cat in
> open2. so open2(... -ss ) is reading an empty file.
open2 runs a command in the background (that's the point) so the perl
program will continue before the shell has even started parsing the
command line. The root of your problem here is that you're using four
processes (perl, the shell, cat, and mplayer) where you only needed two.
> when I put the lines back where they were in an earlier incarnation, the
> sleep in clear_mplayer ostensibly ensured 'open POS_FH' hadn't written a
> new $vid_resume before cat read from it. and the script runs from cmd
> line same as it does stepping through in cperl-db.
Strictly speaking this isn't safe. Even a five-second sleep isn't enough
to be certain cat has finished reading the file. Just get the value out
yourself beforehand.
Ben
Tim Greer
> when I put the lines back where they were in an earlier incarnation,
> the sleep in clear_mplayer ostensibly ensured 'open POS_FH' hadn't
> written a new $vid_resume before cat read from it. and the script
> runs from cmd line same as it does stepping through in cperl-db.
Sorry I didn't read the entire thread, but I'm curious, what is the
specific purpose of sleep? Do you want to actually wait for something
specific, such as allowing time for something to complete (hopefully),
or for other reasons? If you want to ensure something completed, I'd
check the position against the size of the file (or data) remaining and
try and track how much has been read/output, and once it's complete
(once it's sent all of its data), then close/clear. If you mean
something else, then I might just have to read the thread to make a
better suggestion (even for that previous one, really).
Tim McDaniel
Ben Morrow <b...@morrow.me.uk> wrote:
>I would avoid using Open2 directly in favour of IPC::Run, which has a
>much cleaner interface and is more portable to systems like Win32.
One review says <http://cpanratings.perl.org/dist/IPC-Run>
In words of the author of IPC::Run
> I would personally recommend IPC::Cmd rather than IPC::Run right now.
> It seems more stable and well-supported.
> It's not obsolete -- still works for many people, even with test
> failures -- but IPC::Cmd seems to be more actively maintained.
My review:
It works well and is easy to use but I do not like its interface.
Roberto - 2007-01-31 06:48:19
Is there a reason to go for IPC::Run instead of IPC::Cmd?
--
Tim McDaniel, tm...@panix.com
Ben Morrow
Quoth tm...@panix.com:
> In article <ldhe76-...@osiris.mauzo.dyndns.org>,
> Ben Morrow <b...@morrow.me.uk> wrote:
> >I would avoid using Open2 directly in favour of IPC::Run, which has a
> >much cleaner interface and is more portable to systems like Win32.
>
> One review says <http://cpanratings.perl.org/dist/IPC-Run>
>
> In words of the author of IPC::Run
> > I would personally recommend IPC::Cmd rather than IPC::Run right now.
> > It seems more stable and well-supported.
>
IPC::Cmd doesn't do the same thing? In particular, it doesn't have
open2-like functionality.
Ben
mike
I appreciate your time and great perl tips, thanks.
> I will ask you again: why on earth are you keeping the offset in a file
> at all? Just keep it in a variable.
unless you mean keep it in a var only while the script is running, I have
stacks of instructional videos and using respectively named text files
allows me to have mplayer automatically seek to the position I last left
off at when I reload a vid that has such a file (and obv if it doesn't my
script creates one for it). there's a 15s loop which repeatedly updates
that file w/current vid position while the video remains loaded or
running.
to give credit, I got the idea from a very handy mplayer-resume php script
where I learned one can 'talk' to mplayer. but after using his script
briefly felt it was too limited so made my own.
> > 5. mplayer whether started with a vid arg or not appears to start with two
> > consecutive pids where the second indicates that a video is loaded or
> > running - to guarantee I can find mplayer's responses to my queries I
> > throw away everything up to "Starting..."; to guarantee I'll find
> > "Starting..." I don't look for it until the "L" in ps shows up.
>
> You shouldn't need to mess about with ps: just read from mplayer's
> output until it gets to "Starting...".
obv I'm just sort of fumbling through this but how I have it now is, my
script needs both video filename and current time position and to get
either of them (at various places) I do:
$video = vid_filename_query();
and/or
print SEEK_FH vid_position_query();
# -------------------
# ask mplayer current vid's filename and return it (never includes its path):
sub vid_filename_query {
writer->print("pausing_keep get_file_name\n");
$_ = <reader>;
/ANS_FILENAME=\'(.*)\'/;
return $1;
}
# ask mplayer where current vid is positioned (return val is "seconds"):
sub vid_position_query {
writer->print("pausing_keep get_time_pos\n");
$_ = <reader>;
/ANS_TIME_POSITION=(.*)/;
return $1;
}
# -------------------
"pages locked in memory" for mplayer's pid (or "Starting..." for that
matter) appear only once a video is loaded. until that happens mplayer
ignores or fails to respond to the specific things I ask it (obv "get_*"
would be meaningless if no video is loaded; and mplayer may be accepting a
meaningless instruction and simply dropping it, I don't know).
but as you can see by my writer/<reader> combos, if I try one when no
video is loaded, and mplayer is not going to respond, then <reader> hangs
waiting for something that isn't coming.
so I test for ps "L" (coincidental to "Starting...") to inform my script
whether or not mplayer is going to respond before sending it an
instruction (and since ps "L" is valid whether vid is running or just
loaded but stopped, I only need to do this pid chk once/video).
so whether or not I just use <reader> to scan up to "Starting...", I can't
know it won't hang not finding it if I don't first test for ps "L". imm :)
--
Ben Morrow
Quoth mike <no...@nks.org>:
>
> I appreciate your time and great perl tips, thanks.
>
> > I will ask you again: why on earth are you keeping the offset in a file
> > at all? Just keep it in a variable.
>
> unless you mean keep it in a var only while the script is running, I have
> stacks of instructional videos and using respectively named text files
> allows me to have mplayer automatically seek to the position I last left
> off at when I reload a vid that has such a file (and obv if it doesn't my
> script creates one for it). there's a 15s loop which repeatedly updates
> that file w/current vid position while the video remains loaded or
> running.
OK, that's a good reason. You definitely want to read the contents of
the file in Perl before you try to overwrite it, though.
> > > 5. mplayer whether started with a vid arg or not appears to start with two
> > > consecutive pids where the second indicates that a video is loaded or
> > > running - to guarantee I can find mplayer's responses to my queries I
> > > throw away everything up to "Starting..."; to guarantee I'll find
> > > "Starting..." I don't look for it until the "L" in ps shows up.
> >
> > You shouldn't need to mess about with ps: just read from mplayer's
> > output until it gets to "Starting...".
>
> obv I'm just sort of fumbling through this but how I have it now is, my
> script needs both video filename and current time position and to get
> either of them (at various places) I do:
>
> $video = vid_filename_query();
> and/or
> print SEEK_FH vid_position_query();
>
>
> # -------------------
> # ask mplayer current vid's filename and return it (never includes its path):
> sub vid_filename_query {
> writer->print("pausing_keep get_file_name\n");
> $_ = <reader>;
> /ANS_FILENAME=\'(.*)\'/;
This isn't safe. Firstly you are not checking the match succeeded;
secondly, if it failed you will need to read another line and try again.
It may not have happened to you yet, but mplayer can return other output
before the output you want (status updates, warnings about dropped
frames, &c.) and you want to be able to ignore it and look for the
answer to your question; you also probably want to time out if mplayer
is not responding. I would recommend you look at either Expect.pm or
IPC::Run.
> return $1;
$1 only contains what you think it does if the match succeeded.
Generally it's better to avoid the $N variables and assign the match
result instead:
my ($filename) = /ANS_FILENAME='(.*)'/;
return $filename;
> "pages locked in memory" for mplayer's pid (or "Starting..." for that
> matter) appear only once a video is loaded. until that happens mplayer
> ignores or fails to respond to the specific things I ask it (obv "get_*"
> would be meaningless if no video is loaded; and mplayer may be accepting a
> meaningless instruction and simply dropping it, I don't know).
That's not what I see. With mplayer 1.0rc2-4.2.1 I get
~% echo "get_time_pos" | mplayer -slave -quiet -vo null -ss 250 vid_file
MPlayer 1.0rc2-4.2.1 (C) 2000-2007 MPlayer Team
CPU: Intel(R) Pentium(R) 4 CPU 1500MHz (Family: 15, Model: 0, Stepping: 10)
<snip>
Starting playback...
VDec: vo config request - 640 x 360 (preferred colorspace: Planar YV12)
VDec: using Planar YV12 as output csp (no 0)
Movie-Aspect is 1.78:1 - prescaling to correct movie aspect.
VO: [null] 640x360 => 640x360 Planar YV12 [fs] [zoom]
ANS_TIME_POSITION=252.4
^C
MPlayer interrupted by signal 2 in module: sleep_timer
~%
so even if the command is sent before mplayer starts I still get a
response, there's just a whole lot of other stuff in between. Expect can
handle this extremely well (including setting timeouts after which it
will give up).
> so I test for ps "L" (coincidental to "Starting...") to inform my script
> whether or not mplayer is going to respond before sending it an
> instruction (and since ps "L" is valid whether vid is running or just
> loaded but stopped, I only need to do this pid chk once/video).
It seems an extremely crude (not to mention fragile) way of checking
mplayer has finished initializing. For example, on my system mplayer
never goes into the RL state, presumably because it doesn't have
permission to lock itself into memory.
Ben