First pass at adding http/backend cache to NetLog

chrome/browser/resources/net_internals/logviewpainter.js

 // Copyright (c) 2010 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 /**
  * TODO(eroman): This needs better presentation, and cleaner code. This
  *               implementation is more of a transitionary step as
  *               the old net-internals is replaced.
  */
 
@@ skipping 31 matching lines @@
   var startDate = g_browser.convertTimeTicksToDate(logEntries[0].time);
   addTextNode(nobr2, 'Start Time: ' + startDate.toLocaleString());
 
   var pre = addNode(div, 'pre');
   addTextNode(pre, PrintSourceEntriesAsText(logEntries, false));
 }
 
 function canCollapseBeginWithEnd(beginEntry) {
   return beginEntry &&
          beginEntry.isBegin() &&
-         !beginEntry.orig.params &&
          beginEntry.end &&
          beginEntry.end.index == beginEntry.index + 1 &&
-         !beginEntry.end.orig.params &&
+         (!beginEntry.orig.params || !beginEntry.end.orig.params) &&

[eroman, 2011/01/05 02:39:06]

Can you explain this change? Won't this make it ambiguous as to whether the
extra parameters applied to the BEGIN or END phase?

[mmenke, 2011/01/05 16:32:25]

Not really (To being ambiguous, not to being able to explain the change).  If we
log data for both begin and end phases, they're still kept separate.  When we
only log data for one or the other, which event the data came from tends to be
pretty clear from what the value names are.  In my opinion, this change
significantly increases readability.

As for explaining the change... I find a list of:

[st=107227]    SOCKET_IN_USE           [dt=   112]
               --> source_dependency = {"id":77499,"type":1}
[st=107227]    SOCKET_IN_USE           [dt=   112]
               --> source_dependency = {"id":77499,"type":1}
[st=107227]    SOCKET_IN_USE           [dt=   112]
               --> source_dependency = {"id":77499,"type":1}
[st=107227]    SOCKET_IN_USE           [dt=   112]
               --> source_dependency = {"id":77499,"type":1}

much easier to visually parse than:

[st=107227]   +SOCKET_IN_USE           [dt=   112]
               --> source_dependency = {"id":77499,"type":1}
[st=107339]   -SOCKET_IN_USE           
[st=107227]   +SOCKET_IN_USE           [dt=   112]
               --> source_dependency = {"id":77499,"type":1}
[st=107339]   -SOCKET_IN_USE           
[st=107227]   +SOCKET_IN_USE           [dt=   112]
               --> source_dependency = {"id":77499,"type":1}
[st=107339]   -SOCKET_IN_USE           
[st=107227]   +SOCKET_IN_USE           [dt=   112]
               --> source_dependency = {"id":77499,"type":1}
[st=107339]   -SOCKET_IN_USE           

When there are intervening events, the indentation is easy to pick up on.  When
there aren't, I find visualizing event beginnings/endings at a high level much
more difficult.

If you feel strongly that the second is the way to go, I'm willing to undo the
change, but I don't think making it slightly clearer if a parameter belongs to
the begin or end event is worth significantly increasing the level of visual
noise.

I put the change in this CL because virtually all the new DiskCache events are
paired in this fashion, and I was finding them a little painful to follow.  Of
course, since I added data for the end events of read and write operations, in
response to another of your comments, this argument isn't quite as compelling as
before.

Another option would be to use "<---" for EndEvent results.  Only issue there is
that could be a little misleading at times, since some values labelled with
"--->" would still actually be return values, particularly for events without
begin/end phases.

          beginEntry.orig.wasPassivelyCaptured ==
              beginEntry.end.orig.wasPassivelyCaptured;
 }
 
 PrintSourceEntriesAsText = function(sourceEntries, doSecurityStripping) {
   var entries = LogGroupEntry.createArrayFrom(sourceEntries);
   if (entries.length == 0)
     return '';
 
   var startDate = g_browser.convertTimeTicksToDate(entries[0].orig.time);
   var startTime = startDate.getTime();
 
   var tablePrinter = new TablePrinter();
 
   for (var i = 0; i < entries.length; ++i) {
     var entry = entries[i];
 
-    // Avoid printing the END for a BEGIN that was immediately before.
-    if (entry.isEnd() && canCollapseBeginWithEnd(entry.begin))
-      continue;
+    // 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.addRow();
+      // Annotate this entry with "(P)" if it was passively captured.
+      tablePrinter.addCell(entry.orig.wasPassivelyCaptured ? '(P) ' : '');
 
-    // Annotate this entry with "(P)" if it was passively captured.
-    tablePrinter.addCell(entry.orig.wasPassivelyCaptured ? '(P) ' : '');
+      tablePrinter.addCell('t=');
+      var date = g_browser.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;

[eroman, 2011/01/05 02:39:06]

Did any of this, or is it all just indentation differences?

[mmenke, 2011/01/05 16:32:25]

Wish diff handled spaces better.  No, there's absolutely no difference, other
than indentation, other than the change to the first if statement in line 74.

+      tablePrinter.addCell('] ');
 
-    tablePrinter.addCell('t=');
-    var date = g_browser.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 indentationStr = makeRepeatedString(' ', entry.getDepth() * 3);
+      var mainCell =
+          tablePrinter.addCell(indentationStr + getTextForEvent(entry));
+      tablePrinter.addCell('  ');
 
-    var indentationStr = makeRepeatedString(' ', entry.getDepth() * 3);
-    var mainCell =
-        tablePrinter.addCell(indentationStr + getTextForEvent(entry));
-    tablePrinter.addCell('  ');
+      // Get the elapsed time.
+      if (entry.isBegin()) {
+        tablePrinter.addCell('[dt=');
+        var dt = '?';
+        // Definite time.
+        if (entry.end) {
+          dt = entry.end.orig.time - entry.orig.time;
+        }
+        var dtCell = tablePrinter.addCell(dt);
+        dtCell.alignRight = true;
 
-    // Get the elapsed time.
-    if (entry.isBegin()) {
-      tablePrinter.addCell('[dt=');
-      var dt = '?';
-      // Definite time.
-      if (entry.end) {
-        dt = entry.end.orig.time - entry.orig.time;
+        tablePrinter.addCell(']');
+      } else {
+        mainCell.allowOverflow = true;
       }
-      var dtCell = tablePrinter.addCell(dt);
-      dtCell.alignRight = true;
-
-      tablePrinter.addCell(']');
-    } else {
-      mainCell.allowOverflow = true;
     }
 
     // Output the extra parameters.
     if (entry.orig.params != undefined) {
       // Add a continuation row for each line of text from the extra parameters.
       var extraParamsText = getTextForExtraParams(entry.orig,
                                                   doSecurityStripping);
       var extraParamsTextLines = extraParamsText.split('\n');
 
       for (var j = 0; j < extraParamsTextLines.length; ++j) {
@@ skipping 303 matching lines @@
   var result = [];
   for (var i = 0; i < modes.length; ++i)
     result.push(indentLines('(' + (i + 1) + ') ', modes[i]));
 
   return result.join('\n');
 };
 
 // End of anonymous namespace.
 })();