[CalendarServer-changes] [6283] CalendarServer/trunk/contrib/tools/request_monitor.py

[source_changes at macosforge.org]

Revision: 6283
          http://trac.macosforge.org/projects/calendarserver/changeset/6283
Author:   cdaboo at apple.com
Date:     2010-09-13 12:03:44 -0700 (Mon, 13 Sep 2010)
Log Message:
-----------
Better handle line parsing errors. Add a --debug option to print out tracebacks when exceptions occur. Count
number of /ischedule requests during the analysis window.

Modified Paths:
--------------
    CalendarServer/trunk/contrib/tools/request_monitor.py

Modified: CalendarServer/trunk/contrib/tools/request_monitor.py
===================================================================
--- CalendarServer/trunk/contrib/tools/request_monitor.py	2010-09-13 18:49:44 UTC (rev 6282)
+++ CalendarServer/trunk/contrib/tools/request_monitor.py	2010-09-13 19:03:44 UTC (rev 6283)
@@ -22,6 +22,7 @@
 import os
 import sys
 import time
+import traceback
 
 sys.stdout = os.fdopen(sys.stdout.fileno(), 'w', 0) 
 
@@ -148,23 +149,50 @@
 
 
 def usage():
+    print "request_monitor [OPTIONS] [FILENAME]"
+    print ""
+    print "FILENAME   optional path of access log to monitor [/var/log/caldavd/access.log]"
+    print ""
+    print "OPTIONS"
     print "-h         print help and exit"
+    print "--debug    print tracebacks and error details"
     print "--lines N  specifies how many lines to tail from access.log (default: 10000)"
     print "--procs N  specifies how many python processes are expected in the log file (default: 80)"
 
 numLines = 10000
 numProcs = 80
-options, args = getopt.getopt(sys.argv[1:], "h", ["lines=", "procs=",])
+debug = False
+options, args = getopt.getopt(sys.argv[1:], "h", ["debug", "lines=", "procs=",])
 for option, value in options:
     if option == "-h":
         usage()
         sys.exit(0)
+    elif option == "--debug":
+        debug = True
     elif option == "--lines":
         numLines = int(value)
     elif option == "--procs":
         numProcs = int(value)
 
+if len(args):
+    filename = os.path.expanduser(args[0])
 
+if not os.path.isfile(filename):
+    print "Path %s does not exist" % (filename,)
+    print
+    usage()
+    sys.exit(1)
+
+if not os.access(filename, os.R_OK):
+    print "Path %s does not exist" % (filename,)
+    print
+    usage()
+    sys.exit(1)
+
+if debug:
+    print "Starting: access log file: %s" % (filename,)
+    print
+
 while True:
 
     samples = []
@@ -175,6 +203,7 @@
     rawCounts = {}
     timesSpent = {}
     numRequests = 0
+    numServerToServer = 0
     totalRespTime = 0.0
     maxRespTime = 0.0
     under10ms = 0
@@ -189,6 +218,7 @@
     startTime = None
     endTime = None
     errorCount = 0
+    parseErrors = 0
 
     try: 
         for line in tail(filename, numLines):
@@ -197,7 +227,19 @@
 
             numRequests += 1
 
-            userId, logTime, method, uri, status, bytes, _ignore_referer, client, extended = parseLine(line)
+            try:
+                userId, logTime, method, uri, status, bytes, _ignore_referer, client, extended = parseLine(line)
+            except Exception, e:
+                parseErrors += 1
+                
+                if debug:
+                    print "Access log line parse failure", e
+                    print traceback.print_exc()
+                    print "---"
+                    print line
+                    print "---"
+                    
+                continue
 
             logTime = dateparse(logTime, fuzzy=True)
             times.append(logTime)
@@ -205,6 +247,9 @@
             if status >= 500:
                 errorCount += 1
 
+            if uri == "/ischedule":
+                numServerToServer += 1
+
             outstanding = int(extended['or'])
             logId = int(extended['i'])
             raw = rawCounts.get(logId, 0) + 1
@@ -299,7 +344,10 @@
 
         if avg:
             print avg, "|",
-        print "%d requests between %s and %s" % (numLines, startTime.strftime("%H:%M:%S"), endTime.strftime("%H:%M:%S"))
+        print "%d requests between %s and %s" % (numRequests, startTime.strftime("%H:%M:%S"), endTime.strftime("%H:%M:%S")),
+        if numServerToServer:
+            print "| %d server-to-server" % (numServerToServer,),
+        print
         
         lqlatency = (lqssl / avgRequests, lqnon / avgRequests,) if avgRequests else (0.0, 0.0,)
         print "Response time: average %.1f ms, max %.1f ms, listenq latency (ssl+non): %.1f s %.1f s" % (
@@ -312,6 +360,9 @@
         print
         if errorCount:
             print "Number of 500 errors: %d" % (errorCount,)
+        if parseErrors:
+            print "Number of access log parsing errors: %d" % (parseErrors,)
+        if errorCount or parseErrors:
             print
 
         print "Proc:   Peak outstanding:        Seconds of processing (number of requests):"
@@ -342,7 +393,7 @@
             print
 
         print
-        print "Top 10 longest (in most recent %d requests):" % (numLines,)
+        print "Top 10 longest (in most recent %d requests):" % (numRequests,)
         requests.sort()
         requests.reverse()
         for i in xrange(10):
@@ -364,7 +415,7 @@
             
 
         print
-        print "Top 5 busiest users (in most recent %d requests):" % (numLines,)
+        print "Top 5 busiest users (in most recent %d requests):" % (numRequests,)
         userlist = []
         for user, userStat in users.iteritems():
             userlist.append((userStat['count'], user, userStat))
@@ -391,4 +442,5 @@
 
     except Exception, e:
         print "Script failure", e
-
+        if debug:
+            print traceback.print_exc()
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.macosforge.org/pipermail/calendarserver-changes/attachments/20100913/103edd7d/attachment-0001.html>