Perl script log to file, output lag

Question

I have a Perlscript which does some logfile parsing and sometimes executes a bash command:

$messagePath = `ls -t -d -1 $dir | head -n 5 | xargs grep -l "$messageSearchString"\`;

I start my perl script like this ./perlscript.pl > logfile.log.

Now I do a tail on the logfile to watch the progress, but the output gets stuck every time at the line I described above. The output will stop there for some seconds and then continue. ???

To profile the problem I wrapped it like this:

print `date`;
$messagePath = `ls -t -d -1 $dir | head -n 5 | xargs grep -l "$messageSearchString"`;
print `date`;

The output shows that the command does not consume a lot of time:

So 6. Okt 22:35:04 CEST 2013
So 6. Okt 22:35:04 CEST 2013

If I run the script without redirecting the output to a file there is no LAG.

Any idea why?

1) programming questions are off topic here, you can post them on Super User or, in the case of common *nix scripting languages like Perl, on Unix & Linux 2) Never parse the output of ls. — terdon
– terdon, Commented Oct 6, 2013 at 23:38

Community · Accepted Answer · 2017-05-23 12:28:04Z

2

I haven't tried to duplicate your behaviour, but it might be a stdout buffering problem. Try with:

$| = 1;
$messagePath = `ls -t -d -1 $dir | head -n 5 | xargs grep -l "$messageSearchString"`;

Update

I have tried to duplicate the behaviour you observe: I've had to make some assumptions but I believe my suspicion was correct. Here I'm piping, but it's the same as redirecting to a file and tailing that file:

./test.pl |  awk '{ print strftime("%Y-%m-%d %H:%M:%S"), $0; }'

Without $| = 1, output is buffered and aggregated:

2013-10-06 23:08:27 Saluton, mondo: /home/lserni/test.sh
2013-10-06 23:08:27
2013-10-06 23:08:27 Waiting 10s...
2013-10-06 23:08:27 Saluton denove!

With the modification, each line is printed as it is generated:

2013-10-06 23:09:09 Saluton, mondo: /home/lserni/test.sh
2013-10-06 23:09:09
2013-10-06 23:09:09 Waiting 10s...
2013-10-06 23:09:19 Saluton denove!

I expect that your script is doing something that takes some seconds, and which is not generating that messagePath; and the output will be delayed until Perl has a sizeable chunk of data to send along, giving the impression that it's that line that's stalling.

I forgot: the timing pipe comes from here.

edited May 23, 2017 at 12:28

CommunityBot

11 silver badge

answered Oct 6, 2013 at 20:53

LSerni

57.7k10 gold badges70 silver badges110 bronze badges

Sign up to request clarification or add additional context in comments.

1 Comment

cgross Over a year ago

Thanks for the answer, it was indeed a buffering problem.

garyjohn · Accepted Answer · 2013-10-06 22:16:10Z

0

In situations like yours, I've had some success using the unbuffer command. It runs a command in an environment that looks to the command like it's outputting to a tty so it doesn't buffer its output. I don't know how to apply it exactly in your case, so if you want to try it, you will have to experiment a little.

answered Oct 6, 2013 at 22:16

garyjohn

1011 silver badge1 bronze badge

Collectives™ on Stack Overflow

Perl script log to file, output lag

2 Answers 2

Update

1 Comment

Comments

Your Answer

Hot Network Questions

Collectives™ on Stack Overflow

2 Answers 2

Update

1 Comment

Comments

Your Answer

Sign up or log in

Post as a guest

Related