New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 835502 link

Starred by 6 users

Issue metadata

Status: Fixed
Owner:
Closed: Jul 2
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Linux , Windows , Mac
Pri: 1
Type: Bug-Regression



Sign in to add a comment

Network requests timings are broken in DevTools

Project Member Reported by alph@chromium.org, Apr 21 2018

Issue description

The finish_time for network requests is wrong in both network and performance panels. The following patch seems to be responsible for the regression: https://chromium.googlesource.com/chromium/src/+/91088a195969f5af61f404c9f02edc622cbe373a

To reproduce, open e.g. https://chromium-review.googlesource.com/c/chromium/src/+/1011586
and record page load profile in DevTools.

Notice that all network requests finish times (right end of network requests bars) never falls into a long running task, but instead get postponed until the main thread gets idle. This is strange as network IO should not depend on main thread activity.

For example on the network panel the requests for photo.png used to be ~20ms and with the patch they are reported as ~280ms. See the attached screenshots.

 

Comment 1 by alph@chromium.org, Apr 21 2018

The screenshots
timeline-network-bad.png
169 KB View Download
timeline-network-good.png
117 KB View Download
network-bad.png
158 KB View Download
network-good.png
146 KB View Download
Components: -Internals>Network Blink>Loader

Comment 3 by gov...@chromium.org, Apr 25 2018

M67 Stable promotion is coming soon. Your bug is labelled as Stable ReleaseBlock, pls make sure to land the fix and request a merge into the release branch ASAP. Thank you.


Labels: -ReleaseBlock-Stable
I don't think this is a stable blocker.
Agree this isn't stable blocker, though we would like it fixed soon. Thank you!

Comment 6 by alph@chromium.org, May 11 2018

 Issue 837503  has been merged into this issue.
Project Member

Comment 7 by bugdroid1@chromium.org, May 11 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/560e1ab54b7397d97533fd08a047ca7f54071bcf

commit 560e1ab54b7397d97533fd08a047ca7f54071bcf
Author: Yutaka Hirano <yhirano@chromium.org>
Date: Fri May 11 07:43:46 2018

Reset ResourceDispatcher::PendingRequest::request_start on redirect

net::URLRequest clears its request_start on redirect, so we should do
the same in the renderer.

Bug:  824155 ,  835502 
Change-Id: I74252d62d98aae0e26e4ee30ad21eeefb5fda267
Reviewed-on: https://chromium-review.googlesource.com/1054907
Commit-Queue: Yutaka Hirano <yhirano@chromium.org>
Reviewed-by: Matt Menke <mmenke@chromium.org>
Cr-Commit-Position: refs/heads/master@{#557810}
[modify] https://crrev.com/560e1ab54b7397d97533fd08a047ca7f54071bcf/content/renderer/loader/resource_dispatcher.cc

Labels: Needs-Feedback
Tested the issue on mac 10.13.3 using chrome version without fix i.e 65.0.3325.162. Observed that ResourceTiming duration is very less and seems to be not reproducible on that chrome version(build without fix).

Attaching a screen cast for reference.

alph@ - Could you please check the attached screencast and please help us in verifying the fix.

Thanks...!!
835502@65.0.3325.162.mp4
3.6 MB View Download

Comment 9 by alph@chromium.org, May 14 2018

Cc: vamshi.kommuri@chromium.org
 Issue 836466  has been merged into this issue.
Project Member

Comment 10 by bugdroid1@chromium.org, May 17 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/8004bde35ba57035a7de0e85ed80d34573bc365d

commit 8004bde35ba57035a7de0e85ed80d34573bc365d
Author: Yutaka Hirano <yhirano@chromium.org>
Date: Thu May 17 14:37:31 2018

Fix inter-process completion timestamp conversion

We basically use request completion time recorded in the render
process to calculate responseEnd defined in Resource Timing API. This
is problematic because the renderer main thread can be blocked for a
long time, and that is confusing users of devtools and Resource
Timing API.

This CL changes how to calculate responseEnd. With this CL, it will be
calculated based on the completion time recorded in the browser
process.

Bug:  824155 ,  835502 ,  843440 
Change-Id: I990da586a86c420d21a8115d13e840f7c29d462e
Reviewed-on: https://chromium-review.googlesource.com/1053849
Reviewed-by: Timothy Dresser <tdresser@chromium.org>
Reviewed-by: Kinuko Yasuda <kinuko@chromium.org>
Commit-Queue: Yutaka Hirano <yhirano@chromium.org>
Cr-Commit-Position: refs/heads/master@{#559530}
[modify] https://crrev.com/8004bde35ba57035a7de0e85ed80d34573bc365d/content/renderer/loader/resource_dispatcher.cc
[modify] https://crrev.com/8004bde35ba57035a7de0e85ed80d34573bc365d/content/renderer/loader/resource_dispatcher.h
[modify] https://crrev.com/8004bde35ba57035a7de0e85ed80d34573bc365d/content/renderer/loader/resource_dispatcher_unittest.cc
[modify] https://crrev.com/8004bde35ba57035a7de0e85ed80d34573bc365d/content/renderer/loader/test_request_peer.cc
[modify] https://crrev.com/8004bde35ba57035a7de0e85ed80d34573bc365d/content/renderer/loader/test_request_peer.h

Comment 11 by alph@chromium.org, May 17 2018

Looks like the last patch has fixed the issue.
Project Member

Comment 12 by bugdroid1@chromium.org, May 22 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/b3e41e67541fcb9e13bde7db301402f675f38e92

commit b3e41e67541fcb9e13bde7db301402f675f38e92
Author: Yutaka Hirano <yhirano@chromium.org>
Date: Tue May 22 08:24:56 2018

InterProcessTimeTicksConverter miscellaneous refactorings and bug fixes

This CL consists of bunch of cleanups and bug fixes:

 - LocalTimeTicks and RemoteTimeTicks are rewritten. They are now
   typedefs of SiteSpecificTimeDelta<SiteSpecificTimeLocalTag> and
   SiteSpecificTimeDelta<SiteSpecificTimeRemoteTag>, respectively, and
   have consistent methods each other.
 - Same for LocalTimeDelta and RemoteTimeDelta. Now they hold int64_t
   (via base::TimeDelta) rather than int32_t, which is good because
   int32_t lasts less than one hour.
 - This CL removes many integer operations and replaces them with
   base::TimeTicks and base::TimeDelta operations. This CL also removes
   many ToInternalValue and FromInternalValue calls which are
   deprecated.
 - InterProcessTimeTicksConverter now holds a double value for
   interpolation rather than two int64_t values as using int64_t leads
   to overflow.

Bug:  824155 ,  835502 
Change-Id: I51ed657f0370d13b509c65324afc3af81b249e37
Reviewed-on: https://chromium-review.googlesource.com/1055171
Commit-Queue: Yutaka Hirano <yhirano@chromium.org>
Reviewed-by: Matt Menke <mmenke@chromium.org>
Reviewed-by: Kinuko Yasuda <kinuko@chromium.org>
Cr-Commit-Position: refs/heads/master@{#560511}
[modify] https://crrev.com/b3e41e67541fcb9e13bde7db301402f675f38e92/content/common/inter_process_time_ticks_converter.cc
[modify] https://crrev.com/b3e41e67541fcb9e13bde7db301402f675f38e92/content/common/inter_process_time_ticks_converter.h
[modify] https://crrev.com/b3e41e67541fcb9e13bde7db301402f675f38e92/content/common/inter_process_time_ticks_converter_unittest.cc

Status: Fixed (was: Assigned)

Sign in to add a comment