DevTools: Add timestamp support in the console

DevTools: Add timestamp support in the console

Add a setting which when enabled will append a time stamp to each
message in the console.

BUG=131714
Committed: https://src.chromium.org/viewvc/blink?view=rev&revision=170055

[kenneth.r.christiansen, 2014-03-04 13:17:56]

Screenshot: i.imgur.com/gQLEFaj.png

[apavlov, 2014-03-04 14:06:45]

https://codereview.chromium.org/185713007/diff/50001/Source/devtools/front_en...
File Source/devtools/front_end/ConsoleViewMessage.js (right):

https://codereview.chromium.org/185713007/diff/50001/Source/devtools/front_en...
Source/devtools/front_end/ConsoleViewMessage.js:885: timestamp.textContent = new
Date(this._message.timestamp * 1000).toISOString().replace("T", "
").replace("Z", "");
This will generate time in UTC, while users will want to see their local time,
right?

https://codereview.chromium.org/185713007/diff/50001/Source/devtools/front_en...
File Source/devtools/front_end/inspector.css (right):

https://codereview.chromium.org/185713007/diff/50001/Source/devtools/front_en...
Source/devtools/front_end/inspector.css:896: font-size: 11px;
pfeldman suggests that you not specify font size here, since console message
font sizes are platform-specific

[kenneth.r.christiansen, 2014-03-04 18:08:04]

Fixed the concerns

[apavlov, 2014-03-06 09:56:19]

https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
File LayoutTests/inspector/console/console-timestamp.html (right):

https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
LayoutTests/inspector/console/console-timestamp.html:13: "PASS",
It is desirable to have some text different from the outcome message, to avoid
confusion. "Console message text" will do fine.

https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
LayoutTests/inspector/console/console-timestamp.html:35:
InspectorTest.assertEquals("PASS", getConsoleLine(0));
Inspector tests normally do not run assertions but instead dump the results and
have them compared with expectations:

InspectorTest.addResult(getConsoleLine(0));

https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
LayoutTests/inspector/console/console-timestamp.html:38:
WebInspector.settings.consoleTimestampsEnabled.set(true);
Didn't we agree to have the timestamps toggled in real time, along with the
setting change?

https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
LayoutTests/inspector/console/console-timestamp.html:43:
InspectorTest.assertEquals("2014-05-13T16:53:20.123Z", date.toISOString());
InspectorTest.addResult(date.toISOString());

https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
LayoutTests/inspector/console/console-timestamp.html:46: //    Original
timestamp .123Z is updated with .123Z.
The latter should be ".321Z" instead. Or, use "456" to avoid this kind of
confusion in the future.

https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
LayoutTests/inspector/console/console-timestamp.html:51:
InspectorTest.assertEquals(0, line.indexOf("10")); // Prefixed with repeat
count.
This can be dumped as well

https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
LayoutTests/inspector/console/console-timestamp.html:54:
InspectorTest.assertEquals("2014-05-13T16:53:20.321Z", date.toISOString());
ditto

https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
File Source/devtools/front_end/ConsoleViewMessage.js (right):

https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
Source/devtools/front_end/ConsoleViewMessage.js:849: if (!this.timestampElement)
I suspect it should always be present (see below).

https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
Source/devtools/front_end/ConsoleViewMessage.js:852: var date = new
Date(this._message.timestamp * 1000);
This is the only client of ConsoleMessage.timestamp. Let's store the
milliseconds so that you won't have to /1000 in the ctor and *1000 here.

https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
Source/devtools/front_end/ConsoleViewMessage.js:854: + ("0" + (date.getMonth() +
1)).slice(-2) + "-"
This slicing is relatively slow, and I suspect it can dramatically slow down the
inspector when handling zillions of messages (an easily reproducible situation).
You can also extract this into a nested function:

/**
 * @param {number} value
 * @return {string}
 */
function zeroPad(value)
{
    return (value < 10 ? "0" : "") + value;
}

https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
Source/devtools/front_end/ConsoleViewMessage.js:899: if
(WebInspector.settings.consoleTimestampsEnabled.get()) {
We should also think of a way to add/remove the timestamps quickly upon the
setting switch. Perhaps, the timestamp element should also be present, but just
hidden with CSS when the setting is off.

https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
Source/devtools/front_end/ConsoleViewMessage.js:900: this.timestampElement =
document.createElement("span");
This snippet can be written as:

this.timestampElement = element.createChild("span", "console-timestamp");
this._updateTiemstamp();

https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
File Source/devtools/front_end/inspector.css (right):

https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
Source/devtools/front_end/inspector.css:897: margin-right: 10px;
Just an idea: we can wrap it into square brackets rather than use the right
margin

[kenneth.r.christiansen, 2014-03-06 15:31:22]

On 2014/03/06 09:56:19, apavlov wrote:
>
https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
> File LayoutTests/inspector/console/console-timestamp.html (right):
> 
>
https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
> LayoutTests/inspector/console/console-timestamp.html:13: "PASS",
> It is desirable to have some text different from the outcome message, to avoid
> confusion. "Console message text" will do fine.

done

>
https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
> LayoutTests/inspector/console/console-timestamp.html:35:
> InspectorTest.assertEquals("PASS", getConsoleLine(0));
> Inspector tests normally do not run assertions but instead dump the results
and
> have them compared with expectations:
> 
> InspectorTest.addResult(getConsoleLine(0));

done

>
https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
> LayoutTests/inspector/console/console-timestamp.html:38:
> WebInspector.settings.consoleTimestampsEnabled.set(true);
> Didn't we agree to have the timestamps toggled in real time, along with the
> setting change?

I didn't attempt this yet

>
https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
> LayoutTests/inspector/console/console-timestamp.html:43:
> InspectorTest.assertEquals("2014-05-13T16:53:20.123Z", date.toISOString());
> InspectorTest.addResult(date.toISOString());

done

>
https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
> LayoutTests/inspector/console/console-timestamp.html:46: //    Original
> timestamp .123Z is updated with .123Z.
> The latter should be ".321Z" instead. Or, use "456" to avoid this kind of
> confusion in the future.

done

>
https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
> LayoutTests/inspector/console/console-timestamp.html:51:
> InspectorTest.assertEquals(0, line.indexOf("10")); // Prefixed with repeat
> count.
> This can be dumped as well

done

>
https://codereview.chromium.org/185713007/diff/70001/LayoutTests/inspector/co...
> LayoutTests/inspector/console/console-timestamp.html:54:
> InspectorTest.assertEquals("2014-05-13T16:53:20.321Z", date.toISOString());
> ditto

done

>
https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
> File Source/devtools/front_end/ConsoleViewMessage.js (right):
> 
>
https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
> Source/devtools/front_end/ConsoleViewMessage.js:849: if
(!this.timestampElement)
> I suspect it should always be present (see below).

I will try this soon

>
https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
> Source/devtools/front_end/ConsoleViewMessage.js:852: var date = new
> Date(this._message.timestamp * 1000);
> This is the only client of ConsoleMessage.timestamp. Let's store the
> milliseconds so that you won't have to /1000 in the ctor and *1000 here.

I need to convert somewhere... either this way of the values coming from blink.
I left this as is


>
https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
> Source/devtools/front_end/ConsoleViewMessage.js:854: + ("0" + (date.getMonth()
+
> 1)).slice(-2) + "-"
> This slicing is relatively slow, and I suspect it can dramatically slow down
the
> inspector when handling zillions of messages (an easily reproducible
situation).
> You can also extract this into a nested function:
> 
> /**
>  * @param {number} value
>  * @return {string}
>  */
> function zeroPad(value)
> {
>     return (value < 10 ? "0" : "") + value;
> }

fixed

> 
>
https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
> Source/devtools/front_end/ConsoleViewMessage.js:899: if
> (WebInspector.settings.consoleTimestampsEnabled.get()) {
> We should also think of a way to add/remove the timestamps quickly upon the
> setting switch. Perhaps, the timestamp element should also be present, but
just
> hidden with CSS when the setting is off.

ok

> 
>
https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
> Source/devtools/front_end/ConsoleViewMessage.js:900: this.timestampElement =
> document.createElement("span");
> This snippet can be written as:
> 
> this.timestampElement = element.createChild("span", "console-timestamp");
> this._updateTiemstamp();

done

> 
>
https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
> File Source/devtools/front_end/inspector.css (right):
> 
>
https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
> Source/devtools/front_end/inspector.css:897: margin-right: 10px;
> Just an idea: we can wrap it into square brackets rather than use the right
> margin

Looks ugly :-) I could add a trailing space instead... it is not selectable
anyway

[eustas, 2014-03-06 15:40:04]

https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
File Source/devtools/front_end/ConsoleModel.js (right):

https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
Source/devtools/front_end/ConsoleModel.js:240: // Timestamp doesn't affect
equality.
This will cause grouping whereas we don't want it.
This should be configurable.

https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
File Source/devtools/front_end/ConsoleViewMessage.js (right):

https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
Source/devtools/front_end/ConsoleViewMessage.js:859: + date.getMilliseconds();
Milliseconds should be padded.

[kenneth.r.christiansen, 2014-03-06 16:42:41]

>
https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
> Source/devtools/front_end/ConsoleModel.js:240: // Timestamp doesn't affect
> equality.
> This will cause grouping whereas we don't want it.
> This should be configurable.

That would be changing current behavior. Though I can see that this can make
sense, I believe it should be a separate CL from this one.

[eustas, 2014-03-11 05:23:10]

On 2014/03/06 16:42:41, kenneth.r.christiansen wrote:
> >
>
https://codereview.chromium.org/185713007/diff/70001/Source/devtools/front_en...
> > Source/devtools/front_end/ConsoleModel.js:240: // Timestamp doesn't affect
> > equality.
> > This will cause grouping whereas we don't want it.
> > This should be configurable.
> 
> That would be changing current behavior. Though I can see that this can make
> sense, I believe it should be a separate CL from this one.

We've discussed that topic inside DevTools team.

Console message grouping should be completely disabled on backend.
Instead messages should be grouped only on frontend if flag "Show timestamps in
console" is not set.

[kenneth.r.christiansen, 2014-03-21 08:55:40]

Please review. I especially need advice for how to deal with the protocol
changes.

[apavlov, 2014-03-21 09:30:45]

Looks mostly good! Waiting for protocol folks to comment.

https://codereview.chromium.org/185713007/diff/110001/LayoutTests/inspector/c...
File LayoutTests/inspector/console/console-timestamp.html (right):

https://codereview.chromium.org/185713007/diff/110001/LayoutTests/inspector/c...
LayoutTests/inspector/console/console-timestamp.html:26: // 1. Ensure no
timestamp, just message.
unnecessary comment. Instead, add
InspectorTest.addResult("Console messages with timestamps disabled");
just before the first dumpConsoleMessages call.

https://codereview.chromium.org/185713007/diff/110001/LayoutTests/inspector/c...
LayoutTests/inspector/console/console-timestamp.html:27: for (var i = 0; i < 2;
i++) {
You can just write
addMessageWithFixedTimestamp();
addMessageWithFixedTimestamp();

which will save us one line :) Actually, you don't need braces for single-line
blocks in Blink

https://codereview.chromium.org/185713007/diff/110001/LayoutTests/inspector/c...
LayoutTests/inspector/console/console-timestamp.html:36: for (var i = 0; i < 2;
i++) {
Ditto

https://codereview.chromium.org/185713007/diff/110001/LayoutTests/inspector/c...
LayoutTests/inspector/console/console-timestamp.html:41:
InspectorTest.dumpConsoleMessages();
Add
InspectorTest.addResult("Console messages with timestamps enabled");
before this line

https://codereview.chromium.org/185713007/diff/110001/Source/core/inspector/I...
File Source/core/inspector/InspectorConsoleAgent.cpp (right):

https://codereview.chromium.org/185713007/diff/110001/Source/core/inspector/I...
Source/core/inspector/InspectorConsoleAgent.cpp:309: m_previousMessage =
consoleMessage.get();
Is m_previousMessage used anywhere at all?

https://codereview.chromium.org/185713007/diff/110001/Source/devtools/front_e...
File Source/devtools/front_end/ConsoleModel.js (right):

https://codereview.chromium.org/185713007/diff/110001/Source/devtools/front_e...
Source/devtools/front_end/ConsoleModel.js:111:
this._previousMessage.repeatCount++;
For things other than loop counters we tend to use += 1 for clarity, even though
this is not strictly mandated. And we usually use the prefix version (++foo)
wherever possible.

https://codereview.chromium.org/185713007/diff/110001/Source/devtools/front_e...
Source/devtools/front_end/ConsoleModel.js:202: this.warnings++;
ditto

https://codereview.chromium.org/185713007/diff/110001/Source/devtools/front_e...
Source/devtools/front_end/ConsoleModel.js:205: this.errors++;
ditto

https://codereview.chromium.org/185713007/diff/110001/Source/devtools/front_e...
Source/devtools/front_end/ConsoleModel.js:324: var l = this.parameters;
"l" is a poor variable name, since it's easily "confusible" with 1.

"mine" and "theirs" are better :)

https://codereview.chromium.org/185713007/diff/110001/Source/devtools/front_e...
Source/devtools/front_end/ConsoleModel.js:329: for (var i = 0; i < l.length;
i++) {
prefix ++ for consistency

https://codereview.chromium.org/185713007/diff/110001/Source/devtools/front_e...
File Source/devtools/front_end/ConsoleViewMessage.js (right):

https://codereview.chromium.org/185713007/diff/110001/Source/devtools/front_e...
Source/devtools/front_end/ConsoleViewMessage.js:54:
WebInspector.settings.consoleTimestampsEnabled.addChangeListener(this._consoleTimestampsSettingChanged.bind(this));
WebInspector.settings.consoleTimestampsEnabled.addChangeListener(this._consoleTimestampsSettingChanged,
this);

https://codereview.chromium.org/185713007/diff/110001/Source/devtools/front_e...
Source/devtools/front_end/ConsoleViewMessage.js:57: 
extra line added

https://codereview.chromium.org/185713007/diff/110001/Source/devtools/front_e...
Source/devtools/front_end/ConsoleViewMessage.js:854: if (!this.timestampElement)
{
don't we want the timestampElements to be lazily created only when necessary?

https://codereview.chromium.org/185713007/diff/110001/Source/devtools/front_e...
Source/devtools/front_end/ConsoleViewMessage.js:863:
this.timestampElement.textContent = "";
...and removed when no longer needed?

That can save us hundreds of extra elements in the page

https://codereview.chromium.org/185713007/diff/110001/Source/devtools/front_e...
File Source/devtools/front_end/ResourceTreeModel.js (right):

https://codereview.chromium.org/185713007/diff/110001/Source/devtools/front_e...
Source/devtools/front_end/ResourceTreeModel.js:400: resource.warnings++;
+= 1?

https://codereview.chromium.org/185713007/diff/110001/Source/devtools/front_e...
Source/devtools/front_end/ResourceTreeModel.js:403: resource.errors++;
ditto

[kenneth.r.christiansen, 2014-03-21 14:39:48]

Fixed all comments

[apavlov, 2014-03-21 14:47:57]

https://codereview.chromium.org/185713007/diff/130001/Source/core/inspector/I...
File Source/core/inspector/InspectorConsoleAgent.cpp (right):

https://codereview.chromium.org/185713007/diff/130001/Source/core/inspector/I...
Source/core/inspector/InspectorConsoleAgent.cpp:308: ConsoleMessage* msg =
consoleMessage.get();
Blink style does not honor abbreviations. Moreover, "msg" has only one usage, so
you can inline consoleMessage.get()

https://codereview.chromium.org/185713007/diff/130001/Source/devtools/front_e...
File Source/devtools/front_end/ConsoleViewMessage.js (right):

https://codereview.chromium.org/185713007/diff/130001/Source/devtools/front_e...
Source/devtools/front_end/ConsoleViewMessage.js:857:
this._element.insertBefore(this.timestampElement, afterRepeatCountChild ||
this._element.firstChild);
you can add a return; after this line, since the remaining code is the exact
opposite

[apavlov, 2014-03-21 15:12:22]

lgtm

[kenneth.r.christiansen, 2014-03-24 17:49:00]

ping protocol owners :-)

[apavlov, 2014-03-25 16:21:17]

Kenneth, please rebase your patch, as sergeyv has also removed the repeat counts
:)

[pfeldman, 2014-03-25 16:25:26]

Hey. There has been an unfortunate incident where message counters were removed
in r169953 (for a completely different reason - support for workers in the main
front-end window). Sorry about that. I'll review your protocol changes once this
is rebaselined so that you could land it with no further due.

[kenneth.r.christiansen, 2014-03-25 17:13:36]

On 2014/03/25 16:25:26, pfeldman wrote:
> Hey. There has been an unfortunate incident where message counters were
removed
> in r169953 (for a completely different reason - support for workers in the
main
> front-end window). Sorry about that. I'll review your protocol changes once
this
> is rebaselined so that you could land it with no further due.

So should they be removed all together or just readded in JS like I am doing?

[apavlov, 2014-03-26 11:51:42]

lgtm

[apavlov, 2014-03-26 11:53:10]

https://codereview.chromium.org/185713007/diff/330001/Source/devtools/front_e...
File Source/devtools/front_end/ConsoleView.js (right):

https://codereview.chromium.org/185713007/diff/330001/Source/devtools/front_e...
Source/devtools/front_end/ConsoleView.js:425:
this._messageToViewMessage.get(this._previousMessage).incrementRepeatCount(message.timestamp);
I'd rename this method to avoid any confusion

[kenneth.r.christiansen, 2014-03-26 12:25:56]

The CQ bit was checked by kenneth.r.christiansen@intel.com

[commit-bot: I haz the power, 2014-03-26 12:26:02]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/kenneth.r.christiansen@intel.com/18571...

[commit-bot: I haz the power, 2014-03-26 12:47:41]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2014-03-26 12:47:41]

Try jobs failed on following builders:
  tryserver.blink on win_blink_compile_dbg

[kenneth.r.christiansen, 2014-03-26 12:53:39]

The CQ bit was checked by kenneth.r.christiansen@intel.com

[commit-bot: I haz the power, 2014-03-26 12:53:51]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/kenneth.r.christiansen@intel.com/18571...

[commit-bot: I haz the power, 2014-03-26 13:28:07]

Change committed as 170055