Calculating gaps between full CMS cycles

While troubleshooting a performance issue, we had a need to graph the number of seconds between full collections.

We used what is below. This assumes you have added -XX:+PrintGCDetails and -XX:+PrintGCDateStamps as well as a file location for -Xloggc: to your startup script. You can use the output in Excel, or pipe it to another scripting language such as awk for additional dynamic reporting.

The output fields are start time, finish time, seconds for collection to run, and the number of seconds since the completion and the previous cycle and the start of this one.

#!/usr/bin/env python

import datetime, time, sys
startTime = 0
finishTime = 0
gap = -1
for line in open(sys.argv[1],"r"):
  if line.find("CMS-initial-mark:") > -1:
    start = line.split(" ")[0].split(".")[0]
    tmp = line.split(" ")[0].split(".")[0]
    startTime = time.mktime(time.strptime(tmp,'%Y-%m-%dT%H:%M:%S'))
    if finishTime != 0:
      gap = startTime - finishTime
  elif line.find("CMS-concurrent-reset:") > -1:
    finish = line.split(" ")[0].split(".")[0]
    tmp = time.strptime(line.split(" ")[0].split(".")[0],'%Y-%m-%dT%H:%M:%S')
    finishTime = time.mktime(tmp)
    duration = finishTime - startTime
    if gap != -1:
      print start,finish,duration, gap