Add "start" annotation to event rate chart, showing each time a corre…

…lator process was started or restarted.

CHANGELOG.rst

@@ -1,5 +1,6 @@
 3.4
 ---
+- Add "start" annotation to event rate chart, showing each time a correlator process was started or restarted. 
 - Remove .zip (or similar) extension from auto-generated output directory name when unpacking an archive, to avoid confusion. 
 - Avoid negative event rate values when a correlator restart occurs within a log file. 
 

apamax/log_analyzer.py

@@ -595,6 +595,7 @@ def handleFileStarted(self, file, **extra):
 		file['totalStatusLinesInFile'] = 0
 
 		file['startupStanzas'] = [{}]
+		file['annotations'] = []
 		file['inStartupStanza'] = False
 
 		file['connectionMessages'] : List = []
@@ -781,6 +782,12 @@ def decideColumns(status):
 
 		seconds = status['epoch secs'] # floating point epoch seconds
 
+		if (not previousStatus) or (previousStatus['restarts'] != len(file['startupStanzas'])): 
+			if file['startupStanzas'][-1].get('startTime'): # this is the only place we can add the annotation given we must associated it with a timestamp that's in the data series
+				file['annotations'].append({'x': line.getDateTime(), 'shortText':'start', 'width':40, 
+					'text': f"Correlator process {'started' if len(file['startupStanzas'])==1 else 'restart #%s'%(len(file['startupStanzas'])-1)}"})
+
+
 		if previousStatus is None:
 			if file['startTime'] is not None:
 				secsSinceLast = status['epoch secs']-file['startTime'].replace(tzinfo=datetime.timezone.utc).timestamp()
@@ -1667,7 +1674,7 @@ def v(val, cls='overview-value', fmt=None): # values are escaped then put into a
 						ss = file['startupStanzas'][stanzaNum]
 
 						ov['Process id:'] = f"{v(ss.get('pid') or '?',cls='overview-pid overview-value')}"
-						if stanzaNum > 0: ov['Process id:']+= " "+v(f"restart #{stanzaNum+1}")+f" at {v(ss.get('startTime'))} (line {ss['startLineNumber']})"
+						if stanzaNum > 0: ov['Process id:']+= " "+v(f"restart #{stanzaNum}")+f" at {v(ss.get('startTime'))} (line {ss['startLineNumber']})"
 
 						ov['Apama version:'] = f"{v(ss.get('apamaVersion', '?'))}{', apama-ctrl: '+v(file['apamaCtrlVersion']) if file.get('apamaCtrlVersion') else ''}; running on {v(ss.get('OS'))}"
 						ov['Log timezone:'] = f"{v(ss.get('utcOffset') or '?')}"+(f" ({v(ss.get('timezoneName'))})" if ss.get('timezoneName') else '')
@@ -1935,8 +1942,16 @@ def writeOverviewHTMLForAllFiles(self, overviewHTML, **extra):
 						shutil.copyfileobj(datafile, out)
 					os.remove(tmpfile)
 					out.write('],\n'+json.dumps(options)[:-1]+',"legendFormatter":legendFormatter}'+'\n);\n')
-					out.write('\ncharts.push(g); </script>\n')
+					out.write('\ncharts.push(g);\n')
+					if c == 'rates':
+						for a in file['annotations']:
+							dt = a['x']
+							a['x'] = f"new Date({dt.year},{dt.month-1},{dt.day},{dt.hour},{dt.minute},{dt.second}).getTime()"
+							a.update({'series':'rx /sec', 'attachAtBottom':True})
+						out.write('g.setAnnotations('+re.sub('"(new [^"]*)"', "\\1", json.dumps(file['annotations'])+')'))
+					out.write('</script>\n')
 
+
 			out.write(self.HTML_END)
 		if os.path.exists(os.path.join(self.outputdir, 'tmp')):
 			shutil.rmtree(os.path.join(self.outputdir, 'tmp'))

tests/correctness/Cor_012/Reference/ref-overview.txt

@@ -11,9 +11,9 @@
   Notable:        noLicenseConstrainedMode
   Clean shutdown: Requested at Mon 2019-10-14 22:26:59 (reason: I want you to shut down)
 
-  Process id:     14572 restart #2 at Mon 2019-10-14 22:27:06 (line 65)
+  Process id:     14572 restart #1 at Mon 2019-10-14 22:27:06 (line 65)
 
-  Process id:     66760 restart #3 at Mon 2019-10-14 22:27:11 (line 128)
+  Process id:     66760 restart #2 at Mon 2019-10-14 22:27:11 (line 128)
 
 
 - #02 correlator-10.3.1.0-win.log
@@ -63,4 +63,4 @@
   Fri 2019-10-04 19:02:53 to 19:03:04 (=0:00:10)
 
 
-Generated by Apama log analyzer v3.4.dev/2020-01-02.
+Generated by Apama log analyzer v3.4.dev/2020-02-07.

tests/correctness/Cor_012/run.py

@@ -52,6 +52,10 @@ def validate(self):
 			for statusline in s:
 				for k in ['interval secs', 'rx /sec', 'tx /sec', 'log lines /sec']:
 					self.assertEval('{val} >= 0', val=statusline[k], key=k)
+
+		# check for annotations for start and restart on chart
+		self.assertGrep(outputdir+'/overview.html', expr='setAnnotations[(].*new Date[(]2019,9,14,22,26,59[)].*"text": "Correlator process started"')
+		self.assertGrep(outputdir+'/overview.html', expr='setAnnotations[(].*new Date[(]2019,9,14,22,27,6[)].*"text": "Correlator process restart #1"')
 
 		# strip out the stats since we test them elsewhere
 		self.copy(outputdir+'/overview.txt', 'overview-without-stats.txt', mappers=[