Beefy Boxes and Bandwidth Generously Provided by pair Networks
There's more than one way to do things

IO::Tee not behaving correctly

by grinder (Bishop)
on Mar 13, 2002 at 08:28 UTC ( #151332=perlquestion: print w/replies, xml ) Need Help??

grinder has asked for the wisdom of the Perl Monks concerning the following question:

Fellow monks, I have a really hairy problem with IO::Tee that I can't resolve. I am using IO::Tee to print to STDOUT and a log file at the same time. In this way, anything that is written to STDOUT is, theoretically, guaranteed to be written to the log file as well, which comes in handy when I have to trace why something didn't work correctly.

The problem is that at the end of the program, the log file is of length zero, and yet everything is correctly printed to STDOUT. I created a test program, but that works flawlessly. It goes something like this:

#! /usr/bin/perl -w use strict; # use all the modules I'm using in the main script, just in case use DBI; use File::Basename qw/basename/; use File::Path qw/mkpath/; use Getopt::Mixed; use IO::File; use IO::Tee; my $max = shift || 3; BEGIN { my @now; sub work_name { @now = localtime unless @now; sprintf( '/var/log/test/%02d%02d%02d.log', sub{ @_[reverse 0..2] }->(@now) ) } } my $logger = do { my $logfile = work_name(); my $fd = new IO::File( "> $logfile" ) or die "Could not open $logfile for output: $!\n"; new IO::Tee(\*STDOUT, $fd ); }; END { $logger and $logger->flush and $logger->close } for( 1..$max ) { my $letter = ('a'..'z')[rand 26]; my $lines = 1 + int(rand(10)); my $cols = 1 + int(rand(72)); $logger->print( "$_ ", (($letter x $cols) . "\n") x $lines ); } $logger->print("--end--");

I thought it might have been problems with a missing \n on the last line, or needing to flush explicitly, but that doesn't change things. The test script works, but not the main script. Elsewhere in the script I am using arrays of arrays of IO::File objects which behave as advertised. At no point do I do any bare prints (to STDOUT), everything is printed via the logger object.

If, in the main script, I create the $logger object, print to it and exit immediately, the output gets recorded in the log file. Something down the track seems to be making things go haywire, and I am at a loss as to explain why. I am using 5.6.0, which is the most suspicious thing I can think of. For instance, I am not using sfio.

Any tips or suggestions for things to try are most appreciated.

print@_{sort keys %_},$/if%_=split//,'= & *a?b:e\f/h^h!j+n,o@o;r$s-t%t#u'

Replies are listed 'Best First'.
Re: IO::Tee not behaving correctly
by busunsl (Vicar) on Mar 13, 2002 at 08:53 UTC
    Well, if that test program works correct, how shall we find the error?

    Post the failing program, if it's not too large, or put it somewhere where we can take a look.

Re: IO::Tee not behaving correctly
by derby (Abbot) on Mar 13, 2002 at 12:53 UTC

    as busunsl pointed out it's really hard to help without the fault code. Here's what I would try:

    • if it's a console program, run under the debugger, setting stop points at certain log statements you think are failing. Inspect the tee object before the print, explicitly flush (via the debugger) after you print, check the log file.
    • or, whereever you have tee print, right before insert an explicit print to STDERR a Data::Dumper the tee object


      The trouble is that it's around 1300 lines, and it's an interface between our billing system and the accounts system, so I'm a little leery of showing it to all and sundry. What I'm after specifically is whether anyone has (extensive)? experience with IO::Tee and whether there are any common gotchas to be aware of.

      It is very annoying, because the pressure is on me to do something low-tech, like print $var; print LOG $var which is more prone to synchronisation errors (printing to the screen and not to the log).

      print@_{sort keys %_},$/if%_=split//,'= & *a?b:e\f/h^h!j+n,o@o;r$s-t%t#u'
Re (tilly) 1: IO::Tee not behaving correctly
by tilly (Archbishop) on Mar 16, 2002 at 01:00 UTC
    Two things to check.

    The first is that something might be doing a select or missing up the tie. I would try in the middle of your script calling tied to see if the tie has survived, and select to see if the output is going where you think.

    The second is whether you are producing output at the C level. For instance if you call system or fork, the child processes will talk directly to STDOUT without any chance for Perl's IO layer to capture it and notice the tie.

    In either case, the cookbook has an alternate recipe that might interest you where you fork and filter STDOUT after the fact. This is more heavyweight, but is a less fragile approach.

(RhetTbull) Re: IO::Tee not behaving correctly
by RhetTbull (Curate) on Mar 13, 2002 at 14:03 UTC
    I usually do this sort of thing with Filter::Handle which has always worked well for me. Might be worth taking a look at it. Regards,
Re: IO::Tee not behaving correctly
by petral (Curate) on Mar 13, 2002 at 20:00 UTC
    $fd->autoflush when you open it or save it (globally?!?) and $fd->flush at the END?


Log In?

What's my password?
Create A New User
Domain Nodelet?
Node Status?
node history
Node Type: perlquestion [id://151332]
Approved by root
and the web crawler heard nothing...

How do I use this? | Other CB clients
Other Users?
Others surveying the Monastery: (7)
As of 2022-06-29 22:48 GMT
Find Nodes?
    Voting Booth?
    My most frequent journeys are powered by:

    Results (97 votes). Check out past polls.