2

I have a POE Perl program forking children.

The children it is forking do logging and interactive telnets into remote devices. POE uses STDOUT to return output back up to the parent process but for some reason it's getting lost (not going to screen or to any files).

I'm theorising that this is because STDOUT is being redirected somewhere - I need to ascertain where.

I have used (-t STDOUT) to identify that the STDOUT of the child is not a TTY.

I have also reset the STDOUT of the child to be that of the parent before the child was called - but this method seems to avoid POE's event handlers and it just dumps the output to parents STDOUT.

Q) How do I identify what the current STDOUT points at so I can find where my data is going

Thanks

Simon

brian d foy
  • 129,424
  • 31
  • 207
  • 592
SimonT
  • 31
  • 4
  • Can you please provide forking and output redirecting code? – Ivan Nevostruev Nov 06 '09 at 20:58
  • We need more information. Are you using POE::Wheel::Run? Is the subprocess Perl? Does the subprocess print to STDOUT when it is running normally, not as a child of your POE app? – jrockway Nov 07 '09 at 13:08
  • Q)Are you using POE::Wheel::Run? A)Yes Q) Is the subprocess Perl? A) Yes Q) Does the subprocess print to STDOUT when it is running normally, not as a child of your POE app? A) Yes/No and this is what im trying to determine. The subprocess calls an object which utilises Expect.pm and also Error.pm and something in there is messing with STDOUT. If i could tell where STDOUT currently is then i might have a chance at altering it. All i know so far is that once the child gets forked STDOUT is not a TTY but before it gets spawned it is a TTY – SimonT Nov 09 '09 at 09:06

4 Answers4

1

Would fileno help in this situation? If a child is closing and reopening STDOUT, then fileno(STDOUT) would have a different value in the child than in the parent.

$ perldoc -f fileno
   fileno FILEHANDLE
           Returns the file descriptor for a filehandle, or undefined if
           the filehandle is not open.  This is mainly useful for
           constructing bitmaps for "select" and low-level POSIX tty-
           handling operations.  If FILEHANDLE is an expression, the value
           is taken as an indirect filehandle, generally its name.

           You can use this to find out whether two handles refer to the
           same underlying descriptor:

               if (fileno(THIS) == fileno(THAT)) {
                   print "THIS and THAT are dups\n";
               }

           (Filehandles connected to memory objects via new features of
           "open" may return undefined even though they are open.)
mob
  • 117,087
  • 18
  • 149
  • 283
  • Assuming you're on one of the supported UNIX dialects, you might try combining that with lsof (man lsof for more info). – bish Nov 07 '09 at 02:13
  • my ($dev,$ino,$mode,$nlink,$uid,$gid,$rdev,$size, $atime,$mtime,$ctime,$blksize,$blocks) = stat(STDOUT) or die "No STDOUT $!"; my $output1 = system("/usr/sbin/lsof -p $$ | grep $ino >/tmp/jsuh$$"); COMMAND PID USER FD TYPE DEVICE SIZE NODE NAME new_batch 31616 sdu 0u unix 0x00000100376a7380 9951954 socket new_batch 31616 sdu 1u unix 0x00000100376a7380 9951954 socket new_batch 31616 sdu 2u unix 0x0000010007774680 9951957 socket So this tells me that STDOUT is connected to a Socket? – SimonT Nov 09 '09 at 10:13
  • This is possible since the forked program spawns telnet sessions - so it could still be connected to a port on an ip on a remote server via a socket - but the first thing i checked was that the object that handles that was destroyed. – SimonT Nov 09 '09 at 10:14
  • Ignore that last post - havent spawned the connection at that point - am looking at the object before it creates the remote connection. – SimonT Nov 09 '09 at 10:28
  • Does this give you a different result? my $fd = fileno(STDOUT); my $output1 = system("/usr/sbin/lsof -a -p $$ -d $fd >/tmp/jsuh$$"); – bish Nov 09 '09 at 15:12
  • With the extra -d switch gives us a list of the TTY's bash 17289 sdu 1u CHR 136,0 2 /dev/pts/0 bash 17320 sdu 1u CHR 136,1 3 /dev/pts/1 bash 17363 sdu 1u CHR 136,3 5 /dev/pts/3 bash 30667 sdu 1u CHR 136,4 6 /dev/pts/4 – SimonT Nov 09 '09 at 16:58
  • References other sdu sessions (sdu is the executing user) – SimonT Nov 09 '09 at 17:00
  • Closed those sessions downs. Ran it again. LSOF output now doesnt contain the entries. No change in communication between child and parent. – SimonT Nov 09 '09 at 17:09
  • Did you remember to add the -a switch? By default, lsof will OR the options you give it rather than AND them. It looks like this happened since your results appear to contain multiple processes. If that doesn't help, I'll stop heading you down this path since I'm starting to feel like I'm having you chase ghosts. – bish Nov 09 '09 at 18:03
  • I dont think it will help. Bottom line the child is using a socket connection to the parent to send its STDOUT up. My next question then becomes how can i tell whether this "socket printing" mechanism is working. Had a look on the internet and couldnt see any mechanism for looking at the activity on a socket connection. – SimonT Nov 09 '09 at 21:20
  • Found the problem. When i was using a StdoutFilter => POE::Filter::Reference->new() it was failing to recognise output from the child process. When i removed it - it picked it up. I now know a heck of lot more about POE debug modes and what all the moving parts do. Cheers for the support whilst i went up the learning curve! – SimonT Nov 09 '09 at 23:02
  • Glad you were able to find it! Good to see it helped you learn a lot more about POE too. – bish Nov 10 '09 at 04:35
1

If your forked children are Perl programs too you can "select STDOUT" and set $| to mark it unbuffered right before any logging happens.

Murali VP
  • 6,198
  • 4
  • 28
  • 36
1

This was down to the POE::Filter::Reference StdOut Handler being sent output by the child process that was not in the format it was expecting.

Removed the filter - could then see what it was being sent and this enabled me to rectify the issue.

The issue was the child process was spewing the contents of its subprocesses STDOUT back along the socket connection to the StdOut Handler.

Simon

SimonT
  • 31
  • 4
0

Are you certain this isn't a buffering issue? I'm not familiar with POE so I don't know how you'd investigate or correct that, but I suspect it's worth checking, at least.

BlairHippo
  • 9,502
  • 10
  • 54
  • 78
  • 1
    dont think so - all the instructs ive seen about POE indicate that you send something from the child on STDOUT and if its configured correctly the parent gets it – SimonT Nov 06 '09 at 21:16
  • Fair enough. Figured I'd suggest it, since in my own experience the answer to "Where the $% is my precious precious output going?!" has sometimes been "The buffer." Here's hoping somebody smarter than me wanders by. :-) Good luck! – BlairHippo Nov 06 '09 at 21:21
  • 2
    @SimonT - It's still a good idea to check. You should consider scattering `$| = 1;` in appropriate places throughout your program's to flush the output streams and see if it helps. It may not, but at least it's easy to test. – Chris Lutz Nov 06 '09 at 21:27
  • POE will read STDOUT as soon as it is readable, sure, but there is no guarantee that "print" in your child is putting anything on the STDOUT pipe. Buffering. – jrockway Nov 07 '09 at 13:07
  • Added $|=1 and tried printing to STDOUT just after the child has been forked before it does any other work - still not seeing any output. – SimonT Nov 09 '09 at 11:40