Beefy Boxes and Bandwidth Generously Provided by pair Networks
The stupid question is the question not asked
 
PerlMonks  

Extracting time from a log

by Azur (Initiate)
on Jun 28, 2013 at 16:53 UTC ( #1041287=perlquestion: print w/ replies, xml ) Need Help??
Azur has asked for the wisdom of the Perl Monks concerning the following question:

I've got a website using the reverse proxy Varnish. I want to find objects which take more than X seconds to serve. Varnishlog is a small app which on-the-fly outputs Varnish's log, like this:

... 11 SessionOpen c 123.234.56.78 63618 123.234.56.89:80 11 RxURL c /example.php 11 RxHeader c Host: 123.234.56.89 11 RxHeader c User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; r +v:22.0) Gecko/20100101 Firefox/22.0 11 RxHeader c Accept-Language: en-US,en;q=0.5 11 RxHeader c Accept-Encoding: gzip, deflate 11 ReqEnd c 1832330560 1372436083.710740089 1372436083.711302 +519 0.000174284 0.000352383 0.000210047 ...

The interesting line is the ReqEnd one, the fifth group of digits (0.000352383) is the time in seconds it took to serve the object. Searching the net I found this command, which is supposed to extract entries which have taken more than 10 seconds to load:

varnishlog -o -i Backend,RxURL,ReqEnd,RxHeader | perl -ne 'BEGIN { $/= + "";} print if (/ReqEnd(?:[\sc]+)\d+\s\d+.\d+\s+\d+.\d+\s+\d+.\d+\s+( +\d+.\d+)/ and $1 > 10.0)'

...but it outputs nothing. Can someone help me find the problem with that command?

Comment on Extracting time from a log
Select or Download Code
Re: Extracting time from a log
by toolic (Chancellor) on Jun 28, 2013 at 17:02 UTC
    The problem is that 0.000352383 (which is stored in $1) is not greater than 10.0. You should also escape all the periods because they have special meaning in regexes (perlre).
      1) Yes, that output was just an example of the log format. There are several pages which take 2-3 seconds, but even changing 10.0 to 1 or 0 result in no output. 2)Thank you, I thought as much. However, the command doesn't work any better with the periods escaped:  varnishlog -o -i Backend,RxURL,ReqEnd,RxHeader | perl -ne 'BEGIN { $/= "";} print if (/ReqEnd(?:[\sc]+)\d+\s\d+\.\d+\s+\d+\.\d+\s+\d+\.\d+\s+(\d+\.\d+)/ and $1 > 1.0)'
        but even changing 10.0 to 1 or 0 result in no output

        I beg to differ:

        $ echo " 11 SessionOpen c 123.234.56.78 63618 123.234.56.89:80 11 RxURL c /example.php 11 RxHeader c Host: 123.234.56.89 11 RxHeader c User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; r +v:22.0) Gecko/20100101 Firefox/22.0 11 RxHeader c Accept-Language: en-US,en;q=0.5 11 RxHeader c Accept-Encoding: gzip, deflate 11 ReqEnd c 1832330560 1372436083.710740089 1372436083.711302 +519 0.000174284 0.000352383 0.000210047" | perl -ne 'BEGIN { $/="";} +print if (/ReqEnd(?:[\sc]+)\d+\s\d+\.\d+\s+\d+\.\d+\s+\d+\.\d+\s+(\d+ +\.\d+)/ and $1 > 0)'

        Output:

        11 SessionOpen c 123.234.56.78 63618 123.234.56.89:80 11 RxURL c /example.php 11 RxHeader c Host: 123.234.56.89 11 RxHeader c User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; r +v:22.0) Gecko/20100101 Firefox/22.0 11 RxHeader c Accept-Language: en-US,en;q=0.5 11 RxHeader c Accept-Encoding: gzip, deflate 11 ReqEnd c 1832330560 1372436083.710740089 1372436083.711302 +519 0.000174284 0.000352383 0.000210047

        I changed the 10.0 to 0 and it outputted successfully. Perhaps you are overlooking something?

Log In?
Username:
Password:

What's my password?
Create A New User
Node Status?
node history
Node Type: perlquestion [id://1041287]
Approved by toolic
help
Chatterbox?
and the web crawler heard nothing...

How do I use this? | Other CB clients
Other Users?
Others musing on the Monastery: (6)
As of 2014-10-21 05:29 GMT
Sections?
Information?
Find Nodes?
Leftovers?
    Voting Booth?

    For retirement, I am banking on:










    Results (96 votes), past polls