Title: [171881] trunk/Source/WebInspectorUI
Revision
171881
Author
[email protected]
Date
2014-07-31 12:47:40 -0700 (Thu, 31 Jul 2014)

Log Message

Web Inspector: MessageDispatcher should not synchronously dispatch all backend messages
https://bugs.webkit.org/show_bug.cgi?id=135427

Reviewed by Timothy Hatcher.

The frontend dispatches all queued messages from the backend synchronously, even if there are
hundreds of messages, or even if some of the messages take a long time (>10ms) to process.

This patch adds a time limit to the frontend's message dispatcher. If the time limit is exceeded
when processing the message queue, unhandled messages remain in the queue and the dispatcher goes
to sleep until the next run loop (obtained by a new setTimeout).

This has the effect of removing stutters when the message queue has hundreds of small messages.
The outliers are still the same since some single messages can take over 200ms to be handled.

This patch also improves performance logging in InspectorBackend so that it is easier to see
message handling times and their distribution among run loop turns.

* UserInterface/Protocol/InspectorBackend.js:
(InspectorBackendClass): Add a new diagnostic flag that warns about slow message handling.
(InspectorBackendClass.prototype._dispatchCallback.get if): Improve logging.
(InspectorBackendClass.prototype._dispatchCallback): Improve logging.
(InspectorBackendClass.prototype._dispatchEvent): Improve logging.
* UserInterface/Protocol/MessageDispatcher.js:
(WebInspector.dispatchNextQueuedMessageFromBackend): Keep track of a time limit for message
dispatching, and set a new timeout if we exceed the time limit.

Modified Paths

Diff

Modified: trunk/Source/WebInspectorUI/ChangeLog (171880 => 171881)


--- trunk/Source/WebInspectorUI/ChangeLog	2014-07-31 19:21:28 UTC (rev 171880)
+++ trunk/Source/WebInspectorUI/ChangeLog	2014-07-31 19:47:40 UTC (rev 171881)
@@ -1,3 +1,32 @@
+2014-07-31  Brian J. Burg  <[email protected]>
+
+        Web Inspector: MessageDispatcher should not synchronously dispatch all backend messages
+        https://bugs.webkit.org/show_bug.cgi?id=135427
+
+        Reviewed by Timothy Hatcher.
+
+        The frontend dispatches all queued messages from the backend synchronously, even if there are
+        hundreds of messages, or even if some of the messages take a long time (>10ms) to process.
+
+        This patch adds a time limit to the frontend's message dispatcher. If the time limit is exceeded
+        when processing the message queue, unhandled messages remain in the queue and the dispatcher goes
+        to sleep until the next run loop (obtained by a new setTimeout).
+
+        This has the effect of removing stutters when the message queue has hundreds of small messages.
+        The outliers are still the same since some single messages can take over 200ms to be handled.
+
+        This patch also improves performance logging in InspectorBackend so that it is easier to see
+        message handling times and their distribution among run loop turns.
+
+        * UserInterface/Protocol/InspectorBackend.js:
+        (InspectorBackendClass): Add a new diagnostic flag that warns about slow message handling.
+        (InspectorBackendClass.prototype._dispatchCallback.get if): Improve logging.
+        (InspectorBackendClass.prototype._dispatchCallback): Improve logging.
+        (InspectorBackendClass.prototype._dispatchEvent): Improve logging.
+        * UserInterface/Protocol/MessageDispatcher.js:
+        (WebInspector.dispatchNextQueuedMessageFromBackend): Keep track of a time limit for message
+        dispatching, and set a new timeout if we exceed the time limit.
+
 2014-07-31  Joseph Pecoraro  <[email protected]>
 
         Web Inspector: Right edge of Timeline Record button does not work

Modified: trunk/Source/WebInspectorUI/UserInterface/Protocol/InspectorBackend.js (171880 => 171881)


--- trunk/Source/WebInspectorUI/UserInterface/Protocol/InspectorBackend.js	2014-07-31 19:21:28 UTC (rev 171880)
+++ trunk/Source/WebInspectorUI/UserInterface/Protocol/InspectorBackend.js	2014-07-31 19:47:40 UTC (rev 171881)
@@ -40,6 +40,8 @@
 
     this.dumpInspectorTimeStats = false;
     this.dumpInspectorProtocolMessages = false;
+    this.warnForLongMessageHandling = false;
+    this.longMessageHandlingThreshold = 10; // milliseconds.
 }
 
 InspectorBackendClass.prototype = {
@@ -171,8 +173,12 @@
                 console.error("Uncaught exception in inspector page while dispatching callback for command " + command.qualifiedName + ": ", e);
             }
 
+            var processingDuration = Date.now() - processingStartTime;
+            if (this.warnForLongMessageHandling && processingDuration > this.longMessageHandlingThreshold)
+                console.warn("InspectorBackend: took " + processingDuration + "ms to handle response for command: " + command.qualifiedName);
+
             if (this.dumpInspectorTimeStats)
-                console.log("time-stats: " + command.qualifiedName + " = " + (processingStartTime - callbackData.sendRequestTime) + " + " + (Date.now() - processingStartTime));
+                console.log("time-stats: Handling: " + processingDuration + "ms; RTT: " + (processingStartTime - callbackData.sendRequestTime) + "ms; (command " + command.qualifiedName + ")");
 
             this._callbackData.delete(messageObject["id"]);
         }
@@ -214,8 +220,12 @@
             console.error("Uncaught exception in inspector page while handling event " + qualifiedName + ": ", e);
         }
 
+        var processingDuration = Date.now() - processingStartTime;
+        if (this.warnForLongMessageHandling && processingDuration > this.longMessageHandlingThreshold)
+            console.warn("InspectorBackend: took " + processingDuration + "ms to handle event: " + messageObject["method"]);
+
         if (this.dumpInspectorTimeStats)
-            console.log("time-stats: " + messageObject["method"] + " = " + (Date.now() - processingStartTime));
+            console.log("time-stats: Handling: " + processingDuration + "ms (event " + messageObject["method"] + ")");
     },
 
     _invokeCommand: function(command, parameters, callback)

Modified: trunk/Source/WebInspectorUI/UserInterface/Protocol/MessageDispatcher.js (171880 => 171881)


--- trunk/Source/WebInspectorUI/UserInterface/Protocol/MessageDispatcher.js	2014-07-31 19:21:28 UTC (rev 171880)
+++ trunk/Source/WebInspectorUI/UserInterface/Protocol/MessageDispatcher.js	2014-07-31 19:47:40 UTC (rev 171881)
@@ -1,5 +1,6 @@
 /*
  * Copyright (C) 2013 Apple Inc. All rights reserved.
+ * Copyright (C) 2014 University of Washington
  *
  * Redistribution and use in source and binary forms, with or without
  * modification, are permitted provided that the following conditions
@@ -27,12 +28,30 @@
 
 WebInspector.dispatchNextQueuedMessageFromBackend = function()
 {
-    for (var i = 0; i < this.messagesToDispatch.length; ++i)
-        InspectorBackend.dispatch(this.messagesToDispatch[i]);
+    var startCount = WebInspector.messagesToDispatch.length;
+    var startTime = Date.now();
+    var timeLimitPerRunLoop = 10; // milliseconds
 
-    this.messagesToDispatch = [];
+    var i = 0;
+    for (; i < WebInspector.messagesToDispatch.length; ++i) {
+        // Defer remaining messages if we have taken too long. In practice, single
+        // messages like Page.getResourceContent blow through the time budget.
+        if (Date.now() - startTime > timeLimitPerRunLoop)
+            break;
 
-    this._dispatchTimeout = null;
+        InspectorBackend.dispatch(WebInspector.messagesToDispatch[i]);
+    }
+
+    if (i === WebInspector.messagesToDispatch.length) {
+        WebInspector.messagesToDispatch = [];
+        WebInspector._dispatchTimeout = null;
+    } else {
+        WebInspector.messagesToDispatch = WebInspector.messagesToDispatch.slice(i);
+        WebInspector._dispatchTimeout = setTimeout(WebInspector.dispatchNextQueuedMessageFromBackend, 0);
+    }
+
+    if (InspectorBackend.dumpInspectorTimeStats)
+        console.log("time-stats: --- RunLoop duration: " + (Date.now() - startTime) + "ms; dispatched: " + (startCount - WebInspector.messagesToDispatch.length) + "; remaining: " + WebInspector.messagesToDispatch.length);
 }
 
 WebInspector.dispatchMessageFromBackend = function(message)
@@ -45,5 +64,5 @@
     if (this._dispatchTimeout)
         return;
 
-    this._dispatchTimeout = setTimeout(this.dispatchNextQueuedMessageFromBackend.bind(this), 0);
+    this._dispatchTimeout = setTimeout(WebInspector.dispatchNextQueuedMessageFromBackend, 0);
 }
_______________________________________________
webkit-changes mailing list
[email protected]
https://lists.webkit.org/mailman/listinfo/webkit-changes

Reply via email to