<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.1//EN"
"http://www.w3.org/TR/xhtml11/DTD/xhtml11.dtd">
<html xmlns="http://www.w3.org/1999/xhtml">
<head><meta http-equiv="content-type" content="text/html; charset=utf-8" />
<title>[171881] trunk/Source/WebInspectorUI</title>
</head>
<body>
<style type="text/css"><!--
#msg dl.meta { border: 1px #006 solid; background: #369; padding: 6px; color: #fff; }
#msg dl.meta dt { float: left; width: 6em; font-weight: bold; }
#msg dt:after { content:':';}
#msg dl, #msg dt, #msg ul, #msg li, #header, #footer, #logmsg { font-family: verdana,arial,helvetica,sans-serif; font-size: 10pt; }
#msg dl a { font-weight: bold}
#msg dl a:link { color:#fc3; }
#msg dl a:active { color:#ff0; }
#msg dl a:visited { color:#cc6; }
h3 { font-family: verdana,arial,helvetica,sans-serif; font-size: 10pt; font-weight: bold; }
#msg pre { overflow: auto; background: #ffc; border: 1px #fa0 solid; padding: 6px; }
#logmsg { background: #ffc; border: 1px #fa0 solid; padding: 1em 1em 0 1em; }
#logmsg p, #logmsg pre, #logmsg blockquote { margin: 0 0 1em 0; }
#logmsg p, #logmsg li, #logmsg dt, #logmsg dd { line-height: 14pt; }
#logmsg h1, #logmsg h2, #logmsg h3, #logmsg h4, #logmsg h5, #logmsg h6 { margin: .5em 0; }
#logmsg h1:first-child, #logmsg h2:first-child, #logmsg h3:first-child, #logmsg h4:first-child, #logmsg h5:first-child, #logmsg h6:first-child { margin-top: 0; }
#logmsg ul, #logmsg ol { padding: 0; list-style-position: inside; margin: 0 0 0 1em; }
#logmsg ul { text-indent: -1em; padding-left: 1em; }#logmsg ol { text-indent: -1.5em; padding-left: 1.5em; }
#logmsg > ul, #logmsg > ol { margin: 0 0 1em 0; }
#logmsg pre { background: #eee; padding: 1em; }
#logmsg blockquote { border: 1px solid #fa0; border-left-width: 10px; padding: 1em 1em 0 1em; background: white;}
#logmsg dl { margin: 0; }
#logmsg dt { font-weight: bold; }
#logmsg dd { margin: 0; padding: 0 0 0.5em 0; }
#logmsg dd:before { content:'\00bb';}
#logmsg table { border-spacing: 0px; border-collapse: collapse; border-top: 4px solid #fa0; border-bottom: 1px solid #fa0; background: #fff; }
#logmsg table th { text-align: left; font-weight: normal; padding: 0.2em 0.5em; border-top: 1px dotted #fa0; }
#logmsg table td { text-align: right; border-top: 1px dotted #fa0; padding: 0.2em 0.5em; }
#logmsg table thead th { text-align: center; border-bottom: 1px solid #fa0; }
#logmsg table th.Corner { text-align: left; }
#logmsg hr { border: none 0; border-top: 2px dashed #fa0; height: 1px; }
#header, #footer { color: #fff; background: #636; border: 1px #300 solid; padding: 6px; }
#patch { width: 100%; }
#patch h4 {font-family: verdana,arial,helvetica,sans-serif;font-size:10pt;padding:8px;background:#369;color:#fff;margin:0;}
#patch .propset h4, #patch .binary h4 {margin:0;}
#patch pre {padding:0;line-height:1.2em;margin:0;}
#patch .diff {width:100%;background:#eee;padding: 0 0 10px 0;overflow:auto;}
#patch .propset .diff, #patch .binary .diff {padding:10px 0;}
#patch span {display:block;padding:0 10px;}
#patch .modfile, #patch .addfile, #patch .delfile, #patch .propset, #patch .binary, #patch .copfile {border:1px solid #ccc;margin:10px 0;}
#patch ins {background:#dfd;text-decoration:none;display:block;padding:0 10px;}
#patch del {background:#fdd;text-decoration:none;display:block;padding:0 10px;}
#patch .lines, .info {color:#888;background:#fff;}
--></style>
<div id="msg">
<dl class="meta">
<dt>Revision</dt> <dd><a href="http://trac.webkit.org/projects/webkit/changeset/171881">171881</a></dd>
<dt>Author</dt> <dd>burg@cs.washington.edu</dd>
<dt>Date</dt> <dd>2014-07-31 12:47:40 -0700 (Thu, 31 Jul 2014)</dd>
</dl>
<h3>Log Message</h3>
<pre>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.</pre>
<h3>Modified Paths</h3>
<ul>
<li><a href="#trunkSourceWebInspectorUIChangeLog">trunk/Source/WebInspectorUI/ChangeLog</a></li>
<li><a href="#trunkSourceWebInspectorUIUserInterfaceProtocolInspectorBackendjs">trunk/Source/WebInspectorUI/UserInterface/Protocol/InspectorBackend.js</a></li>
<li><a href="#trunkSourceWebInspectorUIUserInterfaceProtocolMessageDispatcherjs">trunk/Source/WebInspectorUI/UserInterface/Protocol/MessageDispatcher.js</a></li>
</ul>
</div>
<div id="patch">
<h3>Diff</h3>
<a id="trunkSourceWebInspectorUIChangeLog"></a>
<div class="modfile"><h4>Modified: trunk/Source/WebInspectorUI/ChangeLog (171880 => 171881)</h4>
<pre class="diff"><span>
<span class="info">--- 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)
</span><span class="lines">@@ -1,3 +1,32 @@
</span><ins>+2014-07-31 Brian J. Burg <burg@cs.washington.edu>
+
+ 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.
+
</ins><span class="cx"> 2014-07-31 Joseph Pecoraro <pecoraro@apple.com>
</span><span class="cx">
</span><span class="cx"> Web Inspector: Right edge of Timeline Record button does not work
</span></span></pre></div>
<a id="trunkSourceWebInspectorUIUserInterfaceProtocolInspectorBackendjs"></a>
<div class="modfile"><h4>Modified: trunk/Source/WebInspectorUI/UserInterface/Protocol/InspectorBackend.js (171880 => 171881)</h4>
<pre class="diff"><span>
<span class="info">--- 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)
</span><span class="lines">@@ -40,6 +40,8 @@
</span><span class="cx">
</span><span class="cx"> this.dumpInspectorTimeStats = false;
</span><span class="cx"> this.dumpInspectorProtocolMessages = false;
</span><ins>+ this.warnForLongMessageHandling = false;
+ this.longMessageHandlingThreshold = 10; // milliseconds.
</ins><span class="cx"> }
</span><span class="cx">
</span><span class="cx"> InspectorBackendClass.prototype = {
</span><span class="lines">@@ -171,8 +173,12 @@
</span><span class="cx"> console.error("Uncaught exception in inspector page while dispatching callback for command " + command.qualifiedName + ": ", e);
</span><span class="cx"> }
</span><span class="cx">
</span><ins>+ var processingDuration = Date.now() - processingStartTime;
+ if (this.warnForLongMessageHandling && processingDuration > this.longMessageHandlingThreshold)
+ console.warn("InspectorBackend: took " + processingDuration + "ms to handle response for command: " + command.qualifiedName);
+
</ins><span class="cx"> if (this.dumpInspectorTimeStats)
</span><del>- console.log("time-stats: " + command.qualifiedName + " = " + (processingStartTime - callbackData.sendRequestTime) + " + " + (Date.now() - processingStartTime));
</del><ins>+ console.log("time-stats: Handling: " + processingDuration + "ms; RTT: " + (processingStartTime - callbackData.sendRequestTime) + "ms; (command " + command.qualifiedName + ")");
</ins><span class="cx">
</span><span class="cx"> this._callbackData.delete(messageObject["id"]);
</span><span class="cx"> }
</span><span class="lines">@@ -214,8 +220,12 @@
</span><span class="cx"> console.error("Uncaught exception in inspector page while handling event " + qualifiedName + ": ", e);
</span><span class="cx"> }
</span><span class="cx">
</span><ins>+ var processingDuration = Date.now() - processingStartTime;
+ if (this.warnForLongMessageHandling && processingDuration > this.longMessageHandlingThreshold)
+ console.warn("InspectorBackend: took " + processingDuration + "ms to handle event: " + messageObject["method"]);
+
</ins><span class="cx"> if (this.dumpInspectorTimeStats)
</span><del>- console.log("time-stats: " + messageObject["method"] + " = " + (Date.now() - processingStartTime));
</del><ins>+ console.log("time-stats: Handling: " + processingDuration + "ms (event " + messageObject["method"] + ")");
</ins><span class="cx"> },
</span><span class="cx">
</span><span class="cx"> _invokeCommand: function(command, parameters, callback)
</span></span></pre></div>
<a id="trunkSourceWebInspectorUIUserInterfaceProtocolMessageDispatcherjs"></a>
<div class="modfile"><h4>Modified: trunk/Source/WebInspectorUI/UserInterface/Protocol/MessageDispatcher.js (171880 => 171881)</h4>
<pre class="diff"><span>
<span class="info">--- 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)
</span><span class="lines">@@ -1,5 +1,6 @@
</span><span class="cx"> /*
</span><span class="cx"> * Copyright (C) 2013 Apple Inc. All rights reserved.
</span><ins>+ * Copyright (C) 2014 University of Washington
</ins><span class="cx"> *
</span><span class="cx"> * Redistribution and use in source and binary forms, with or without
</span><span class="cx"> * modification, are permitted provided that the following conditions
</span><span class="lines">@@ -27,12 +28,30 @@
</span><span class="cx">
</span><span class="cx"> WebInspector.dispatchNextQueuedMessageFromBackend = function()
</span><span class="cx"> {
</span><del>- for (var i = 0; i < this.messagesToDispatch.length; ++i)
- InspectorBackend.dispatch(this.messagesToDispatch[i]);
</del><ins>+ var startCount = WebInspector.messagesToDispatch.length;
+ var startTime = Date.now();
+ var timeLimitPerRunLoop = 10; // milliseconds
</ins><span class="cx">
</span><del>- this.messagesToDispatch = [];
</del><ins>+ 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;
</ins><span class="cx">
</span><del>- this._dispatchTimeout = null;
</del><ins>+ 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);
</ins><span class="cx"> }
</span><span class="cx">
</span><span class="cx"> WebInspector.dispatchMessageFromBackend = function(message)
</span><span class="lines">@@ -45,5 +64,5 @@
</span><span class="cx"> if (this._dispatchTimeout)
</span><span class="cx"> return;
</span><span class="cx">
</span><del>- this._dispatchTimeout = setTimeout(this.dispatchNextQueuedMessageFromBackend.bind(this), 0);
</del><ins>+ this._dispatchTimeout = setTimeout(WebInspector.dispatchNextQueuedMessageFromBackend, 0);
</ins><span class="cx"> }
</span></span></pre>
</div>
</div>
</body>
</html>