Handle session logs and add event subset selection

R=scheglov@google.com

Review URL: https://codereview.chromium.org/2390693002 .

pkg/analysis_server/tool/instrumentation/log/log.dart

@@ -5,13 +5,82 @@
 /**
  * A representation of the contents of an instrumentation log.
  */
-library analysis_server.tool.instrumentation.log;
+library analysis_server.tool.instrumentation.log.log;
 
-import 'dart:collection';
 import 'dart:convert';
 
 import 'package:analyzer/instrumentation/instrumentation.dart';
 
+/**
+ * A boolean-valued function of one argument.
+ */
+typedef bool Predicate<T>(T value);
+
+/**
+ * A description of a group of log entries.
+ */
+class EntryGroup {
+  /**
+   * A list of all of the instances of this class.
+   */
+  static final List<EntryGroup> groups = <EntryGroup>[
+    new EntryGroup._(
+        'nonTask', 'Non-task', (LogEntry entry) => entry is! TaskEntry),
+    new EntryGroup._(
+        'errors',
+        'Errors',
+        (LogEntry entry) =>
+            entry is ErrorEntry ||
+            entry is ExceptionEntry ||
+            (entry is NotificationEntry && entry.isServerError)),
+    new EntryGroup._('malformed', 'Malformed',
+        (LogEntry entry) => entry is MalformedLogEntry),
+    new EntryGroup._('all', 'All', (LogEntry entry) => true),
+  ];
+
+  /**
+   * The unique id of the group.
+   */
+  final String id;
+
+  /**
+   * The human-readable name of the group.
+   */
+  final String name;
+
+  /**
+   * The filter used to determine which entries belong to the group. The filter
+   * should return `true` for members and `false` for non-members.
+   */
+  final Predicate<LogEntry> filter;
+
+  /**
+   * Initialize a newly created entry group with the given state.
+   */
+  EntryGroup._(this.id, this.name, this.filter);
+
+  /**
+   * Given a list of [entries], return all of the entries in the list that are
+   * members of this group.
+   */
+  List<LogEntry> computeMembers(List<LogEntry> entries) {
+    return entries.where(filter).toList();
+  }
+
+  /**
+   * Return the entry group with the given [id], or `null` if there is no group
+   * with the given id.
+   */
+  static EntryGroup withId(String id) {
+    for (EntryGroup group in groups) {
+      if (group.id == id) {
+        return group;
+      }
+    }
+    return null;
+  }
+}
+
 /**
  * A range of log entries, represented by the index of the first and last
  * entries in the range.
@@ -107,34 +176,33 @@ class InstrumentationLog {
   List<LogEntry> logEntries;
 
   /**
-   * The entries in the instrumentation log that are not instances of
-   * [TaskEntry].
+   * A table mapping the entry groups that have been computed to the list of
+   * entries in that group.
    */
-  List<LogEntry> nonTaskEntries;
+  Map<EntryGroup, List<LogEntry>> entryGroups = <EntryGroup, List<LogEntry>>{};
 
   /**
    * A table mapping entries that are paired with another entry to the entry
    * with which they are paired.
    */
-  Map<LogEntry, LogEntry> _pairedEntries = new HashMap<LogEntry, LogEntry>();
+  Map<LogEntry, LogEntry> _pairedEntries = <LogEntry, LogEntry>{};
 
   /**
    * A table mapping the id's of requests to the entry representing the request.
    */
-  Map<String, RequestEntry> _requestMap = new HashMap<String, RequestEntry>();
+  Map<String, RequestEntry> _requestMap = <String, RequestEntry>{};
 
   /**
    * A table mapping the id's of responses to the entry representing the
    * response.
    */
-  Map<String, ResponseEntry> _responseMap =
-      new HashMap<String, ResponseEntry>();
+  Map<String, ResponseEntry> _responseMap = <String, ResponseEntry>{};
 
   /**
    * A table mapping the ids of completion events to the events with those ids.
    */
   Map<String, List<NotificationEntry>> _completionMap =
-      new HashMap<String, List<NotificationEntry>>();
+      <String, List<NotificationEntry>>{};
 
   /**
    * The ranges of entries that are between analysis start and analysis end
@@ -157,6 +225,12 @@ class InstrumentationLog {
   List<NotificationEntry> completionEventsWithId(String id) =>
       _completionMap[id];
 
+  /**
+   * Return the log entries that are contained in the given [group].
+   */
+  List<LogEntry> entriesInGroup(EntryGroup group) =>
+      entryGroups.putIfAbsent(group, () => group.computeMembers(logEntries));
+
   /**
    * Return the entry that is paired with the given [entry], or `null` if there
    * is no entry paired with it.
@@ -181,7 +255,7 @@ class InstrumentationLog {
    */
   List<TaskEntry> taskEntriesFor(int startIndex) {
     List<TaskEntry> taskEntries = <TaskEntry>[];
-    NotificationEntry startEntry = nonTaskEntries[startIndex];
+    NotificationEntry startEntry = logEntries[startIndex];
     LogEntry endEntry = pairedEntry(startEntry);
     int lastIndex = endEntry == null ? logEntries.length : endEntry.index;
     for (int i = startEntry.index + 1; i < lastIndex; i++) {
@@ -193,6 +267,18 @@ class InstrumentationLog {
     return taskEntries;
   }
 
+  /**
+   * Return `true` if the given [logContent] appears to be from session data.
+   */
+  bool _isSessionData(List<String> logContent) {
+    if (logContent.length < 2) {
+      return false;
+    }
+    String firstLine = logContent[0];
+    return firstLine.startsWith('-----') && logContent[1].startsWith('~') ||
+        firstLine.startsWith('~');
+  }
+
   /**
    * Merge any multi-line entries into a single line so that every element in
    * the given [logContent] is a single entry.
@@ -233,9 +319,18 @@ class InstrumentationLog {
    * Parse the given [logContent] into a list of log entries.
    */
   void _parseLogContent(List<String> logContent) {
-    _mergeEntries(logContent);
+    if (_isSessionData(logContent)) {
+      if (logContent[0].startsWith('-----')) {
+        logContent.removeAt(0);
+      }
+      int lastIndex = logContent.length - 1;
+      if (logContent[lastIndex].startsWith('extraction complete')) {
+        logContent.removeAt(lastIndex);
+      }
+    } else {
+      _mergeEntries(logContent);
+    }
     logEntries = <LogEntry>[];
-    nonTaskEntries = <LogEntry>[];
     analysisRanges = <EntryRange>[];
     NotificationEntry analysisStartEntry = null;
     int analysisStartIndex = -1;
@@ -244,9 +339,6 @@ class InstrumentationLog {
       LogEntry entry = new LogEntry.from(logEntries.length, line);
       if (entry != null) {
         logEntries.add(entry);
-        if (entry is! TaskEntry) {
-          nonTaskEntries.add(entry);
-        }
         if (entry is RequestEntry) {
           _requestMap[entry.id] = entry;
         } else if (entry is ResponseEntry) {
@@ -439,6 +531,7 @@ abstract class LogEntry {
     'Err': 'Error',
     'Ex': 'Exception',
     'Log': 'Log message',
+    'Mal': 'Malformed entry',
     'Noti': 'Notification',
     'Read': 'Read file',
     'Req': 'Request',
@@ -479,47 +572,54 @@ abstract class LogEntry {
     if (entry.isEmpty) {
       return null;
     }
-    List<String> components = _parseComponents(entry);
-    int timeStamp;
     try {
-      timeStamp = int.parse(components[0]);
-    } catch (exception) {
-      print('Invalid time stamp in "${components[0]}"; entry = "$entry"');
-      return null;
-    }
-    String entryKind = components[1];
-    if (entryKind == InstrumentationService.TAG_ANALYSIS_TASK) {
-      return new TaskEntry(index, timeStamp, components[2], components[3]);
-    } else if (entryKind == InstrumentationService.TAG_ERROR) {
-      return new ErrorEntry(index, timeStamp, entryKind, components.sublist(2));
-    } else if (entryKind == InstrumentationService.TAG_EXCEPTION) {
-      return new ExceptionEntry(
+      List<String> components = _parseComponents(entry);
+      int timeStamp;
+      String component = components[0];
+      if (component.startsWith('~')) {
+        component = component.substring(1);
+      }
+      timeStamp = int.parse(component);
+      String entryKind = components[1];
+      if (entryKind == InstrumentationService.TAG_ANALYSIS_TASK) {
+        return new TaskEntry(index, timeStamp, components[2], components[3]);
+      } else if (entryKind == InstrumentationService.TAG_ERROR) {
+        return new ErrorEntry(
+            index, timeStamp, entryKind, components.sublist(2));
+      } else if (entryKind == InstrumentationService.TAG_EXCEPTION) {
+        return new ExceptionEntry(
+            index, timeStamp, entryKind, components.sublist(2));
+      } else if (entryKind == InstrumentationService.TAG_FILE_READ) {
+        // Fall through
+      } else if (entryKind == InstrumentationService.TAG_LOG_ENTRY) {
+        // Fall through
+      } else if (entryKind == InstrumentationService.TAG_NOTIFICATION) {
+        Map requestData = JSON.decode(components[2]);
+        return new NotificationEntry(index, timeStamp, requestData);
+      } else if (entryKind == InstrumentationService.TAG_PERFORMANCE) {
+        // Fall through
+      } else if (entryKind == InstrumentationService.TAG_REQUEST) {
+        Map requestData = JSON.decode(components[2]);
+        return new RequestEntry(index, timeStamp, requestData);
+      } else if (entryKind == InstrumentationService.TAG_RESPONSE) {
+        Map responseData = JSON.decode(components[2]);
+        return new ResponseEntry(index, timeStamp, responseData);
+      } else if (entryKind == InstrumentationService.TAG_SUBPROCESS_START) {
+        // Fall through
+      } else if (entryKind == InstrumentationService.TAG_SUBPROCESS_RESULT) {
+        // Fall through
+      } else if (entryKind == InstrumentationService.TAG_VERSION) {
+        // Fall through
+      } else if (entryKind == InstrumentationService.TAG_WATCH_EVENT) {
+        // Fall through
+      }
+      return new GenericEntry(
           index, timeStamp, entryKind, components.sublist(2));
-    } else if (entryKind == InstrumentationService.TAG_FILE_READ) {
-      // Fall through
-    } else if (entryKind == InstrumentationService.TAG_LOG_ENTRY) {
-      // Fall through
-    } else if (entryKind == InstrumentationService.TAG_NOTIFICATION) {
-      Map requestData = JSON.decode(components[2]);
-      return new NotificationEntry(index, timeStamp, requestData);
-    } else if (entryKind == InstrumentationService.TAG_PERFORMANCE) {
-      // Fall through
-    } else if (entryKind == InstrumentationService.TAG_REQUEST) {
-      Map requestData = JSON.decode(components[2]);
-      return new RequestEntry(index, timeStamp, requestData);
-    } else if (entryKind == InstrumentationService.TAG_RESPONSE) {
-      Map responseData = JSON.decode(components[2]);
-      return new ResponseEntry(index, timeStamp, responseData);
-    } else if (entryKind == InstrumentationService.TAG_SUBPROCESS_START) {
-      // Fall through
-    } else if (entryKind == InstrumentationService.TAG_SUBPROCESS_RESULT) {
-      // Fall through
-    } else if (entryKind == InstrumentationService.TAG_VERSION) {
-      // Fall through
-    } else if (entryKind == InstrumentationService.TAG_WATCH_EVENT) {
-      // Fall through
+    } catch (exception) {
+      LogEntry logEntry = new MalformedLogEntry(index, entry);
+      logEntry.recordProblem(exception.toString());
+      return logEntry;
     }
-    return new GenericEntry(index, timeStamp, entryKind, components.sublist(2));
   }
 
   /**
@@ -607,6 +707,25 @@ abstract class LogEntry {
   }
 }
 
+/**
+ * A representation of a malformed log entry.
+ */
+class MalformedLogEntry extends LogEntry {
+  final String entry;
+
+  MalformedLogEntry(int index, this.entry) : super(index, -1);
+
+  @override
+  String get kind => 'Mal';
+
+  @override
+  void _appendDetails(StringBuffer buffer) {
+    super._appendDetails(buffer);
+    buffer.write(entry);
+    buffer.write('<br>');
+  }
+}
+
 /**
  * A log entry representing a notification that was sent from the server to the
  * client.
@@ -624,6 +743,11 @@ class NotificationEntry extends JsonBasedEntry {
    */
   String get event => data['event'];
 
+  /**
+   * Return `true` if this is a server error notification.
+   */
+  bool get isServerError => event == 'server.error';
+
   /**
    * Return `true` if this is a server status notification.
    */

pkg/analysis_server/tool/instrumentation/log_viewer.dart

@@ -118,6 +118,7 @@ class Driver {
           stackTrace: stackTrace);
       return;
     }
+    print('Log file contains ${lines.length} lines');
 
     InstrumentationLog log =
         new InstrumentationLog(<String>[logFile.path], lines);

pkg/analysis_server/tool/instrumentation/page/log_page.dart

@@ -19,6 +19,16 @@ class LogPage extends PageWriter {
    */
   InstrumentationLog log;
 
+  /**
+   * The id of the entry groups to be displayed.
+   */
+  EntryGroup selectedGroup;
+
+  /**
+   * The entries in the selected group.
+   */
+  List<LogEntry> entries;
+
   /**
    * The index of the first entry to be written.
    */
@@ -35,27 +45,17 @@ class LogPage extends PageWriter {
    */
   int prefixLength;
 
-  /**
-   * The number of each kind of log entry. Currently used only for debugging and
-   * should be removed.
-   */
-  Map<String, int> counts = new HashMap<String, int>();
-
   /**
    * Initialize a newly created writer to write the content of the given
    * [instrumentationLog].
    */
-  LogPage(this.log) {
-    List<LogEntry> entries = log.logEntries;
-    prefixLength = computePrefixLength(entries);
-    for (LogEntry entry in entries) {
-      int count = counts.putIfAbsent(entry.kind, () => 0);
-      counts[entry.kind] = count + 1;
-    }
-  }
+  LogPage(this.log);
 
   @override
   void writeBody(StringSink sink) {
+    entries = log.entriesInGroup(selectedGroup);
+    prefixLength = computePrefixLength(entries);
+
     writeMenu(sink);
     writeTwoColumns(
         sink, 'leftColumn', _writeLeftColumn, 'rightColumn', _writeRightColumn);
@@ -89,6 +89,11 @@ function setDetails(detailsContent) {
     element.innerHTML = detailsContent;
   }
 }
+function selectEntryGroup(pageStart) {
+  var element = document.getElementById("entryGroup");
+  var url = "/log?group=" + element.value;
+  window.location.assign(url);
+}
 ''');
   }
 
@@ -175,6 +180,8 @@ function setDetails(detailsContent) {
       description = '<span class="error">$description</span>';
     } else if (entry is ExceptionEntry) {
       description = '<span class="error">$description</span>';
+    } else if (entry is MalformedLogEntry) {
+      description = '<span class="error">$description</span>';
     }
     id = id == null ? '' : 'id="$id" ';
     clickHandler = '$clickHandler; setDetails(\'${escape(entry.details())}\')';
@@ -198,7 +205,6 @@ function setDetails(detailsContent) {
    * Write the entries in the instrumentation log to the given [sink].
    */
   void _writeLeftColumn(StringSink sink) {
-    List<LogEntry> entries = log.nonTaskEntries;
     int length = entries.length;
     int pageEnd =
         pageLength == null ? length : math.min(pageStart + pageLength, length);
@@ -207,6 +213,19 @@ function setDetails(detailsContent) {
     //
     sink.writeln('<div class="columnHeader">');
     sink.writeln('<div style="float: left">');
+    sink.writeln('<select id="entryGroup" onchange="selectEntryGroup()">');
+    for (EntryGroup group in EntryGroup.groups) {
+      sink.write('<option value="');
+      sink.write(group.id);
+      sink.write('"');
+      if (group == selectedGroup) {
+        sink.write(' selected');
+      }
+      sink.write('>');
+      sink.write(group.name);
+      sink.writeln('</option>');
+    }
+    sink.writeln('</select>');
     sink.writeln('Events $pageStart - ${pageEnd - 1} of ${length - 1}');
     sink.writeln('</div>');
 
@@ -216,7 +235,7 @@ function setDetails(detailsContent) {
     } else {
       sink.write('<button type="button">');
       sink.write(
-          '<a href="${WebServer.logPath}?start=${pageStart - pageLength}">');
+          '<a href="${WebServer.logPath}?group=${selectedGroup.id}&start=${pageStart - pageLength}">');
       sink.write('<b>&lt;</b>');
       sink.writeln('</a></button>');
     }
@@ -226,7 +245,7 @@ function setDetails(detailsContent) {
     } else {
       sink.write('<button type="button">');
       sink.write(
-          '<a href="${WebServer.logPath}?start=${pageStart + pageLength}">');
+          '<a href="${WebServer.logPath}?group=${selectedGroup.id}&start=${pageStart + pageLength}">');
       sink.write('<b>&gt;</b>');
       sink.writeln('</a></button>');
     }

pkg/analysis_server/tool/instrumentation/page/page_writer.dart

@@ -48,7 +48,11 @@ abstract class PageWriter {
    * Return an escaped version of the given [unsafe] text.
    */
   String escape(String unsafe) {
-    return htmlEscape.convert(unsafe);
+    // We double escape single quotes because the escaped characters are
+    // processed as part of reading the HTML, which means that single quotes
+    // end up terminating string literals too early when they appear in event
+    // handlers (which in turn leads to JavaScript syntax errors).
+    return htmlEscape.convert(unsafe).replaceAll(''', ''');
   }
 
   /**
@@ -273,8 +277,8 @@ th.narrow {
    */
   void writeTwoColumns(StringSink sink, String leftColumnId,
       Writer writeLeftColumn, String rightColumnId, Writer writeRightColumn) {
-    sink.writeln('<div>');
-    sink.writeln('  <div>');
+    sink.writeln('<div id="container">');
+    sink.writeln('  <div id="content">');
     sink.writeln('    <div id="$leftColumnId">');
     sink.writeln('      <div class="inset">');
     writeLeftColumn(sink);

pkg/analysis_server/tool/instrumentation/page/stats_page.dart

@@ -52,20 +52,8 @@ class StatsPage extends PageWriter {
   @override
   void writeBody(StringSink sink) {
     writeMenu(sink);
-    sink.writeln('<div id="container">');
-    sink.writeln('  <div id="content">');
-    sink.writeln('    <div id="leftColumn">');
-    sink.writeln('      <div class="inset">');
-    _writeLeftColumn(sink);
-    sink.writeln('      </div>');
-    sink.writeln('    </div>');
-    sink.writeln('    <div id="rightColumn">');
-    sink.writeln('      <div class="inset">');
-    _writeRightColumn(sink);
-    sink.writeln('      </div>');
-    sink.writeln('    </div>');
-    sink.writeln('  </div>');
-    sink.writeln('</div>');
+    writeTwoColumns(
+        sink, 'leftColumn', _writeLeftColumn, 'rightColumn', _writeRightColumn);
   }
 
   /**
@@ -74,20 +62,7 @@ class StatsPage extends PageWriter {
    */
   void writeStyleSheet(StringSink sink) {
     super.writeStyleSheet(sink);
-    sink.writeln(r'''
-#leftColumn {
-  float: left;
-  height: 100%;
-  overflow: auto;
-  width: 50%;
-}
-#rightColumn {
-  float: right;
-  height: 100%;
-  overflow: auto;
-  width: 50%;
-}
-''');
+    writeTwoColumnStyles(sink, 'leftColumn', 'rightColumn');
   }
 
   /**

pkg/analysis_server/tool/instrumentation/server.dart

@@ -186,8 +186,10 @@ class WebServer {
 
   void _writeLogPage(HttpRequest request, StringBuffer buffer) {
     Map<String, String> parameterMap = getParameterMap(request);
+    String groupId = parameterMap['group'];
     String startIndex = parameterMap['start'];
     LogPage page = new LogPage(log);
+    page.selectedGroup = EntryGroup.withId(groupId ?? 'nonTask');
     if (startIndex != null) {
       page.pageStart = int.parse(startIndex);
     } else {