Commit bc62b5a5 authored by mmenke@chromium.org's avatar mmenke@chromium.org

net-internals: When viewing a loaded log, display time

how long it's been since idle sources have logged their
most recent event.

BUG=139830

Review URL: https://chromiumcodereview.appspot.com/10825116

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@149341 0039d316-1c4b-4281-b951-d872f2087c98
parent ff97e164
......@@ -24,7 +24,8 @@ function canCollapseBeginWithEnd(beginEntry) {
* Adds a child pre element to the end of |parent|, and writes the
* formatted contents of |logEntries| to it.
*/
printLogEntriesAsText = function(logEntries, parent, enableSecurityStripping) {
printLogEntriesAsText = function(logEntries, parent, enableSecurityStripping,
logCreationTime) {
var entries = LogGroupEntry.createArrayFrom(logEntries);
var tablePrinter = new TablePrinter();
var parameterOutputter = new ParameterOutputter(tablePrinter);
......@@ -32,8 +33,7 @@ printLogEntriesAsText = function(logEntries, parent, enableSecurityStripping) {
if (entries.length == 0)
return;
var startDate = timeutil.convertTimeTicksToDate(entries[0].orig.time);
var startTime = startDate.getTime();
var startTime = timeutil.convertTimeTicksToTime(entries[0].orig.time);
for (var i = 0; i < entries.length; ++i) {
var entry = entries[i];
......@@ -41,16 +41,8 @@ printLogEntriesAsText = function(logEntries, parent, enableSecurityStripping) {
// Avoid printing the END for a BEGIN that was immediately before, unless
// both have extra parameters.
if (!entry.isEnd() || !canCollapseBeginWithEnd(entry.begin)) {
tablePrinter.addRow();
tablePrinter.addCell('t=');
var date = timeutil.convertTimeTicksToDate(entry.orig.time);
var tCell = tablePrinter.addCell(date.getTime());
tCell.alignRight = true;
tablePrinter.addCell(' [st=');
var stCell = tablePrinter.addCell(date.getTime() - startTime);
stCell.alignRight = true;
tablePrinter.addCell('] ');
var entryTime = timeutil.convertTimeTicksToTime(entry.orig.time);
addRowWithTime(tablePrinter, entryTime, startTime);
for (var j = entry.getDepth(); j > 0; --j)
tablePrinter.addCell(' ');
......@@ -62,6 +54,8 @@ printLogEntriesAsText = function(logEntries, parent, enableSecurityStripping) {
// Definite time.
if (entry.end) {
dt = entry.end.orig.time - entry.orig.time;
} else if (logCreationTime != undefined) {
dt = (logCreationTime - entryTime) + '+';
}
eventText += ' [dt=' + dt + ']';
}
......@@ -80,10 +74,38 @@ printLogEntriesAsText = function(logEntries, parent, enableSecurityStripping) {
}
}
// If viewing a saved log file, add row with just the time the log was
// created, if the event never completed.
if (logCreationTime != undefined &&
entries[entries.length - 1].getDepth() > 0) {
addRowWithTime(tablePrinter, logCreationTime, startTime);
}
// Format the table for fixed-width text.
tablePrinter.toText(0, parent);
}
/**
* Adds a new row to the given TablePrinter, and adds five cells containing
* information about the time an event occured.
* Format is '[t=<UTC time in ms>] [st=<ms since the source started>]'.
* @param {TablePrinter} tablePrinter The table printer to add the cells to.
* @param {number} eventTime The time the event occured, as a UTC time in
* milliseconds.
* @param {number} startTime The time the first event for the source occured,
* as a UTC time in milliseconds.
*/
function addRowWithTime(tablePrinter, eventTime, startTime) {
tablePrinter.addRow();
tablePrinter.addCell('t=');
var tCell = tablePrinter.addCell(eventTime);
tCell.alignRight = true;
tablePrinter.addCell(' [st=');
var stCell = tablePrinter.addCell(eventTime - startTime);
stCell.alignRight = true;
tablePrinter.addCell('] ');
}
/**
* |hexString| must be a string of hexadecimal characters with no whitespace,
* whose length is a multiple of two. Writes multiple lines to |out| with
......
......@@ -288,7 +288,7 @@ var SourceEntry = (function() {
return timeutil.getCurrentTime();
} else {
var endTicks = this.entries_[this.entries_.length - 1].time;
return timeutil.convertTimeTicksToDate(endTicks).getTime();
return timeutil.convertTimeTicksToTime(endTicks);
}
},
......@@ -299,7 +299,7 @@ var SourceEntry = (function() {
*/
getDuration: function() {
var startTicks = this.entries_[0].time;
var startTime = timeutil.convertTimeTicksToDate(startTicks).getTime();
var startTime = timeutil.convertTimeTicksToTime(startTicks);
var endTime = this.getEndTime();
return endTime - startTime;
},
......@@ -309,8 +309,10 @@ var SourceEntry = (function() {
* of |parent|.
*/
printAsText: function(parent) {
// The date will be undefined if not viewing a loaded log file.
printLogEntriesAsText(this.entries_, parent,
SourceTracker.getInstance().getSecurityStripping());
SourceTracker.getInstance().getSecurityStripping(),
Constants.clientInfo.numericDate);
}
};
......
......@@ -20,6 +20,18 @@ var timeutil = (function() {
timeTickOffset = offset - 0;
}
/**
* The browser gives us times in terms of "time ticks" in milliseconds.
* This function converts the tick count to a Javascript "time", which is
* the UTC time in milliseconds.
*
* @param {String} timeTicks A time represented in "time ticks".
* @return {number} The Javascript time that |timeTicks| represents.
*/
function convertTimeTicksToTime(timeTicks) {
return timeTickOffset + (timeTicks - 0);
}
/**
* The browser gives us times in terms of "time ticks" in milliseconds.
* This function converts the tick count to a Date() object.
......@@ -28,8 +40,7 @@ var timeutil = (function() {
* @return {Date} The time that |timeTicks| represents.
*/
function convertTimeTicksToDate(timeTicks) {
var timeStampMs = timeTickOffset + (timeTicks - 0);
return new Date(timeStampMs);
return new Date(convertTimeTicksToTime(timeTicks));
}
/**
......@@ -88,6 +99,7 @@ var timeutil = (function() {
return {
setTimeTickOffset: setTimeTickOffset,
convertTimeTicksToTime: convertTimeTicksToTime,
convertTimeTicksToDate: convertTimeTicksToDate,
getCurrentTime: getCurrentTime,
addNodeWithDate: addNodeWithDate,
......
......@@ -101,7 +101,8 @@ TEST_F('NetInternalsTest', 'netInternalsLogViewPainterPrintAsText', function() {
div.innerHTML = '';
timeutil.setTimeTickOffset(testCase.tickOffset);
printLogEntriesAsText(testCase.logEntries, div,
testCase.enableSecurityStripping);
testCase.enableSecurityStripping,
testCase.logCreationTime);
// Strip any trailing newlines, since the whitespace when using innerText
// can be a bit unpredictable.
......@@ -112,6 +113,8 @@ TEST_F('NetInternalsTest', 'netInternalsLogViewPainterPrintAsText', function() {
}
runTestCase(painterTestURLRequest());
runTestCase(painterTestURLRequestIncomplete());
runTestCase(painterTestURLRequestIncompleteFromLoadedLog());
runTestCase(painterTestNetError());
runTestCase(painterTestHexEncodedBytes());
runTestCase(painterTestCertVerifierJob());
......@@ -130,11 +133,13 @@ TEST_F('NetInternalsTest', 'netInternalsLogViewPainterPrintAsText', function() {
/**
* Test case for a URLRequest. This includes custom formatting for load flags,
* request/response HTTP headers, dependent sources, as well as basic
* indentation and grouping.
* indentation and grouping. Also makes sure that no extra event is logged
* for finished sources when there's a logCreationTime.
*/
function painterTestURLRequest() {
var testCase = {};
testCase.tickOffset = '1337911098446';
testCase.logCreationTime = 1338864634013;
testCase.logEntries = [
{
......@@ -745,6 +750,79 @@ function painterTestURLRequest() {
return testCase;
}
/**
* Test case for a URLRequest that was not completed that did not come from a
* loaded log file.
*/
function painterTestURLRequestIncomplete() {
var testCase = {};
testCase.tickOffset = '1337911098446';
testCase.logEntries = [
{
'phase': EventPhase.PHASE_BEGIN,
'source': {
'id': 146,
'type': EventSourceType.URL_REQUEST
},
'time': '953534778',
'type': EventType.REQUEST_ALIVE
},
{
'params': {
'load_flags': 128,
'method': 'GET',
'priority': 4,
'url': 'http://www.google.com/'
},
'phase': EventPhase.PHASE_BEGIN,
'source': {
'id': 146,
'type': EventSourceType.URL_REQUEST
},
'time': '953534910',
'type': EventType.URL_REQUEST_START_JOB
},
{
'phase': EventPhase.PHASE_END,
'source': {
'id': 146,
'type': EventSourceType.URL_REQUEST
},
'time': '953534970',
'type': EventType.URL_REQUEST_START_JOB
},
];
testCase.expectedText =
't=1338864633224 [st= 0] +REQUEST_ALIVE [dt=?]\n' +
't=1338864633356 [st=132] URL_REQUEST_START_JOB [dt=60]\n' +
' --> load_flags = 128 (ENABLE_LOAD_TIMING)\n' +
' --> method = "GET"\n' +
' --> priority = 4\n' +
' --> url = "http://www.google.com/"';
return testCase;
}
/**
* Test case for a URLRequest that was not completed that came from a loaded
* log file.
*/
function painterTestURLRequestIncompleteFromLoadedLog() {
var testCase = painterTestURLRequestIncomplete();
testCase.logCreationTime = 1338864634013;
testCase.expectedText =
't=1338864633224 [st= 0] +REQUEST_ALIVE [dt=789+]\n' +
't=1338864633356 [st=132] URL_REQUEST_START_JOB [dt=60]\n' +
' --> load_flags = 128 (ENABLE_LOAD_TIMING)\n' +
' --> method = "GET"\n' +
' --> priority = 4\n' +
' --> url = "http://www.google.com/"\n' +
't=1338864634013 [st=789]';
return testCase;
}
/**
* Tests the custom formatting of net_errors across several different event
* types.
......@@ -1294,7 +1372,7 @@ function painterTestStripCookiesURLRequest() {
var testCase = painterTestDontStripCookiesURLRequest();
testCase.enableSecurityStripping = true;
testCase.expectedText =
testCase.expectedText.replace(/MyMagicPony/g, '[value was stripped]');
testCase.expectedText.replace(/MyMagicPony/g, '[value was stripped]');
return testCase;
}
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment