apachelog.py

   1 #!/usr/bin/env python
   2 """Apache Log Parser
   3
   4 Parser for Apache log files. This is a port to python of Peter Hickman's
   5 Apache::LogEntry Perl module:
   6 <http://cpan.uwinnipeg.ca/~peterhi/Apache-LogRegex>
   7
   8 Takes the Apache logging format defined in your httpd.conf and generates
   9 a regular expression which is used to a line from the log file and
  10 return it as a dictionary with keys corresponding to the fields defined
  11 in the log format.
  12
  13 Example:
  14
  15     import apachelog, sys
  16
  17     # Format copied and pasted from Apache conf - use raw string + single quotes
  18     format = r'%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"'
  19
  20     p = apachelog.parser(format)
  21
  22     for line in open('/var/apache/access.log'):
  23         try:
  24            data = p.parse(line)
  25         except:
  26            sys.stderr.write("Unable to parse %s" % line)
  27
  28 The return dictionary from the parse method depends on the input format.
  29 For the above example, the returned dictionary would look like;
  30
  31     {
  32     '%>s': '200',
  33     '%b': '2607',
  34     '%h': '212.74.15.68',
  35     '%l': '-',
  36     '%r': 'GET /images/previous.png HTTP/1.1',
  37     '%t': '[23/Jan/2004:11:36:20 +0000]',
  38     '%u': '-',
  39     '%{Referer}i': 'http://peterhi.dyndns.org/bandwidth/index.html',
  40     '%{User-Agent}i': 'Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.2) Gecko/20021202'
  41     }
  42
  43 ...given an access log entry like (split across lines for formatting);
  44
  45     212.74.15.68 - - [23/Jan/2004:11:36:20 +0000] "GET /images/previous.png HTTP/1.1"
  46         200 2607 "http://peterhi.dyndns.org/bandwidth/index.html"
  47         "Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.2) Gecko/20021202"
  48
  49 You can also re-map the field names by subclassing (or re-pointing) the
  50 alias method.
  51
  52 Generally you should be able to copy and paste the format string from
  53 your Apache configuration, but remember to place it in a raw string
  54 using single-quotes, so that backslashes are handled correctly.
  55
  56 This module provides three of the most common log formats in the
  57 formats dictionary;
  58
  59     # Common Log Format (CLF)
  60     p = apachelog.parser(apachelog.formats['common'])
  61
  62     # Common Log Format with Virtual Host
  63     p = apachelog.parser(apachelog.formats['vhcommon'])
  64
  65     # NCSA extended/combined log format
  66     p = apachelog.parser(apachelog.formats['extended'])
  67
  68 For notes regarding performance while reading lines from a file
  69 in Python, see <http://effbot.org/zone/readline-performance.htm>.
  70 Further performance boost can be gained by using psyco
  71 <http://psyco.sourceforge.net/>
  72
  73 On my system, using a loop like;
  74
  75     for line in open('access.log'):
  76         p.parse(line)
  77
  78 ...was able to parse ~60,000 lines / second. Adding psyco to the mix,
  79 up that to ~75,000 lines / second.
  80
  81 The parse_date function is intended as a fast way to convert a log
  82 date into something useful, without incurring a significant date
  83 parsing overhead - good enough for basic stuff but will be a problem
  84 if you need to deal with log from multiple servers in different
  85 timezones.
  86 """
  87
  88 __version__ = "1.1"
  89 __license__ = """Released under the same terms as Perl.
  90 See: http://dev.perl.org/licenses/
  91 """
  92 __author__ = "Harry Fuecks <hfuecks@gmail.com>"
  93 __contributors__ = [
  94     "Peter Hickman <peterhi@ntlworld.com>",
  95     "Loic Dachary <loic@dachary.org>"
  96     ]
  97
  98 import re
  99
 100 class ApacheLogParserError(Exception):
 101     pass
 102
 103 class parser:
 104     format_to_name = {
 105         # Explanatory comments copied from
 106         # http://httpd.apache.org/docs/2.2/mod/mod_log_config.html
 107         # Remote IP-address
 108         '%a':'remote_ip',
 109         # Local IP-address
 110         '%A':'local_ip',
 111         # Size of response in bytes, excluding HTTP headers.
 112         '%B':'response_bytes',
 113         # Size of response in bytes, excluding HTTP headers. In CLF
 114         # format, i.e. a "-" rather than a 0 when no bytes are sent.
 115         '%b':'response_bytes_clf',
 116         # The contents of cookie Foobar in the request sent to the server.
 117         # Only version 0 cookies are fully supported.
 118         #'%{Foobar}C':'TODO',
 119         # The time taken to serve the request, in microseconds.
 120         '%D':'response_time_us',
 121         # The contents of the environment variable FOOBAR
 122         #'%{FOOBAR}e':'TODO',
 123         # Filename
 124         '%f':'filename',
 125         # Remote host
 126         '%h':'remote_host',
 127         # The request protocol
 128         '%H':'request_protocol',
 129         # The contents of Foobar: header line(s) in the request sent to
 130         # the server. Changes made by other modules (e.g. mod_headers)
 131         # affect this.
 132         #'%{Foobar}i':'TODO',
 133         # Number of keepalive requests handled on this connection.
 134         # Interesting if KeepAlive is being used, so that, for example,
 135         # a "1" means the first keepalive request after the initial one,
 136         # "2" the second, etc...; otherwise this is always 0 (indicating
 137         # the initial request). Available in versions 2.2.11 and later.
 138         '%k':'keepalive_num',
 139         # Remote logname (from identd, if supplied). This will return a
 140         # dash unless mod_ident is present and IdentityCheck is set On.
 141         '%l':'remote_logname',
 142         # The request method
 143         '%m':'request_method',
 144         # The contents of note Foobar from another module.
 145         #'%{Foobar}n':'TODO',
 146         # The contents of Foobar: header line(s) in the reply.
 147         #'%{Foobar}o':'TODO',
 148         # The canonical port of the server serving the request
 149         '%p':'server_port',
 150         # The canonical port of the server serving the request or the
 151         # server's actual port or the client's actual port. Valid
 152         # formats are canonical, local, or remote.
 153         #'%{format}p':"TODO",
 154         # The process ID of the child that serviced the request.
 155         '%P':'process_id',
 156         # The process ID or thread id of the child that serviced the
 157         # request. Valid formats are pid, tid, and hextid. hextid requires
 158         # APR 1.2.0 or higher.
 159         #'%{format}P':'TODO',
 160         # The query string (prepended with a ? if a query string exists,
 161         # otherwise an empty string)
 162         '%q':'query_string',
 163         # First line of request
 164         '%r':'first_line',
 165         # The handler generating the response (if any).
 166         '%R':'response_handler',
 167         # Status. For requests that got internally redirected, this is
 168         # the status of the *original* request --- %>s for the last.
 169         '%s':'status',
 170         # Time the request was received (standard english format)
 171         '%t':'time',
 172         # The time, in the form given by format, which should be in
 173         # strftime(3) format. (potentially localized)
 174         #'%{format}t':'TODO',
 175         # The time taken to serve the request, in seconds.
 176         '%T':'response_time_sec',
 177         # Remote user (from auth; may be bogus if return status (%s) is 401)
 178         '%u':'remote_user',
 179         # The URL path requested, not including any query string.
 180         '%U':'url_path',
 181         # The canonical ServerName of the server serving the request.
 182         '%v':'canonical_server_name',
 183         # The server name according to the UseCanonicalName setting.
 184         '%V':'server_name_config', #TODO: Needs better name
 185         # Connection status when response is completed:
 186         # X = connection aborted before the response completed.
 187         # + = connection may be kept alive after the response is sent.
 188         # - = connection will be closed after the response is sent.
 189         '%X':'completed_connection_status',
 190         # Bytes received, including request and headers, cannot be zero.
 191         # You need to enable mod_logio to use this.
 192         '%I':'bytes_received',
 193         # Bytes sent, including headers, cannot be zero. You need to
 194         # enable mod_logio to use this
 195         '%O':'bytes_sent',
 196     }
 197
 198     def __init__(self, format):
 199         """
 200         Takes the log format from an Apache configuration file.
 201
 202         Best just copy and paste directly from the .conf file
 203         and pass using a Python raw string e.g.
 204
 205         format = r'%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"'
 206         p = apachelog.parser(format)
 207         """
 208         self._names = []
 209         self._regex = None
 210         self._pattern = ''
 211         self._parse_format(format)
 212
 213     def _parse_format(self, format):
 214         """
 215         Converts the input format to a regular
 216         expression, as well as extracting fields
 217
 218         Raises an exception if it couldn't compile
 219         the generated regex.
 220         """
 221         format = format.strip()
 222         format = re.sub('[ \t]+',' ',format)
 223
 224         subpatterns = []
 225
 226         findquotes = re.compile(r'^\\"')
 227         findreferreragent = re.compile('Referer|User-Agent', re.I)
 228         findpercent = re.compile('^%.*t$')
 229         lstripquotes = re.compile(r'^\\"')
 230         rstripquotes = re.compile(r'\\"$')
 231         self._names = []
 232
 233         for element in format.split(' '):
 234
 235             hasquotes = 0
 236             if findquotes.search(element): hasquotes = 1
 237
 238             if hasquotes:
 239                 element = lstripquotes.sub('', element)
 240                 element = rstripquotes.sub('', element)
 241
 242             self._names.append(self.alias(element))
 243
 244             subpattern = '(\S*)'
 245
 246             if hasquotes:
 247                 if element == '%r' or findreferreragent.search(element):
 248                     subpattern = r'\"([^"\\]*(?:\\.[^"\\]*)*)\"'
 249                 else:
 250                     subpattern = r'\"([^\"]*)\"'
 251
 252             elif findpercent.search(element):
 253                 subpattern = r'(\[[^\]]+\])'
 254
 255             elif element == '%U':
 256                 subpattern = '(.+?)'
 257
 258             subpatterns.append(subpattern)
 259
 260         self._pattern = '^' + ' '.join(subpatterns) + '$'
 261         try:
 262             self._regex = re.compile(self._pattern)
 263         except Exception, e:
 264             raise ApacheLogParserError(e)
 265
 266     def parse(self, line):
 267         """
 268         Parses a single line from the log file and returns
 269         a dictionary of it's contents.
 270
 271         Raises and exception if it couldn't parse the line
 272         """
 273         line = line.strip()
 274         match = self._regex.match(line)
 275
 276         if match:
 277             data = {}
 278             for k, v in zip(self._names, match.groups()):
 279                 data[k] = v
 280             return data
 281
 282         raise ApacheLogParserError("Unable to parse: %s with the %s regular expression" % ( line, self._pattern ) )
 283
 284     def alias(self, name):
 285         """
 286         Override / replace this method if you want to map format
 287         field names to something else. This method is called
 288         when the parser is constructed, not when actually parsing
 289         a log file
 290
 291         Takes and returns a string fieldname
 292         """
 293         try:
 294             return self.format_to_name[name]
 295         except KeyError:
 296             return name
 297
 298     def pattern(self):
 299         """
 300         Returns the compound regular expression the parser extracted
 301         from the input format (a string)
 302         """
 303         return self._pattern
 304
 305     def names(self):
 306         """
 307         Returns the field names the parser extracted from the
 308         input format (a list)
 309         """
 310         return self._names
 311
 312 months = {
 313     'Jan':'01',
 314     'Feb':'02',
 315     'Mar':'03',
 316     'Apr':'04',
 317     'May':'05',
 318     'Jun':'06',
 319     'Jul':'07',
 320     'Aug':'08',
 321     'Sep':'09',
 322     'Oct':'10',
 323     'Nov':'11',
 324     'Dec':'12'
 325     }
 326
 327 def parse_date(date):
 328     """
 329     Takes a date in the format: [05/Dec/2006:10:51:44 +0000]
 330     (including square brackets) and returns a two element
 331     tuple containing first a timestamp of the form
 332     YYYYMMDDHH24IISS e.g. 20061205105144 and second the
 333     timezone offset as is e.g.;
 334
 335     parse_date('[05/Dec/2006:10:51:44 +0000]')
 336     >> ('20061205105144', '+0000')
 337
 338     It does not attempt to adjust the timestamp according
 339     to the timezone - this is your problem.
 340     """
 341     date = date[1:-1]
 342     elems = [
 343         date[7:11],
 344         months[date[3:6]],
 345         date[0:2],
 346         date[12:14],
 347         date[15:17],
 348         date[18:20],
 349         ]
 350     return (''.join(elems),date[21:])
 351
 352
 353 """
 354 Frequenty used log formats stored here
 355 """
 356 formats = {
 357     # Common Log Format (CLF)
 358     'common':r'%h %l %u %t \"%r\" %>s %b',
 359
 360     # Common Log Format with Virtual Host
 361     'vhcommon':r'%v %h %l %u %t \"%r\" %>s %b',
 362
 363     # NCSA extended/combined log format
 364     'extended':r'%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"',
 365     }
 366
 367 if __name__ == '__main__':
 368     import unittest
 369
 370     class TestApacheLogParser(unittest.TestCase):
 371
 372         def setUp(self):
 373             self.format = r'%h %l %u %t \"%r\" %>s '\
 374                           r'%b \"%{Referer}i\" \"%{User-Agent}i\"'
 375             self.fields = '%h %l %u %t %r %>s %b %{Referer}i '\
 376                           '%{User-Agent}i'.split(' ')
 377             self.pattern = '^(\\S*) (\\S*) (\\S*) (\\[[^\\]]+\\]) '\
 378                            '\\\"([^"\\\\]*(?:\\\\.[^"\\\\]*)*)\\\" '\
 379                            '(\\S*) (\\S*) \\\"([^"\\\\]*(?:\\\\.[^"\\\\]*)*)\\\" '\
 380                            '\\\"([^"\\\\]*(?:\\\\.[^"\\\\]*)*)\\\"$'
 381             self.line1  = r'212.74.15.68 - - [23/Jan/2004:11:36:20 +0000] '\
 382                           r'"GET /images/previous.png HTTP/1.1" 200 2607 '\
 383                           r'"http://peterhi.dyndns.org/bandwidth/index.html" '\
 384                           r'"Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.2) '\
 385                           r'Gecko/20021202"'
 386             self.line2  = r'212.74.15.68 - - [23/Jan/2004:11:36:20 +0000] '\
 387                           r'"GET /images/previous.png=\" HTTP/1.1" 200 2607 '\
 388                           r'"http://peterhi.dyndns.org/bandwidth/index.html" '\
 389                           r'"Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.2) '\
 390                           r'Gecko/20021202"'
 391             self.line3  = r'4.224.234.46 - - [20/Jul/2004:13:18:55 -0700] '\
 392                           r'"GET /core/listing/pl_boat_detail.jsp?&units=Feet&checked'\
 393                           r'_boats=1176818&slim=broker&&hosturl=giffordmarine&&ywo='\
 394                           r'giffordmarine& HTTP/1.1" 200 2888 "http://search.yahoo.com/'\
 395                           r'bin/search?p=\"grady%20white%20306%20bimini\"" '\
 396                           r'"\"Mozilla/4.0 (compatible; MSIE 6.0; Windows 98; '\
 397                           r'YPC 3.0.3; yplus 4.0.00d)\""'
 398 #                          r'"Mozilla/4.0 (compatible; MSIE 6.0; Windows 98; '\
 399 #                          r'YPC 3.0.3; yplus 4.0.00d)"'
 400             self.p = parser(self.format)
 401
 402         def testpattern(self):
 403             self.assertEqual(self.pattern, self.p.pattern())
 404
 405         def testnames(self):
 406             self.assertEqual(self.fields, self.p.names())
 407
 408         def testline1(self):
 409             data = self.p.parse(self.line1)
 410             self.assertEqual(data['%h'], '212.74.15.68', msg = 'Line 1 %h')
 411             self.assertEqual(data['%l'], '-', msg = 'Line 1 %l')
 412             self.assertEqual(data['%u'], '-', msg = 'Line 1 %u')
 413             self.assertEqual(data['%t'], '[23/Jan/2004:11:36:20 +0000]', msg = 'Line 1 %t')
 414             self.assertEqual(
 415                 data['%r'],
 416                 'GET /images/previous.png HTTP/1.1',
 417                 msg = 'Line 1 %r'
 418                 )
 419             self.assertEqual(data['%>s'], '200', msg = 'Line 1 %>s')
 420             self.assertEqual(data['%b'], '2607', msg = 'Line 1 %b')
 421             self.assertEqual(
 422                 data['%{Referer}i'],
 423                 'http://peterhi.dyndns.org/bandwidth/index.html',
 424                 msg = 'Line 1 %{Referer}i'
 425                 )
 426             self.assertEqual(
 427                 data['%{User-Agent}i'],
 428                 'Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.2) Gecko/20021202',
 429                 msg = 'Line 1 %{User-Agent}i'
 430                 )
 431
 432
 433         def testline2(self):
 434             data = self.p.parse(self.line2)
 435             self.assertEqual(data['%h'], '212.74.15.68', msg = 'Line 2 %h')
 436             self.assertEqual(data['%l'], '-', msg = 'Line 2 %l')
 437             self.assertEqual(data['%u'], '-', msg = 'Line 2 %u')
 438             self.assertEqual(
 439                 data['%t'],
 440                 '[23/Jan/2004:11:36:20 +0000]',
 441                 msg = 'Line 2 %t'
 442                 )
 443             self.assertEqual(
 444                 data['%r'],
 445                 r'GET /images/previous.png=\" HTTP/1.1',
 446                 msg = 'Line 2 %r'
 447                 )
 448             self.assertEqual(data['%>s'], '200', msg = 'Line 2 %>s')
 449             self.assertEqual(data['%b'], '2607', msg = 'Line 2 %b')
 450             self.assertEqual(
 451                 data['%{Referer}i'],
 452                 'http://peterhi.dyndns.org/bandwidth/index.html',
 453                 msg = 'Line 2 %{Referer}i'
 454                 )
 455             self.assertEqual(
 456                 data['%{User-Agent}i'],
 457                 'Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.2) Gecko/20021202',
 458                 msg = 'Line 2 %{User-Agent}i'
 459                 )
 460
 461         def testline3(self):
 462             data = self.p.parse(self.line3)
 463             self.assertEqual(data['%h'], '4.224.234.46', msg = 'Line 3 %h')
 464             self.assertEqual(data['%l'], '-', msg = 'Line 3 %l')
 465             self.assertEqual(data['%u'], '-', msg = 'Line 3 %u')
 466             self.assertEqual(
 467                 data['%t'],
 468                 '[20/Jul/2004:13:18:55 -0700]',
 469                 msg = 'Line 3 %t'
 470                 )
 471             self.assertEqual(
 472                 data['%r'],
 473                 r'GET /core/listing/pl_boat_detail.jsp?&units=Feet&checked_boats='\
 474                 r'1176818&slim=broker&&hosturl=giffordmarine&&ywo=giffordmarine& '\
 475                 r'HTTP/1.1',
 476                 msg = 'Line 3 %r'
 477                 )
 478             self.assertEqual(data['%>s'], '200', msg = 'Line 3 %>s')
 479             self.assertEqual(data['%b'], '2888', msg = 'Line 3 %b')
 480             self.assertEqual(
 481                 data['%{Referer}i'],
 482                 r'http://search.yahoo.com/bin/search?p=\"grady%20white%20306'\
 483                 r'%20bimini\"',
 484                 msg = 'Line 3 %{Referer}i'
 485                 )
 486             self.assertEqual(
 487                 data['%{User-Agent}i'],
 488                 '\\"Mozilla/4.0 (compatible; MSIE 6.0; Windows 98; YPC 3.0.3; '\
 489                 'yplus 4.0.00d)\\"',
 490 #                'Mozilla/4.0 (compatible; MSIE 6.0; Windows 98; YPC 3.0.3; '\
 491 #                'yplus 4.0.00d)',
 492                 msg = 'Line 3 %{User-Agent}i'
 493                 )
 494
 495
 496         def testjunkline(self):
 497             self.assertRaises(ApacheLogParserError,self.p.parse,'foobar')
 498
 499         def testhasquotesaltn(self):
 500             p = parser(r'%a \"%b\" %c')
 501             line = r'foo "xyz" bar'
 502             data = p.parse(line)
 503             self.assertEqual(data['%a'],'foo', '%a')
 504             self.assertEqual(data['%b'],'xyz', '%c')
 505             self.assertEqual(data['%c'],'bar', '%c')
 506
 507         def testparsedate(self):
 508             date = '[05/Dec/2006:10:51:44 +0000]'
 509             self.assertEqual(('20061205105144','+0000'),parse_date(date))
 510
 511     unittest.main()