New issue
Advanced search Search tips

Issue 844511 link

Starred by 3 users

Issue metadata

Status: Fixed
Owner:
Closed: May 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 1
Type: Bug

Blocking:
issue 846676



Sign in to add a comment

Many tests are failing on perf waterfall with "Failure recorded: Error: Tasks must not overlap"

Project Member Reported by nednguyen@chromium.org, May 18 2018

Issue description

Example log:
(WARNING) 2018-05-17 02:21:43,674 timeline_based_measurement._ComputeTimelineBasedMetrics:316  Processing resulting traces took 17.330 seconds
Failure recorded: Error: Tasks must not overlap
    at Object.maxExpectedQueueingTimeInSlidingWindow (/tracing/extras/chrome/estimated_input_latency.html:331:15)
    at addExpectedQueueingTimeMetric_ (/tracing/metrics/system_health/expected_queueing_time_metric.html:144:23)
    at new expectedQueueingTimeMetric (/tracing/metrics/system_health/expected_queueing_time_metric.html:86:5)
    at runMetrics (/b/s/w/ir/third_party/catapult/tracing/tracing/metrics/metric_map_function.html:47:16)
    at metricMapFunction (/b/s/w/ir/third_party/catapult/tracing/tracing/metrics/metric_map_function.html:150:24)
    at Object.mapSingleTrace (/tracing/mre/map_single_trace.html:39:7)
    at eval (/b/s/w/ir/third_party/catapult/tracing/tracing/mre/map_single_trace_cmdline.html:61:18)
    at Object.runAndConvertErrorsToFailures (/tracing/mre/map_single_trace.html:24:10)
    at mapSingleTraceWithResult (/b/s/w/ir/third_party/catapult/tracing/tracing/mre/map_single_trace_cmdline.html:52:12)
    at Object.mapSingleTraceMain (/b/s/w/ir/third_party/catapult/tracing/tracing/mre/map_single_trace_cmdline.html:77:20)
(INFO) 2018-05-17 02:21:43,828 browser.Close:207  Closing browser (pid=20137) ...
(INFO) 2018-05-17 02:21:44,053 browser.Close:220  Browser is closed.

(https://chromium-swarm.appspot.com/user/task/3d85d3128cb85110)

This affect a lot of v8 realworld benchmarks. See "v8.browsing_desktop-future on Intel GPU on Mac on Mac-10.12" in https://ci.chromium.org/buildbot/chromium.perf/Mac%2010.12%20Perf/2064



 
Cc: benjhayden@chromium.org tdres...@chromium.org
+Ben, Tim in case you're aware of any change recently in this area

Comment 2 by eyaich@chromium.org, May 18 2018

Cc: eyaich@google.com
 Issue 844519  has been merged into this issue.

Comment 3 by eyaich@chromium.org, May 18 2018

We are seeing 15 story failures for v8.browsing_desktop* desktop and 21 on v8.browsing_mobile*.

Disabling on all platforms for now until this can be resolved.
Project Member

Comment 4 by bugdroid1@chromium.org, May 18 2018

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

commit 9d370074256308fe49baef585c254da8e81a8725
Author: Emily Hanley <eyaich@google.com>
Date: Fri May 18 18:13:33 2018

Disabling v8.browsing* on chromium.perf

TBR=nednguyen@google.com
NOTRY=true

Bug:  844511 
Change-Id: I8b8646c219f0e501af546b07fdc674cd90edffc6
Reviewed-on: https://chromium-review.googlesource.com/1066327
Reviewed-by: Emily Hanley <eyaich@chromium.org>
Commit-Queue: Emily Hanley <eyaich@chromium.org>
Cr-Commit-Position: refs/heads/master@{#559959}
[modify] https://crrev.com/9d370074256308fe49baef585c254da8e81a8725/tools/perf/expectations.config

https://console.developers.google.com/m/cloudstorage/b/chrome-telemetry-output/o/browse_social_twitter_2018-05-17_02-41-53_40236.html

In this trace, in the NASA renderer, in its main thread, the MessageLoop::RunTask at 1058.9ms ends 6ms after the BlinkGC.AtomicPhaseMarking begins at 1061ms. Should BlinkGC.AtomicPhaseMarking be an async event?

Cc: mlippautz@chromium.org
Looks like that trace event was recently changed.
https://chromium-review.googlesource.com/c/chromium/src/+/1057626

Michael, is it guaranteed that InternalScope objects are destroyed in the same task that they are created? If not, then they should be async events. Please see the trace in #5 for example.
Ulan: would you be interested in adding more information to the error messages to make it easier to debug issues like this in the future? I just hacked the trace file to plumb the slices from the expectedQueuingTimeMetric down to the maxExpectedQueueingTimeInSlidingWindow function, for example.

Comment 8 by u...@chromium.org, May 22 2018

Owner: mlippautz@chromium.org
Status: Assigned (was: Untriaged)
I agree with comment #6. The trace in Comment #5 shows that something is off with BlinkGC.AtomicPhaseMarking as it starts at the beginning of the run and does not finish.

benjhayden@, what kind of debug info do you have in mind? The names of the traces? We can add them if they are useful. They will slightly slow down the metric computation though.
trace.png
346 KB View Download
#8: The titles of the overlapping slices and their thread's names might have helped in this case, yes. I'm not sure what other data would help debug the other errors, I'll defer to you. Let's look at the performance impact in code review?
Cc: -mlippautz@chromium.org
Status: Started (was: Assigned)
Will have a look immediately.
The scope should always stay on the same task, so I think it is fine in general.

However, we had a fix landing on May 21 that dealt with scopes that were not properly closed:
  https://chromium-review.googlesource.com/c/chromium/src/+/1065723

Anything more to do here other than re-enabling?
Project Member

Comment 13 by bugdroid1@chromium.org, May 23 2018

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

commit 697b81fc4fee63cf5a41ce1fc5197e6423f4767f
Author: Ned Nguyen <nednguyen@google.com>
Date: Wed May 23 16:08:23 2018

Revert "Disabling v8.browsing* on chromium.perf"

This reverts commit 9d370074256308fe49baef585c254da8e81a8725.

Reason for revert: problem may have already been fixed

Original change's description:
> Disabling v8.browsing* on chromium.perf
> 
> TBR=nednguyen@google.com
> NOTRY=true
> 
> Bug:  844511 
> Change-Id: I8b8646c219f0e501af546b07fdc674cd90edffc6
> Reviewed-on: https://chromium-review.googlesource.com/1066327
> Reviewed-by: Emily Hanley <eyaich@chromium.org>
> Commit-Queue: Emily Hanley <eyaich@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#559959}

TBR=nednguyen@google.com,eyaich@chromium.org

# Not skipping CQ checks because original CL landed > 1 day ago.

Bug:  844511 
Change-Id: I33fd7406cea555516be3281e3d1aefaf6d0431b7
Reviewed-on: https://chromium-review.googlesource.com/1070347
Reviewed-by: Ned Nguyen <nednguyen@google.com>
Commit-Queue: Ned Nguyen <nednguyen@google.com>
Cr-Commit-Position: refs/heads/master@{#561111}
[modify] https://crrev.com/697b81fc4fee63cf5a41ce1fc5197e6423f4767f/tools/perf/expectations.config

Ned, can you lmk if anything is not working? Thanks!
Status: Fixed (was: Started)
It's green again in https://ci.chromium.org/buildbot/chromium.perf/Mac%2010.12%20Perf/2091  ^__^

Total tests: 19
* Passed: 14 (14 expected, 0 unexpected)
* Skipped: 5 (5 expected, 0 unexpected)
* Failed: 0 (0 expected, 0 unexpected)
* Flaky: 0 (0 expected, 0 unexpected)


Blocking: 846676

Sign in to add a comment