Strange printing behaviour of Perl programs

[Nikita Synytskyy]

Hello all!

Consider the following simple Perl program:

#~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
print "starting up...\n";
for ($i = 0; $i < 5; $i ++)
{
print "loop start ... ";

for ($j = 0; $j<3000000; $j++)
{ $useless = $j; }

print "loop end.\n";
}
#~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~


When I run this, I would expect the following: first, "starting up..."
printed; immideately afterwards, "loop start", then a long pause, and
then "loop end.". And so on, five times.

What I get instead is: "starting up...", long pause, then "loop start"
and "loop end" immideately following each other, then another long
pause, and so on.

Why does it happen this way?...


Nikita.

 

[Gunnar Hjalmarsson]

Consider the following simple Perl program:

#~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
print "starting up...\n";
for ($i = 0; $i < 5; $i ++)
{
print "loop start ... ";

for ($j = 0; $j<3000000; $j++)
{ $useless = $j; }

print "loop end.\n";
}
#~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

When I run this, I would expect the following: first, "starting
up..." printed; immideately afterwards, "loop start", then a long
pause, and then "loop end.". And so on, five times.

What I get instead is: "starting up...", long pause, then "loop
start" and "loop end" immideately following each other, then
another long pause, and so on.

Why does it happen this way?...

To me it sounds as if your OS is buffering the output until a linefeed
is printed. You may want to try:

print "loop start ...\n";
-------------------------^^

and see if that makes a difference.

 

[Nicholas Dronen]

NS> Hello all!

NS> Consider the following simple Perl program:

NS> #~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
NS> print "starting up...\n";
NS> for ($i = 0; $i < 5; $i ++)
NS> {
NS> print "loop start ... ";

NS> for ($j = 0; $j<3000000; $j++)
NS> { $useless = $j; }

NS> print "loop end.\n";
NS> }
NS> #~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~


NS> When I run this, I would expect the following: first, "starting up..."
NS> printed; immideately afterwards, "loop start", then a long pause, and
NS> then "loop end.". And so on, five times.

NS> What I get instead is: "starting up...", long pause, then "loop start"
NS> and "loop end" immideately following each other, then another long
NS> pause, and so on.

NS> Why does it happen this way?...

Because STDOUT is line buffered by default. See:

* the entry in perldoc -q flush; and
* the entry for $| ($OUTPUT_AUTOFLUSH) in the perlvar man page.

Regards,

Nicholas

 

[David Efflandt]

Hello all!

Consider the following simple Perl program:

#~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
print "starting up...\n";
for ($i = 0; $i < 5; $i ++)
{
print "loop start ... ";

for ($j = 0; $j<3000000; $j++)
{ $useless = $j; }

print "loop end.\n";
}
#~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~


When I run this, I would expect the following: first, "starting up..."
printed; immideately afterwards, "loop start", then a long pause, and
then "loop end.". And so on, five times.

What I get instead is: "starting up...", long pause, then "loop start"
and "loop end" immideately following each other, then another long
pause, and so on.

Why does it happen this way?...

Because default output channel for write or print is buffered until a
newline, unless you change that to autoflush by setting $| = 1; somewhere
before you want it unbuffered (like before your loop).

Scroll down to $| in 'perldoc perlvar' and also look for $| or autoflush
in 'perldoc -f select'.

 

[Chris Mattern]

Hello all!

Consider the following simple Perl program:

#~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
print "starting up...\n";
for ($i = 0; $i < 5; $i ++)
{
print "loop start ... ";

for ($j = 0; $j<3000000; $j++)
{ $useless = $j; }

print "loop end.\n";
}
#~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~


When I run this, I would expect the following: first, "starting up..."
printed; immideately afterwards, "loop start", then a long pause, and
then "loop end.". And so on, five times.

What I get instead is: "starting up...", long pause, then "loop start"
and "loop end" immideately following each other, then another long
pause, and so on.

Why does it happen this way?...

Because your output buffers. Perl doesn't print out the line until
you complete it. So you don't actually *see* "loop start ... "
until the loop ends. Change the second print statement to:
print "loop start ... \n";
and you'll see the results you were expecting.


Chris Mattern

 

[Tore Aursand]

#~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
print "starting up...\n";
for ($i = 0; $i < 5; $i ++)
{
print "loop start ... ";

for ($j = 0; $j<3000000; $j++)
{ $useless = $j; }

print "loop end.\n";
}
#~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

When I run this, I would expect the following: first, "starting up..."
printed; immideately afterwards, "loop start", then a long pause, and
then "loop end.". And so on, five times.

That doesn't happen, 'cause STDOUT is buffered (default) until a newline
comes its way. Turn off buffering like this:

$| = 1;

You could also consider writing your script a little more Perlish;

print "Starting up...\n";
for ( 1..5 ) {
print "Loop Start ... ";
$useless = $_ for ( 1..3_000_000 );
print "Loop End.\n";
}

Easier to read, IMO, and you don't need to use a few unnecessary
(in this case, at least) variables. It wouldn't surprise me if my example
is quite a bit faster, too.

 

[Nikita Synytskyy]

That doesn't happen, 'cause STDOUT is buffered (default) until a newline
comes its way. Turn off buffering like this:

$| = 1;

Thanks to everybody for your answers and examples. It's all working as
it should now.

You could also consider writing your script a little more Perlish;

I started using Perl only recently, and I'm coming from a Java/C/C++
side rather than from the scripting side so Perlish is still a bit
foreign to me. I guess it'll come to me as I write more code.

Nikita.