Issue metadata
Sign in to add a comment
|
DevTools: Correct timestamp not shown for console evaluations
Reported by
starbala...@gmail.com,
Jun 28 2017
|
||||||||||||||||||||||
Issue descriptionUserAgent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/59.0.3071.115 Safari/537.36 Steps to reproduce the problem: 1. In console settings -> Console -> Show timestamp should be checked 2. Open console and execute any js statement What is the expected behavior? Current timestamp should be shown along the result of the executed statement What went wrong? Some stale timestamp is shown. Check the attached image. Did this work before? Yes Chrome version: 59.0.3071.115 Channel: stable OS Version: OS X 10.12.4 Flash Version: Correct timestamp shown for logs triggered from loaded js/logs triggered from executed script (like setTimeout -> put log). Incorrect timestamp comes only for live statements alone.
,
Jun 29 2017
,
Jun 29 2017
@woxxom: Thanks for providing the bisect information. CHANGELOG URL: https://chromium.googlesource.com/chromium/src/+log/a65347a0..f77ebec0?pretty=fuller Review-Url: https://codereview.chromium.org/2651843003 @luoe: Could you please look into the issue, pardon me if it has nothing to do with your changes and if possible please assign it to concern owner. Thanks!!
,
Jun 29 2017
Thanks for the report and the bisect. For evaluated commands (typing and pressing enter), these timestamps are incorrect. DevTools rewrites the timestamp for evaluated commands and their results, to preserve their order when sorting by time. We can either add a "display timestamp" and keep sorting internally, stop sorting entirely, or hide result timestamps entirely. For reference, Firefox can show messages with timestamps out of order.
,
Jun 29 2017
,
Aug 7 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/f2911d6203ee076f5cf1d7b26fee8972361922d3 commit f2911d6203ee076f5cf1d7b26fee8972361922d3 Author: Erik Luo <luoe@chromium.org> Date: Mon Aug 07 21:35:11 2017 DevTools: preserve console timestamps and sort on logical timestamps Before, evaluated command and result console messages had their timestamps overwritten to appear next to each other. This led to misleading times that were incorrect, making commands seem to execute immediately. This CL preserves their original timestamp for display, and introduces logical timestamps for sorting purposes. Now, commands and results have more useful times, even though their timestamps come from frontend, not backend. BUG= 737463 Change-Id: I8c6221bbf61919a3a8d9d96f011fb25850a6a98a Reviewed-on: https://chromium-review.googlesource.com/590502 Commit-Queue: Erik Luo <luoe@chromium.org> Reviewed-by: Andrey Lushnikov <lushnikov@chromium.org> Cr-Commit-Position: refs/heads/master@{#492419} [modify] https://crrev.com/f2911d6203ee076f5cf1d7b26fee8972361922d3/third_party/WebKit/LayoutTests/inspector/console/console-timestamp-expected.txt [modify] https://crrev.com/f2911d6203ee076f5cf1d7b26fee8972361922d3/third_party/WebKit/LayoutTests/inspector/console/console-timestamp.html [modify] https://crrev.com/f2911d6203ee076f5cf1d7b26fee8972361922d3/third_party/WebKit/Source/devtools/front_end/console/ConsoleView.js [modify] https://crrev.com/f2911d6203ee076f5cf1d7b26fee8972361922d3/third_party/WebKit/Source/devtools/front_end/console_model/ConsoleModel.js
,
Aug 14 2017
,
Aug 20 2017
loue@ one case when the order is still incorrect:
1. disable timestamps in devtools console settings
2. clear the console (Ctrl-L)
3. run some async code, for example:
fetch(location).then(r => r.text()).then(t => console.log('got %d bytes', t.length))
The result sometimes/often will be on top of the log.
I can submit a new bug report if required.
,
Aug 20 2017
Yes, please! A new crbug report about the ordering of messages would be great. Feel free to tag me as owner. If it is a bug that occurs sometimes but not always it sounds like a different root cause.
,
Aug 20 2017
loue@, I'm doubtful because your r492419 is within bisected range: https://chromium.googlesource.com/chromium/src/+log/62f41748..f768b8da?pretty=fuller and I can repro reliably after clearing the console via Ctrl-L so I thought maybe it's some missed edge case.
,
Aug 20 2017
Submitted it as issue 757245 and found the correlation: the async console.log output displays the moment the console was cleared instead of the correct timestamp. |
|||||||||||||||||||||||
►
Sign in to add a comment |
|||||||||||||||||||||||
Comment 1 by woxxom@gmail.com
, Jun 28 2017