wvanbergen / request-log-analyzer

A command line tool that analyzes request logfiles (e.g. Rails, Merb, Apache) to produce a performance report.

This URL has Read+Write access

request-log-analyzer / README
100644 121 lines (98 sloc) 5.568 kb
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
Request log analyzer
--------------------------------
 
This is a simple command line tool to analyze request log files. At this moment,
it only supports Rails log files, but Merb log files are planned to be supported
as well. Its purpose is to find what actions are best candidates for optimization.
 
This tool will parse all requests in the logfile and aggregate the
information. Once it is finished parsing the log file, it will show the
requests that take op most server time. Different metrics are used (cumulative
time, average time, blockers, DB time, etc)
 
 
Installation
--------------------------------
gem sources -a http://gems.github.com
gem install wvanbergen-request-log-analyzer
 
 
Usage
--------------------------------
 
Usage: request-log-analyzer [FILE] [OPTION]
Analyze the given log FILE with the given OPTION
Example: request-log-analyzer mongrel.log
 
  --fast, -t: Only use completed requests
  --guess-database-time, -g: Guesses the database duration of requests if they are not in the log
  --output, -o: Comma-separated list of reports to show
  --amount, -c: Displays the top <amount> elements in the reports
  --colorize, -z: Fancy bash coloring
 
 
 
Example
--------------------------------
 
Note that this example was shortened for your viewing pleasure.
$ request-log-analyzer /var/log/my_app.log
 
Request log analyzer, by Willem van Bergen and Bart ten Brinke
 
Processing all log lines...
========================================================================
Successfully analyzed 58908 requests from log file
 
Timestamp first request: 2008-07-13T06:25:58+00:00
Timestamp last request: 2008-07-20T06:18:53+00:00
Total time analyzed: 7 days
 
Top 10 most requested actions
========================================================================
/overview/:date/ : 19359 requests
/overview/day/:date/ : 6365 requests
/overview/:date/set/ : 5589 requests
/overview/ : 3985 requests
/clients/:id/ : 1976 requests
........
 
Top 10 actions by time - cumulative
========================================================================
/overview/:date/ : 9044.582s [19359 requests]
/overview/ : 8478.767s [3985 requests]
/overview/:date/set/ : 3309.041s [5589 requests]
/clients/:id/products/:id/ : 1479.911s [924 requests]
/clients/:id/ : 750.080s [1976 requests]
........
 
Top 10 actions by time - per request mean
========================================================================
/overview/ : 2.128s [3985 requests]
/clients/:id/products/:id/ : 1.602s [924 requests]
/overview/:date/set/ : 0.592s [5589 requests]
/overview/:date/ : 0.467s [19359 requests]
/clients/:id/ : 0.380s [1976 requests]
........
 
Top 10 worst DB offenders - cumulative time
========================================================================
/overview/:date/ : 8773.993s [19359 requests]
/overview/ : 8394.754s [3985 requests]
/overview/:date/set/ : 3307.928s [5589 requests]
/clients/:id/products/:id/ : 1425.220s [924 requests]
/clients/:id/ : 535.229s [1976 requests]
........
 
Top 10 worst DB offenders - mean time
========================================================================
/overview/:id/:id/:id/print/ : 6.994s [448 requests]
/overview/ : 2.128s [3985 requests]
/clients/:id/products/:id/ : 1.602s [924 requests]
/overview/:date/set/ : 0.592s [5589 requests]
/overview/:date/ : 0.467s [19359 requests]
........
 
Mongrel process blockers (> 1.0 seconds) - frequency
========================================================================
/overview/:date/ : 7494.233s [3144 requests]
/overview/ : 8320.293s [1549 requests]
/overview/:date/set/ : 1149.235s [803 requests]
/overview/:id/:id/:id/print/new/ : 613.693s [341 requests]
/clients/:id/products/:id/ : 1370.693s [313 requests]
........
 
Requests graph - per hour
========================================================================
         ........
         7:00 - 2731 : XXXXXXX
         8:00 - 6139 : XXXXXXXXXXXXXXXX
         9:00 - 7465 : XXXXXXXXXXXXXXXXXXXX
        10:00 - 7118 : XXXXXXXXXXXXXXXXXXX
        11:00 - 7409 : XXXXXXXXXXXXXXXXXXX
        12:00 - 6450 : XXXXXXXXXXXXXXXXX
        13:00 - 5377 : XXXXXXXXXXXXXX
        14:00 - 6058 : XXXXXXXXXXXXXXXX
        15:00 - 4156 : XXXXXXXXXXX
        16:00 - 2767 : XXXXXXX
        17:00 - 1598 : XXXX
        18:00 - 792 : XX
        ........