apps: add time to connect to shill log processor
Add additional summary information to the manager and service sections
of the shill log processor.
In the manager section, the time from suspendDone to Online is
recorded. This is the elapsed time from the suspendDone message to the
first connection (service in Online state). In cases where there is a
suspendDone, but not a connection, the time is displayed as [NA_].
In the service section, the elapsed time for each connection attempt is
noted. This includes all attempts from associating to online or
failure. If an associating state is detected without a corresponding
end state [NA_] is displayed, otherwise the elapsed time is displayed.
Example:
Manager 1 00:01:31.172
suspendDone to Online: [00:00:07.280]
Active Service 2: Associating --> Configuring --> Connected --> Online
--> Idle
Connections: 1
Time to Connect [assoc to online or failure (O|F)]: [00:00:04.748
(O)]
Active Service 0: Associating --> Configuring --> Connected --> Online
Connections: 1
Time to Connect [assoc to online or failure (O|F)]: [00:00:05.240
(O)]
BUG=chromium:470649
TEST=ran "grunt test" and manually tested with multiple logs
Change-Id: I77dd2109f1ddbd4ffcefa8d67b8c24e132af2a60
diff --git a/log_summary.js b/log_summary.js
index 47bcac7..25b66ae 100644
--- a/log_summary.js
+++ b/log_summary.js
@@ -4,7 +4,7 @@
'use strict';
/**
- * @fileoverview Class to hold state and process netlog messages.
+ * @fileoverview Class to hold state while processing netlog messages.
*/
/** @constructor */
diff --git a/manager.js b/manager.js
index 635a767..cd0cef1 100644
--- a/manager.js
+++ b/manager.js
@@ -22,6 +22,7 @@
this.scanDetails = [];
this.endTime = -1;
this.suspendDetails = [];
+ this.connFromSuspend = [];
}
/**
@@ -139,6 +140,11 @@
return;
}
+ // add logic for tracking connection time after suspend
+ if ((eventType == 'suspend' || eventType == 'darksuspend') && eventDone) {
+ this.connFromSuspend.push({'suspendDone': time, 'conn': null});
+ }
+
var eventCount = events.length;
var lastEvent = null;
if (eventDone) {
diff --git a/netlog_summary.js b/netlog_summary.js
index 534f286..0ca5646 100644
--- a/netlog_summary.js
+++ b/netlog_summary.js
@@ -60,6 +60,7 @@
re: /Service (\d+) updated; state:* (\w+) failure:* (\D+)/,
handler: function(processingState, result) {
var logSummary = processingState.logSummary;
+ var currentManager = processingState.currentManager;
var id = result[1];
var state = result[2];
var failure = result[3];
@@ -71,13 +72,22 @@
console.log('managers.length: ' + logSummary.managers.length);
console.log('managers: ', logSummary.managers);
console.log('failure: ' + failure);
- var currentService = processingState.currentManager.getService(id);
+ var currentService = currentManager.getService(id);
var update = {state: state, time: processingState.time[0]};
if (failure) {
update.failure = failure;
}
currentService.addUpdate(update);
console.log(currentService);
+ if (state == 'Online') {
+ // add logic to track time to connect from suspend
+ var connFromSuspend = currentManager.connFromSuspend;
+ var cLength = connFromSuspend.length;
+ if (cLength > 0 && !connFromSuspend[cLength - 1].conn) {
+ connFromSuspend[cLength - 1].conn =
+ Date.parse(processingState.time[0]) - currentManager.startTime;
+ }
+ }
if (currentService.isActive) {
return 'serviceStateActive';
}
diff --git a/process_log.js b/process_log.js
index 0adb3d0..8c23c72 100644
--- a/process_log.js
+++ b/process_log.js
@@ -114,10 +114,28 @@
var managers = logSummary.managers;
for (var i = 0; i < managers.length; i++) {
var mInfo = document.createElement('p');
- mInfo.innerText = 'Manager ' + managers[i].id +
- ' ' +
- logHelper.formatElapsedMS(
- managers[i].endTime - managers[i].startTime);
+ mInfo.innerText = 'Manager ' + managers[i].id + ' ' +
+ logHelper.formatElapsedMS(managers[i].endTime - managers[i].startTime);
+
+ if (managers[i].connFromSuspend.length > 0) {
+ var suspendConnInfo = document.createElement('p');
+ var suspendConnTimes = managers[i].connFromSuspend;
+ suspendConnInfo.innerText = 'suspendDone to Online:';
+ for (var w = 0; w < suspendConnTimes.length; w++) {
+ if (suspendConnTimes[w].suspendDone && suspendConnTimes[w].conn) {
+ var t = logHelper.formatElapsedMS(
+ suspendConnTimes[w].conn - suspendConnTimes[w].suspendDone);
+ suspendConnInfo.innerText += ' [' + t + '] ';
+ }
+ else if (suspendConnTimes[w].suspendDone) {
+ suspendConnInfo.innerText += ' [NA_] ';
+ } else {
+ suspendConnInfo.innerText += ' [_NA] ';
+ }
+ }
+ mInfo.appendChild(suspendConnInfo);
+ }
+
var activeService = '';
var failures;
for (var j = 0; j < managers[i].services.length; j++) {
@@ -143,6 +161,28 @@
stateInfo.appendChild(connCountInfo);
activeService = '';
+ if (managers[i].services[j].connections > 0) {
+ var connTimeInfo = document.createElement('p');
+ var connTimes = managers[i].services[j].connectionTimes;
+ connTimeInfo.innerText = 'Time to Connect [assoc to ' +
+ 'online or failure (O|F)]:';
+ for (var w = 0; w < connTimes.length; w++) {
+ if (connTimes[w].start && connTimes[w].end) {
+ var t = logHelper.formatElapsedMS(
+ connTimes[w].end - connTimes[w].start);
+ connTimeInfo.innerText +=
+ ' [' + t + ' (' + connTimes[w].type + ')] ';
+ }
+ else if (connTimes[w].start) {
+ connTimeInfo.innerText +=
+ ' [NA_ (' + connTimes[w].type + ')] ';
+ } else {
+ connTimeInfo.innerText += ' [_NA] ';
+ }
+ }
+ stateInfo.appendChild(connTimeInfo);
+ }
+
if (failures != '') {
var failureInfo = document.createElement('p');
failureInfo.innerText = 'Failures: ' + failures;
diff --git a/service.js b/service.js
index bccac68..74e0313 100644
--- a/service.js
+++ b/service.js
@@ -19,6 +19,7 @@
this.isActive = false;
this.connections = 0;
this.graphData = [];
+ this.connectionTimes = [];
}
/**
@@ -51,8 +52,27 @@
this.states.push(update);
}
this.graphData.push({'x': update.time, 'y': update.state});
+
+ var connTimeLength = this.connectionTimes.length;
if (update.state == 'Associating') {
this.connections++;
+ this.connectionTimes.push({'start': Date.parse(update.time),
+ 'end': null,
+ 'type': '?'});
+ } else if (update.state == 'Failure') {
+ if (connTimeLength > 0) {
+ if (!this.connectionTimes[connTimeLength - 1].end) {
+ this.connectionTimes[connTimeLength - 1].end = Date.parse(update.time);
+ this.connectionTimes[connTimeLength - 1].type = 'F';
+ }
+ }
+ } else if (update.state == 'Online') {
+ if (connTimeLength > 0) {
+ if (!this.connectionTimes[connTimeLength - 1].end) {
+ this.connectionTimes[connTimeLength - 1].end = Date.parse(update.time);
+ this.connectionTimes[connTimeLength - 1].type = 'O';
+ }
+ }
}
};
