apps: create state tracking object for WifiStateMachine that holds notes
When processing Android logs, state will be kept in a new
WifiStateMachine object. This object holds an array of notes. The
notes are comprised of flagged messages that were found during
processing.
After processing, the log processor displays a summary for the supplied
log. In this summary, the notes for the WifiStateMachine are displayed.
Each note contains a link to the (highlighted) log line in the displayed
log.
Two tests were also added:
1. Test for proper regular expression matching for the Android log
timestamp.
2. A sample log is processed and the resulting WifiStateMachine object
is confirmed to have the correct number of notes when complete.
BUG=chromium:577353
TEST=manually with Chrome OS, Brillo and Android logs
TEST=ran 'grunt test'
Change-Id: I2935f7bb0408dc8427f3fc52fd96c5beeda2ca56
diff --git a/Gruntfile.js b/Gruntfile.js
index fd4d27e..cc0d119 100644
--- a/Gruntfile.js
+++ b/Gruntfile.js
@@ -28,7 +28,8 @@
'./manager.js',
'./netlog_summary.js',
'./service.js',
- './syslog_summary.js'
+ './syslog_summary.js',
+ './wifi_state_machine.js'
],
options: {
'specs': 'test/spec/**/*.js'
diff --git a/androidlog_summary.js b/androidlog_summary.js
index d0ead0d..f09fd4b 100644
--- a/androidlog_summary.js
+++ b/androidlog_summary.js
@@ -10,21 +10,6 @@
var androidlogSummary = {};
/**
- * Object used for passing state between main processing loop and
- * regeular expression handler functions.
- * @constructor
- * @type {Object}
- * @param {LogSummary} logSummary object holding log state after processing
- * @param {String} time timestamp of current log line
- * @param {String[]} results results from regex test
- */
-function AndroidlogProcessingState(logSummary, time, results) {
- this.logSummary = logSummary;
- this.time = time;
- this.results = results;
-}
-
-/**
* RegExp for android log line.
* @type {RegExp}
*/
@@ -39,7 +24,9 @@
'supplicant_disconnected': {
re: /wpa_supplicant: wlan0: CTRL-EVENT-DISCONNECTED /,
handler: function(processingState, result) {
- // TODO: this will be added to a summary notes section
+ logHelper.addNote(processingState.wifiStateMachine,
+ processingState.time,
+ result[0]);
}
}
};
@@ -55,46 +42,81 @@
* was processed, null if the log is not a recognized format.
*/
androidlogSummary.processLogLines = function(logLines, logSummary) {
- var logStart = -1;
- var time;
+
+ /**
+ * Object used for passing state between main processing loop and
+ * regeular expression handler functions.
+ * @constructor
+ * @type {Object}
+ * @param {LogSummary} logSummary object holding log state after processing
+ * @param {String} time timestamp of current log line
+ * @param {String[]} results results from regex test
+ */
+ function AndroidlogProcessingState(logSummary, time, results) {
+ this.logSummary = logSummary;
+ this.time = time;
+ this.results = results;
+ }
+
+ var logLineTime;
var logText = [];
- var timeCheck;
- var result = null;
- var processingState = new ProcessingState(logSummary, null, null, null);
+ var parsedLogLineTime;
+ var processingState = new AndroidlogProcessingState(logSummary, null, null);
var logType = 'android';
for (var i = 0; i < logLines.length; i++) {
console.log('processing log line: ' + logLines[i]);
- time = logLines[i].match(logHelper.ANDROID_TIME_FORMAT);
- processingState.time = time;
- if (time == null) {
- console.log('not a valid time... continue');
+ logLineTime = logLines[i].match(logHelper.ANDROID_TIME_FORMAT);
+ if (logLineTime === null) {
+ console.log('not a valid time... skip the log line');
continue;
}
- timeCheck = Date.parse(time[0]);
+ processingState.time = logLineTime[0];
+ parsedLogLineTime = Date.parse(processingState.time);
+
+ if (logSummary.logStartTime == -1) {
+ logSummary.logStartTime = parsedLogLineTime;
+ // This is the start of our log so we need to add the first
+ // WifiStateMachine instance.
+ processingState.wifiStateMachine =
+ new WifiStateMachine(1,
+ parsedLogLineTime,
+ logHelper.getOffsetMS(processingState.time));
+ logSummary.wifiStateMachines.push(processingState.wifiStateMachine);
+ }
+
+ if (parsedLogLineTime < logSummary.logEndTime) {
+ console.log('warning: log time has rolled back, check timezone');
+ } else {
+ logSummary.logEndTime = parsedLogLineTime;
+ }
var tempLogText = {text: logLines[i],
- tag: time[0],
+ tag: null,
type: 'basic',
file: logType,
- ts: timeCheck};
- result = null;
+ ts: parsedLogLineTime};
+
for (var taggedLine in androidlogSummary.taggedLines) {
var result = logLines[i].match(
androidlogSummary.taggedLines[taggedLine].re);
- if (result != null) {
+ if (result !== null) {
tempLogText.type =
androidlogSummary.taggedLines[taggedLine].handler(processingState,
result);
+ // Since this line does have a match with the flagged log lines, create
+ // a tag that allows the summary notes to link to the displayed log.
+ tempLogText.tag = processingState.time;
break;
}
}
- if (!result) {
- tempLogText.tag = null;
- }
logText.push(tempLogText);
}
+ if (logSummary.wifiStateMachines.length > 0) {
+ logSummary.wifiStateMachines[logSummary.wifiStateMachines.length - 1]
+ .endTime = logSummary.logEndTime;
+ }
return logText;
};
diff --git a/log_summary.js b/log_summary.js
index f52b04d..59f77fc 100644
--- a/log_summary.js
+++ b/log_summary.js
@@ -10,6 +10,7 @@
/** @constructor */
function LogSummary() {
this.managers = [];
+ this.wifiStateMachines = [];
this.logStartTime = -1;
this.logEndTime = -1;
this.prevLogLineTime = -1;
diff --git a/netlog_summary.js b/netlog_summary.js
index fea6bef..977a754 100644
--- a/netlog_summary.js
+++ b/netlog_summary.js
@@ -451,11 +451,27 @@
* was processed, null if the log is not a recognized format.
*/
netlogSummary.processLogLines = function(logLines, logSummary) {
+ /**
+ * Object used for passing state between main processing loop and
+ * regeular expression handler functions.
+ * @constructor
+ * @type {Object}
+ * @param {LogSummary} logSummary object holding log state after processing
+ * @param {Manager} currentManager object of the current manager in log
+ * @param {String} time timestamp of current log line
+ * @param {String[]} results results from regex test
+ */
+ function ProcessingState(logSummary, currentManager, time, results) {
+ this.logSummary = logSummary;
+ this.currentManager = currentManager;
+ this.time = time;
+ this.results = results;
+ }
+
var logStart = -1;
var time;
var logText = [];
var timeCheck;
- var result = null;
var processingState = new ProcessingState(logSummary, null, null, null);
var logType = 'netlog';
@@ -476,7 +492,7 @@
}
logHelper.getOffsetMS(time);
timeCheck = Date.parse(time[0]);
- if (logStart == -1 && time != null) {
+ if (logStart == -1 && time !== null) {
logStart = time[0];
logSummary.logStartTime = timeCheck;
logSummary.prevLogLineTime = logSummary.logStartTime;
@@ -498,23 +514,20 @@
}
console.log('log_line: ' + logLines[i]);
var tempLogText = {text: logLines[i],
- tag: time[0],
+ tag: null,
type: 'basic',
file: logType,
ts: timeCheck};
- result = null;
for (var taggedLine in netlogSummary.taggedLines) {
var result = logLines[i].match(netlogSummary.taggedLines[taggedLine].re);
- if (result != null) {
+ if (result !== null) {
tempLogText.type =
netlogSummary.taggedLines[taggedLine].handler(processingState,
result);
+ tempLogText.tag = time[0];
break;
}
}
- if (!result) {
- tempLogText.tag = null;
- }
logText.push(tempLogText);
}
diff --git a/process_log.js b/process_log.js
index d2850c8..6f0e40a 100644
--- a/process_log.js
+++ b/process_log.js
@@ -80,6 +80,10 @@
displayLogSummary(logSummary);
displayServiceSummary(logSummary);
}
+ if (logHolder.androidlog) {
+ displayAndroidLogSummary(logSummary);
+ }
+
if (logHolder.syslog || logHolder.netlog ||
logHolder.brillolog || logHolder.androidlog) {
displayLog(logHolder);
@@ -107,6 +111,61 @@
}
/**
+ * Method to display log-level summary information after processing the
+ * Android log.
+ *
+ * @param {LogSummary} logSummary Object to hold state read from log.
+ * @private
+ */
+
+function displayAndroidLogSummary(logSummary) {
+ console.log('inside android log summary!');
+ var wsm = document.getElementsByClassName('managers')[0];
+ var logHeader = document.createElement('h2');
+ logHeader.innerText = 'Log Summary';
+ wsm.appendChild(logHeader);
+
+ var timeInfo = document.createElement('p');
+ timeInfo.innerText = 'Total Log Time: ' +
+ logHelper.formatElapsedMS(logSummary.logEndTime -
+ logSummary.logStartTime);
+ wsm.appendChild(timeInfo);
+
+ var wifiStateMachines = logSummary.wifiStateMachines;
+ var wsmInfo;
+ for (var i = 0; i < wifiStateMachines.length; i++) {
+ wsmInfo = document.createElement('p');
+ wsmInfo.innerText = 'WifiStateMachine ' + wifiStateMachines[i].id + ": " +
+ logHelper.formatElapsedMS(wifiStateMachines[i].endTime -
+ wifiStateMachines[i].startTime);
+ wsm.appendChild(wsmInfo);
+
+ //TODO: add post processing for WSM states before graphing
+ }
+
+ //Now add in notes for the WSM
+ var wsmHeader = document.createElement('h2');
+ wsmHeader.innerText = 'WifiStateMachines';
+ wsm.appendChild(wsmHeader);
+
+ var wsmOL = document.createElement('ol');
+ var wifiStateMachineNotes;
+ for (var i = 0; i < wifiStateMachines.length; i++) {
+ wifiStateMachineNotes = document.createElement('li');
+ wifiStateMachineNotes.id = 'wsm_' + i;
+ wifiStateMachineNotes.innerText = 'WifiStateMachine ' +
+ wifiStateMachines[i].id;
+ wifiStateMachineNotes.className = 'wsm';
+ if (wifiStateMachines[i].notes && wifiStateMachines[i].notes.length > 0) {
+ wifiStateMachineNotes.appendChild(
+ displayNotes(logSummary, wifiStateMachines[i].notes));
+ }
+ wsmOL.appendChild(wifiStateMachineNotes);
+ }
+ wsm.appendChild(wsmOL);
+}
+
+/**
* Method to display log-level summary information after processing the log.
*
* @param {LogSummary} logSummary Object to hold state read from log.
diff --git a/service_states.html b/service_states.html
index b27f907..e1cc89d 100644
--- a/service_states.html
+++ b/service_states.html
@@ -14,6 +14,7 @@
<script src="process_log.js"></script>
<script src="syslog_summary.js"></script>
<script src="androidlog_summary.js"></script>
+ <script src="wifi_state_machine.js"></script>
</head>
<body>
<h1>ChromeOS Network Log Processor</h1>
diff --git a/syslog_summary.js b/syslog_summary.js
index 888fd23..9bc7e5c 100644
--- a/syslog_summary.js
+++ b/syslog_summary.js
@@ -10,21 +10,6 @@
var syslogSummary = {};
/**
- * Object used for passing state between main processing loop and
- * regeular expression handler functions.
- * @constructor
- * @type {Object}
- * @param {LogSummary} logSummary object holding log state after processing
- * @param {String} time timestamp of current log line
- * @param {String[]} results results from regex test
- */
-function SyslogProcessingState(logSummary, time, results) {
- this.logSummary = logSummary;
- this.time = time;
- this.results = results;
-}
-
-/**
* RegExp for kernel info logging lines.
* @type {RegExp}
*/
@@ -106,6 +91,21 @@
* was processed, null if the log is not a recognized format.
*/
syslogSummary.processLogLines = function(logLines, logSummary) {
+ /**
+ * Object used for passing state between main processing loop and
+ * regeular expression handler functions.
+ * @constructor
+ * @type {Object}
+ * @param {LogSummary} logSummary object holding log state after processing
+ * @param {String} time timestamp of current log line
+ * @param {String[]} results results from regex test
+ */
+ function SyslogProcessingState(logSummary, time, results) {
+ this.logSummary = logSummary;
+ this.time = time;
+ this.results = results;
+ }
+
var logText = [];
var time;
var processingState = new SyslogProcessingState(logSummary, null, null);
@@ -125,11 +125,11 @@
tag = null;
for (var taggedLine in syslogSummary.taggedLines) {
var result = logLines[i].match(syslogSummary.taggedLines[taggedLine].re);
- if (result != null) {
+ if (result !== null) {
processingState.time = time[0];
processingState.result = result;
type = syslogSummary.taggedLines[taggedLine].handler(processingState);
- if (type == null) {
+ if (type === null) {
tag = null;
} else {
tag = time[0];
diff --git a/test/spec/AndroidlogSummarySpec.js b/test/spec/AndroidlogSummarySpec.js
new file mode 100644
index 0000000..4bbf78c
--- /dev/null
+++ b/test/spec/AndroidlogSummarySpec.js
@@ -0,0 +1,51 @@
+// Copyright 2016 The Chromium OS Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+/**
+ * @fileoverview Jasmine test file for androidlog_summary.js.
+ */
+
+describe('AndroidlogSummary', function() {
+ var logSummary;
+ var basicLog;
+ var time1;
+ var time2;
+ var time3;
+
+ beforeEach(function() {
+ logSummary = new LogSummary();
+ time1 = '01-04 14:45:37.720';
+ time2 = '01-04 14:45:37.721';
+ time3 = '01-04 14:45:37.722';
+
+ basicLog = [
+ time1 + ' wpa_supplicant: Deauthentication frame IE(s)' +
+ ' - hexdump(len=0): [NULL]',
+ time2 + ' wpa_supplicant: wlan0: CTRL-EVENT-DISCONNECTED' +
+ ' bssid=24:de:c6:e0:89:51 reason=3 locally_generated=1',
+ time3 + ' WifiStateMachine: setDetailed state, old =OBTAINING_IPADDR' +
+ ' and new state=DISCONNECTED hidden=false'
+ ];
+
+ });
+
+ it('should properly match the Android log time format', function() {
+ var regexMatchTime = time1.match(logHelper.ANDROID_TIME_FORMAT)[0];
+ expect(regexMatchTime).toEqual(time1);
+ });
+
+ it('should detect wpa_supplicant disconnects and add to notes', function() {
+ androidlogSummary.processLogLines(basicLog, logSummary);
+ expect(logSummary.wifiStateMachines.length).toBe(1);
+ expect(logSummary.wifiStateMachines[0].notes.length).toBe(1);
+ });
+
+ it('should skip a log line without a valid timestamp', function() {
+ var log = [' wpa_supplicant: Deauthentication frame IE(s)' +
+ ' - hexdump(len=0): [NULL]'];
+ androidlogSummary.processLogLines(log, logSummary);
+ expect(logSummary.wifiStateMachines.length).toBe(0);
+ expect(logSummary.logStartTime).toBe(-1);
+ });
+});
diff --git a/wifi_state_machine.js b/wifi_state_machine.js
new file mode 100644
index 0000000..eae4532
--- /dev/null
+++ b/wifi_state_machine.js
@@ -0,0 +1,27 @@
+// Copyright 2016 The Chromium OS Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+'use strict';
+
+/**
+ * @fileoverview WiFiStateMachine class to represent and hold state for each
+ * instance of an Android WiFiStateMachine for a given log being processed.
+ */
+
+/**
+ * @constructor
+ *
+ * @param {String} id Identifier for new WifiStateMachine instance.
+ * @param {long} ms WifiStateMachine start time in ms.
+ * @param {long} offset WifiStateMachine log time offset in ms.
+ */
+function WifiStateMachine(id, ms, offset) {
+ this.id = id;
+ this.startTime = ms;
+ this.scans = 0;
+ this.scanDetails = [];
+ this.states = [];
+ this.endTime = -1;
+ this.timeOffset = offset;
+ this.supplicantStates = [];
+}
