in reply to Calling strace from a perl program

I think this is a quirk of strace when invoking it on an already running process. strace relies on the kernel to be notified when a process enters or leaves a syscall. If you run strace on a process that is already in a system call, it may not produce any output until the process is interrupted or returns from the system call.

To implement your hang finder, you might have to use some other mechanism to indicate that a program is attempting to obtain a lock. For instance, one method is to change $0 to reflect the state of the program. On many OS's this will be observable via the ps command, e.g.:

sub get_lock { local($0) = "(acquiring lock)"; flock(...); # returning restores previous value of $0 }

Replies are listed 'Best First'.
Re^2: Calling strace from a perl program
by jason_s (Acolyte) on Mar 11, 2008 at 23:59 UTC
    Unfortunately, the program I need to trace locking on is a closed-source binary, so I can't change it . . .

    BUT, I found that /proc/locks has all the information I needed -- it shows both locks, and processes blocking while trying to obtain a lock. It was much easier to read through /proc/locks to get what I need than to try and control strace.
Re^2: Calling strace from a perl program
by kyle (Abbot) on Mar 11, 2008 at 21:27 UTC

    Interesting. I tried this on my Linux system, and it was not at all as I expected. Long story short:

    • Different behavior when using ps vs. ps ww!
    • ps was not affected by the change to $0 at all.
    • ps ww did see the change, but using local didn't unmake the change as I would have expected.
    sub ps_line { my $ps = shift; print join ' ', "$ps:\t", @{ (grep { $_->[0] == $$ } map { [ split ] } `$ps | tail -n +2`)[0] }; print "\n"; } print "\$0 = $0\n"; ps_line( 'ps' ); ps_line( 'ps ww' ); { local( $0 ) = 'nyuck' x 3; print "\$0 = $0\n"; ps_line( 'ps' ); ps_line( 'ps ww' ); } print "\$0 = $0\n"; ps_line( 'ps' ); ps_line( 'ps ww' ); __END__ $0 = ./perlmonks.pl ps: 875 pts/1 00:00:00 perl ps ww: 875 pts/1 S+ 0:00 perl ./perlmonks.pl $0 = nyucknyucknyuck ps: 875 pts/1 00:00:00 perl ps ww: 875 pts/1 S+ 0:00 nyucknyucknyuck $0 = ./perlmonks.pl ps: 875 pts/1 00:00:00 perl ps ww: 875 pts/1 S+ 0:00 ./perlmonks.pl
      That's very odd. I tried it using this test program:
      #!/usr/bin/perl print "my pid = $$\n"; get_lock(); print "enter return again:"; my $x = <STDIN>; sub get_lock { local($0) = "(acquiring lock)"; print "enter return:"; my $x = <STDIN>; }

      In another terminal I get:

      $ /bin/ps 27940 PID TTY STAT TIME COMMAND 27940 pts/0 S+ 0:00 (acquiring lock) $ /bin/ps 27940 PID TTY STAT TIME COMMAND 27940 pts/0 S+ 0:00 ./d0

      I'm using Ubuntu 7.10.

      Update: Ok, it does seem that you will lose the initial 'perl' from the COMMAND field when $0 is restored, but the script name should still remain. Don't know why that happens, and I also can explain yet your 'ww' output.