text: #!/usr/bin/env python
  ##
  # Copyright (c) 2009-2015 Apple Inc. All rights reserved.
  #
  # Licensed under the Apache License, Version 2.0 (the "License");
  # you may not use this file except in compliance with the License.
  # You may obtain a copy of the License at
  #
  # http://www.apache.org/licenses/LICENSE-2.0
  #
  # Unless required by applicable law or agreed to in writing, software
  # distributed under the License is distributed on an "AS IS" BASIS,
  # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  # See the License for the specific language governing permissions and
  # limitations under the License.
  ##
  from __future__ import print_function
  
  from dateutil.parser import parse as dateparse
  from subprocess import Popen, PIPE, STDOUT
  import datetime
  import getopt
  import os
  import sys
  import time
  import traceback
  import collections
  import tables
  from cStringIO import StringIO
  
  # Detect which OS this is being run on
  child = Popen(
      args=[
          "uname",
      ],
      stdout=PIPE, stderr=STDOUT,
  )
  output, _ignore_error = child.communicate()
  output = output.strip()
  if output == "Darwin":
      OS = "OS X"
  elif output == "Linux":
      OS = "Linux"
  else:
      print("Unknown OS: %s" % (output,))
      sys.exit(1)
  
  # Some system commands we need to detect
  if OS == "OS X":
      NETSTAT = "/usr/sbin/netstat"
      enableListenQueue = os.path.exists(NETSTAT)
  elif OS == "Linux":
      enableListenQueue = False
  
  if OS == "OS X":
      IOSTAT = "/usr/sbin/iostat"
      enableCpuIdle = os.path.exists(IOSTAT)
  elif OS == "Linux":
      IOSTAT = "/usr/bin/iostat"
      enableCpuIdle = os.path.exists(IOSTAT)
  
  if OS == "OS X":
      VMSTAT = "/usr/bin/vm_stat"
      enableFreeMem = os.path.exists(VMSTAT)
  elif OS == "Linux":
      VMSTAT = "/usr/bin/vmstat"
      enableFreeMem = os.path.exists(VMSTAT)
  
  sys.stdout = os.fdopen(sys.stdout.fileno(), 'w', 0)
  
  
  filenames = ["/var/log/caldavd/access.log", ]
  debug = False
  
  def listenq():
      child = Popen(
          args=[
              NETSTAT, "-L", "-anp", "tcp",
          ],
          stdout=PIPE, stderr=STDOUT,
      )
      output, _ignore_error = child.communicate()
      ssl = nonssl = 0
      for line in output.split("\n"):
          if line.find("8443") != -1:
              ssl = int(line.split("/")[0])
          elif line.find("8008") != -1:
              nonssl = int(line.split("/")[0])
      return "%s+%s" % (ssl, nonssl), ssl, nonssl
  
  _listenQueueHistory = []
  
  def listenQueueHistory():
      global _listenQueueHistory
      latest, ssl, nonssl = listenq()
      _listenQueueHistory.insert(0, latest)
      del _listenQueueHistory[12:]
      return _listenQueueHistory, ssl, nonssl
  
  
  _idleHistory = []
  
  def idleHistory():
      global _idleHistory
      latest = cpuidle()
      _idleHistory.insert(0, latest)
      del _idleHistory[12:]
      return _idleHistory
  
  
  
  def tail(filenames, n):
      results = collections.defaultdict(list)
      for filename in filenames:
          child = Popen(
              args=[
                  "/usr/bin/tail", "-%d" % (n,), filename,
              ],
              stdout=PIPE, stderr=STDOUT,
          )
          output, _ignore_error = child.communicate()
          results[filename].extend(output.splitlines())
      return results
  
  
  
  def range(filenames, start, end):
      results = collections.defaultdict(list)
      for filename in filenames:
          with open(filename) as f:
              for count, line in enumerate(f):
                  if count >= start:
                      results[filename].append(line)
                  if count > end:
                      break
      return results
  
  
  
  def cpuPerDaemon():
      a = {}
      child = Popen(
          args=[
              "ps", "auxw",
          ],
          stdout=PIPE, stderr=STDOUT,
      )
      output, _ignore_ = child.communicate()
      for l in output.split("\n"):
          if "ProcessType=" in l:
              f = l.split()
              for l in f:
                  if l.startswith("LogID="):
                      logID = int(l[6:])
                      break
              else:
                  logID = None
              if logID is not None:
                  a[logID] = f[2]
      return ", ".join([v for _ignore_k, v in sorted(a.items(), key=lambda i:i[0])])
  
  
  
  def cpuidle():
      if OS == "OS X":
          child = Popen(
              args=[
                  IOSTAT, "-c", "2", "-n", "0",
              ],
              stdout=PIPE, stderr=STDOUT,
          )
          output, _ignore_ = child.communicate()
          return output.splitlines()[-1].split()[2]
      elif OS == "Linux":
          child = Popen(
              args=[
                  IOSTAT, "-c", "1", "2"
              ],
              stdout=PIPE, stderr=STDOUT,
          )
          output, _ignore_ = child.communicate()
          return output.splitlines()[-2].split()[5]
  
  
  
  def freemem():
      try:
          if OS == "OS X":
              child = Popen(
                  args=[
                      VMSTAT,
                  ],
                  stdout=PIPE, stderr=STDOUT,
              )
              output, _ignore_ = child.communicate()
              lines = output.split("\n")
  
              line = lines[0]
              pageSize = int(line[line.find("page size of") + 12:].split()[0])
              line = lines[1]
              freeSize = int(line[line.find("Pages free:") + 11:].split()[0][:-1])
              freed = freeSize * pageSize
              return "%d bytes (%.1f GB)" % (freed, freed / (1024.0 * 1024 * 1024),)
          elif OS == "Linux":
              child = Popen(
                  args=[
                      VMSTAT, "-s", "-S", "K"
                  ],
                  stdout=PIPE, stderr=STDOUT,
              )
              output, _ignore_ = child.communicate()
              lines = output.splitlines()
  
              line = lines[4]
              freed = int(line.split()[0]) * 1024
              return "%d bytes (%.1f GB)" % (freed, freed / (1024.0 * 1024 * 1024),)
      except Exception, e:
          if debug:
              print("freemem failure", e)
              print(traceback.print_exc())
          return "error"
  
  
  
  def parseLine(line):
  
      startPos = line.find("- ")
      endPos = line.find(" [")
      userId = line[startPos + 2:endPos]
  
      startPos = endPos + 2
      endPos = line.find(']', startPos)
      logTime = line[startPos:endPos]
  
      startPos = endPos + 3
      endPos = line.find(' ', startPos)
      if line[startPos] == '?':
          method = "???"
          uri = ""
          startPos += 5
      else:
          method = line[startPos:endPos]
  
          startPos = endPos + 1
          endPos = line.find(" HTTP/", startPos)
          uri = line[startPos:endPos]
          startPos = endPos + 11
  
      status = int(line[startPos:startPos + 3])
  
      startPos += 4
      endPos = line.find(' ', startPos)
      bytes = int(line[startPos:endPos])
  
      startPos = endPos + 2
      endPos = line.find('"', startPos)
      referer = line[startPos:endPos]
  
      startPos = endPos + 3
      endPos = line.find('"', startPos)
      client = line[startPos:endPos]
  
      startPos = endPos + 2
      if line[startPos] == '[':
          extended = {}
  
          startPos += 1
          endPos = line.find(' ', startPos)
          extended["t"] = float(line[startPos:endPos])
  
          startPos = endPos + 6
          endPos = line.find(' ', startPos)
          extended["i"] = int(line[startPos:endPos])
  
          startPos = endPos + 1
          endPos = line.find(' ', startPos)
          extended["or"] = int(line[startPos:endPos])
      else:
  
          items = line[startPos:].split()
          extended = dict([item.split('=') for item in items if item.find("=") != -1])
  
      return userId, logTime, method, uri, status, bytes, referer, client, extended
  
  
  
  def safePercent(value, total):
  
      return value * 100.0 / total if total else 0.0
  
  
  
  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("--range M:N  specifies a range of lines to analyze from access.log (default: all)")
      print("--procs N  specifies how many python processes are expected in the log file (default: 80)")
      print("--top N    how many long requests to print (default: 10)")
      print("--users N  how many top users to print (default: 5)")
      print("")
      print("Version: 5")
  
  numLines = 10000
  numProcs = 80
  numTop = 10
  numUsers = 5
  lineRange = None
  options, args = getopt.getopt(sys.argv[1:], "h", ["debug", "lines=", "range=", "procs=", "top=", "users="])
  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 == "--range":
          lineRange = (int(value.split(":")[0]), int(value.split(":")[1]))
      elif option == "--procs":
          numProcs = int(value)
      elif option == "--top":
          numTop = int(value)
      elif option == "--users":
          numUsers = int(value)
  
  if len(args):
      filenames = sorted([os.path.expanduser(arg) for arg in args])
      prefix = len(os.path.commonprefix(filenames))
  
  for filename in filenames:
      if not os.path.isfile(filename):
          print("Path %s does not exist" % (filename,))
          print("")
          usage()
          sys.exit(1)
  
  for filename in filenames:
      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 files: %s" % (", ".join(filenames),))
      print("")
  
  while True:
  
      currentSec = None
      currentCount = 0
      times = []
      perfile_times = collections.defaultdict(list)
      ids = {}
      rawCounts = {}
      timesSpent = {}
      numRequests = collections.defaultdict(int)
      numServerToServer = collections.defaultdict(int)
      numProxied = collections.defaultdict(int)
      slotCount = collections.defaultdict(int)
      totalRespTime = collections.defaultdict(float)
      totalRespWithoutWRTime = collections.defaultdict(float)
      maxRespTime = collections.defaultdict(float)
      under10ms = [0, 0]
      over10ms = [0, 0]
      over100ms = [0, 0]
      over1s = [0, 0]
      over10s = [0, 0]
      over30s = [0, 0]
      over60s = [0, 0]
      totalOver1s = [0, 0]
      totalOver10s = [0, 0]
      requests = []
      users = {}
      startTime = None
      endTime = None
      errorCount = 0
      parseErrors = 0
  
      try:
          lines = tail(filenames, numLines) if lineRange is None else range(filenames, *lineRange)
          for filename in lines.keys():
              for line in lines[filename]:
                  if not line or line.startswith("Log"):
                      continue
  
                  numRequests[filename] += 1
  
                  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)
                  perfile_times[filename].append(logTime)
  
                  if status >= 500:
                      errorCount += 1
  
                  if uri == "/ischedule":
                      numServerToServer[filename] += 1
                  elif uri.startswith("/calendars"):
                      numProxied[filename] += 1
  
                  outstanding = int(extended['or'])
                  logId = int(extended['i'] if extended['i'] else 0)
                  raw = rawCounts.get(logId, 0) + 1
                  rawCounts[logId] = raw
                  prevMax = ids.get(logId, 0)
                  if outstanding > prevMax:
                      ids[logId] = outstanding
                  slotCount[filename] += outstanding
  
                  respTime = float(extended['t'])
                  wrTime = float(extended.get('t-resp-wr', 0.0))
                  timeSpent = timesSpent.get(logId, 0.0) + respTime
                  timesSpent[logId] = timeSpent
                  totalRespTime[filename] += respTime
                  totalRespWithoutWRTime[filename] += respTime - wrTime
                  if respTime > maxRespTime[filename]:
                      maxRespTime[filename] = respTime
  
                  for index, testTime in enumerate((respTime, respTime - wrTime,)):
                      if testTime >= 60000.0:
                          over60s[index] += 1
                      elif testTime >= 30000.0:
                          over30s[index] += 1
                      elif testTime >= 10000.0:
                          over10s[index] += 1
                      elif testTime >= 1000.0:
                          over1s[index] += 1
                      elif testTime >= 100.0:
                          over100ms[index] += 1
                      elif testTime >= 10.0:
                          over10ms[index] += 1
                      else:
                          under10ms[index] += 1
                      if testTime >= 1000.0:
                          totalOver1s[index] += 1
                      if testTime >= 10000.0:
                          totalOver10s[index] += 1
  
                  ext = []
                  for key, value in extended.iteritems():
                      if key not in ('i', 't'):
                          if key == "cl":
                              value = float(value) / 1024
                              value = "%.1fKB" % (value,)
                              key = "req"
                          ext.append("%s:%s" % (key, value))
                  ext = ", ".join(ext)
  
                  try:
                      client = client.split(";")[2]
                      client = client.strip()
                  except:
                      pass
  
                  if userId != "-":
                      userStat = users.get(userId, {'count' : 0, 'clients' : {}})
                      userStat['count'] += 1
                      clientCount = userStat['clients'].get(client, 0)
                      userStat['clients'][client] = clientCount + 1
                      users[userId] = userStat
  
                  reqStartTime = logTime - datetime.timedelta(milliseconds=respTime)
                  requests.append((respTime, userId, method, bytes / 1024.0, ext, client, logId, logTime, reqStartTime))
  
          times.sort()
          if len(times) == 0:
              print("No data to analyze")
              time.sleep(10)
              continue
  
          totalRequests = sum(numRequests.values())
  
          print("- " * 40)
          print(datetime.datetime.now().strftime("%Y/%m/%d %H:%M:%S"),)
          if enableListenQueue:
              q, lqssl, lqnon = listenQueueHistory()
              print("Listenq (ssl+non):", q[0], " (Recent", ", ".join(q[1:]), "Oldest)")
          if enableCpuIdle:
              q = idleHistory()
              print("CPU idle %:", q[0], " (Recent", ", ".join(q[1:]), "Oldest)")
          if enableFreeMem:
              print("Memory free:", freemem())
          print("CPU Per Daemon:", cpuPerDaemon())
          print("")
  
          table = tables.Table()
          table.addHeader(
              ("Instance", "Requests", "Av. Requests", "Av. Response", "Av. Response", "Max. Response", "Slot", "Start", "End", "File Name"),
          )
          table.addHeader(
              ("", "", "per second", "(ms)", "no write(ms)", "(ms)", "Average", "Time", "Time", ""),
          )
          table.setDefaultColumnFormats(
              (
                  tables.Table.ColumnFormat("%s", tables.Table.ColumnFormat.CENTER_JUSTIFY),
                  tables.Table.ColumnFormat("%d", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%.1f", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%.1f", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%.1f", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%.1f", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%.2f", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%s", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%s", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%s", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
              )
          )
  
          totalAverage = 0.0
          totalResponseTime = 0.0
          totalResponseWithoutWRTime = 0.0
          maxResponseTime = 0.0
          totalSlots = 0
          minStartTime = None
          maxEndTime = None
          for ctr, filename in enumerate(sorted(perfile_times.keys())):
  
              times = sorted(perfile_times[filename])
              startTime = times[0]
              minStartTime = startTime if minStartTime is None else min(minStartTime, startTime)
  
              endTime = times[-1]
              maxEndTime = endTime if maxEndTime is None else min(maxEndTime, endTime)
  
              deltaTime = endTime - startTime
  
              avgRequests = float(len(times)) / deltaTime.seconds
              totalAverage += avgRequests
  
              avgResponse = totalRespTime[filename] / len(times)
              totalResponseTime += totalRespTime[filename]
  
              avgResponseWithWR = totalRespWithoutWRTime[filename] / len(times)
              totalResponseWithoutWRTime += totalRespWithoutWRTime[filename]
  
              maxResponseTime = max(maxResponseTime, maxRespTime[filename])
  
              totalSlots += slotCount[filename]
  
              table.addRow((
                  "#%s" % (ctr + 1,),
                  len(times),
                  avgRequests,
                  avgResponse,
                  avgResponseWithWR,
                  maxRespTime[filename],
                  float(slotCount[filename]) / len(times),
                  startTime,
                  endTime,
                  filename[prefix:],
              ))
  
          if len(perfile_times) > 1:
              table.addFooter((
                  "Total:",
                  totalRequests,
                  totalAverage,
                  totalResponseTime / totalRequests,
                  totalResponseWithoutWRTime / totalRequests,
                  maxResponseTime,
                  float(totalSlots) / totalRequests,
                  minStartTime,
                  maxEndTime,
                  "",
              ))
  
          os = StringIO()
          table.printTable(os=os)
          print(os.getvalue())
  
          if enableListenQueue:
              lqlatency = (lqssl / avgRequests, lqnon / avgRequests,) if avgRequests else (0.0, 0.0,)
              print(" listenq latency (ssl+non): %.1f s %.1f s" % (
                  lqlatency[0],
                  lqlatency[1],
              ))
  
          table = tables.Table()
          table.addHeader(
              ("", "<10ms", "10ms<->100ms", "100ms<->1s", "1s<->10s", "10s<->30s", "30s<->60s", ">60s", "Over 1s", "Over 10s"),
          )
          table.setDefaultColumnFormats(
              (
                  tables.Table.ColumnFormat("%s", tables.Table.ColumnFormat.CENTER_JUSTIFY),
                  tables.Table.ColumnFormat("%d (%.1f%%)", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%d (%.1f%%)", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%d (%.1f%%)", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%d (%.1f%%)", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%d (%.1f%%)", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%d (%.1f%%)", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%d (%.1f%%)", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%.1f%%", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
                  tables.Table.ColumnFormat("%.1f%%", tables.Table.ColumnFormat.RIGHT_JUSTIFY),
              )
          )
          for i in xrange(2):
              table.addRow((
                  "Overall Response" if i == 0 else "Response without Write",
                  (under10ms[i], safePercent(under10ms[i], totalRequests)),
                  (over10ms[i], safePercent(over10ms[i], totalRequests)),
                  (over100ms[i], safePercent(over100ms[i], totalRequests)),
                  (over1s[i], safePercent(over1s[i], totalRequests)),
                  (over10s[i], safePercent(over10s[i], totalRequests)),
                  (over30s[i], safePercent(over30s[i], totalRequests)),
                  (over60s[i], safePercent(over60s[i], totalRequests)),
                  safePercent(totalOver1s[i], totalRequests),
                  safePercent(totalOver10s[i], totalRequests),
              ))
          os = StringIO()
          table.printTable(os=os)
          print(os.getvalue())
          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):")
          for l in xrange((numProcs - 1) / 10 + 1):
              base = l * 10
              print("%2d-%2d: " % (base, base + 9),)
  
              for i in xrange(base, base + 10):
                  try:
                      r = ids[i]
                      s = "%1d" % (r,)
                  except KeyError:
                      s = "."
                  print(s, end="")
  
              print("    ", end="")
  
              for i in xrange(base, base + 10):
                  try:
                      r = timesSpent[i] / 1000
                      c = rawCounts[i]
                      s = "%4.0f(%4d)" % (r, c)
                  except KeyError:
                      s = "         ."
                  print(s, end="")
  
              print("")
  
          print("")
          print("Top %d longest (in most recent %d requests):" % (numTop, sum(numRequests.values()),))
          requests.sort()
          requests.reverse()
          for i in xrange(numTop):
              try:
                  respTime, userId, method, kb, ext, client, logId, logTime, reqStartTime = requests[i]
                  """
                  overlapCount = 0
                  for request in requests:
                      _respTime, _userId, _method, _kb, _ext, _client, _logId, _logTime, _reqStartTime = request
                      if _logId == logId and _logTime > reqStartTime and _reqStartTime < logTime:
                          overlapCount += 1
  
                  print("%7.1fms  %-12s %s res:%.1fKB, %s [%s] #%d +%d %s->%s" % (respTime, userId, method, kb, ext, client, logId, overlapCount, reqStartTime.strftime("%H:%M:%S"), logTime.strftime("%H:%M:%S"),))
                  """
                  print("%7.1fms  %-12s %s res:%.1fKB, %s [%s] #%d %s->%s" % (respTime, userId, method, kb, ext, client, logId, reqStartTime.strftime("%H:%M:%S"), logTime.strftime("%H:%M:%S"),))
              except:
                  pass
  
          print("")
          print("Top %d busiest users (in most recent %d requests):" % (numUsers, totalRequests,))
          userlist = []
          for user, userStat in users.iteritems():
              userlist.append((userStat['count'], user, userStat))
          userlist.sort()
          userlist.reverse()
          for i in xrange(numUsers):
              try:
                  count, user, userStat = userlist[i]
                  print("%3d  %-12s " % (count, user), end="")
                  clientStat = userStat['clients']
                  clients = clientStat.keys()
                  if len(clients) == 1:
                      print("[%s]" % (clients[0],))
                  else:
                      clientList = []
                      for client in clients:
                          clientList.append("%s: %d" % (client, clientStat[client]))
                      print("[%s]" % ", ".join(clientList))
              except:
                  pass
  
          print
  
          # lineRange => do loop only once
          if lineRange is not None:
              break
  
      except Exception, e:
          print("Script failure", e)
          if debug:
              print(traceback.print_exc())
  
      time.sleep(10)
  