New issue
Advanced search Search tips

Issue 817135 link

Starred by 2 users

Issue metadata

Status: WontFix
Owner:
Closed: Mar 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 2
Type: Bug-Regression



Sign in to add a comment

7.1%-7.2% regression in media.mobile at 539291:539358

Project Member Reported by tmathmeyer@chromium.org, Feb 28 2018

Issue description

See the link to graphs below.
 
Project Member

Comment 1 by 42576172...@developer.gserviceaccount.com, Feb 28 2018

All graphs for this bug:
  https://chromeperf.appspot.com/group_report?bug_id=817135

(For debugging:) Original alerts at time of bug-filing:
  https://chromeperf.appspot.com/group_report?sid=6b5d32cd6c6d722661bace55482a81d5ab3cb2d2b63bf90c31030a26312c5b54


Bot(s) for this bug's original alert(s):

android-nexus5
Cc: chcunningham@chromium.org haraken@chromium.org f...@opera.com
Owner: chcunningham@chromium.org
Status: Assigned (was: Untriaged)
📍 Found a significant difference after 1 commit.
https://pinpoint-dot-chromeperf.appspot.com/job/101fa5b8440000

Improve HTMLMediaElement scheduling of timeupdate by chcunningham@chromium.org
https://chromium.googlesource.com/chromium/src/+/ad2b582f574ea854e8fd0f845c3675e831f3ffac

Understanding performance regressions:
  http://g.co/ChromePerformanceRegressions
Gonna kick off a new pinpoint to see if its consistent. 

The suspected CL increases the frequency of timeupdate event scheduling, so it is possible to trigger some very small resource uptick. But timeupdate (and event scheduling in general) should not cpu intensive, so I'm a bit surprised to see it blamed. The frequency of timeupdate was increased to match the spec, but we still schedule it as infrequently in as spec allows and actually decreased some edge cases where events were fired. 
Cc: tmathmeyer@google.com
 Issue 817945  has been merged into this issue.
 Issue 817958  has been merged into this issue.
Cc: mlamouri@chromium.org dalecur...@chromium.org crouleau@chromium.org
+reviewers, test owners, stakeholders. 

2 new alerts blamed me, so expect the pinpoint jobs in Comment 5 and 6 to do the same.  We'll probably get a few more dupes for the other platforms.

Good news is we're covering both desktop and mobile now... nothing about my change was mobile specific so things are making sense.

Thinking about it more, given the frequency this event fires, perahps these results aren't too surprising. The target is to fire this event 4x per second during playback. That is the lowest frequency allowed by the spec. 

"... if the user agent has not fired a timeupdate event at the element in the past 15 to **250ms** and is not still running event handlers for such an event, then the user agent must queue a task to fire a simple event named timeupdate at the element."

On my machine, the behavior prior to this CL was that the event fired roughly half as often (2x per second) due to the small innacuracies in underlying timer.

https://chromium-review.googlesource.com/c/chromium/src/+/938667#message-3a86ad5e34c55430c75e9f635be7cafc03a91af6

So the question is, do we agree that 2x the events seems a likely cause. And are we ok with that? It would be trivial to change the timing to fire 2x per second - we would just continue to not adhere to the spec.

Also, I checked video.html - the test doesn't seem to even listening in timeupdate, so no leads there. 
📍 Found a significant difference after 1 commit.
https://pinpoint-dot-chromeperf.appspot.com/job/12b66a74440000

Improve HTMLMediaElement scheduling of timeupdate by chcunningham@chromium.org
https://chromium.googlesource.com/chromium/src/+/ad2b582f574ea854e8fd0f845c3675e831f3ffac

Understanding performance regressions:
  http://g.co/ChromePerformanceRegressions
📍 Found a significant difference after 1 commit.
https://pinpoint-dot-chromeperf.appspot.com/job/1280e424440000

Improve HTMLMediaElement scheduling of timeupdate by chcunningham@chromium.org
https://chromium.googlesource.com/chromium/src/+/ad2b582f574ea854e8fd0f845c3675e831f3ffac

Understanding performance regressions:
  http://g.co/ChromePerformanceRegressions
I would be nice to confirm that the increased frequency of the timeupdates is the cause. To do this, you could write a CL that decreased the frequency back to 2x per second and then either

1. trigger a perf try job for that change and see what the performance difference is (I can find documentation on this for you)

or 

2. commit the change, wait a couple days, and see what happens to the graph.
The pinponit jobs in Comments 13 and 14 are running against a new CL (not landed) reduces the timer frequency to 2x per second. 

https://chromium-review.googlesource.com/c/chromium/src/+/946728
📍 Couldn't reproduce a difference.
https://pinpoint-dot-chromeperf.appspot.com/job/124688a4440000
Status: WontFix (was: Assigned)
Status: Untriaged (was: WontFix)
Oops, accidentally did these in a batch.
📍 Couldn't reproduce a difference.
https://pinpoint-dot-chromeperf.appspot.com/job/144688a4440000
Caleb, the pinpoints in 13 and 14 failed to find a CPU difference. Can you double check my jobs to look for mistakes? Also, do you know what the graph is about (no labels on the axis)?

It may just be that the theory of event frequency isn't panning out, and something else about the change is using the CPU. I'll upload a new CL where I just outright revert the CL and see pinpoint finds a difference. 
Pinpoint jobs in  comments 21-24 are running on a full revert of the offending CL. I did 4 jobs to experiment with bots and pinpoint story filter... 

https://chromium-review.googlesource.com/c/chromium/src/+/949664
📍 Couldn't reproduce a difference.
https://pinpoint-dot-chromeperf.appspot.com/job/14d978bc440000
📍 Couldn't reproduce a difference.
https://pinpoint-dot-chromeperf.appspot.com/job/11f06b7c440000
I'd expect this means we're not reaching the low power idle state as frequently given the increased wakeups to run the timer; it seems like a reliable increase, so I wonder if we should consider not firing timeupdate if there are no listeners to it? If possible it seems like something that might be worth applying to all events... so if it's not done today it's probably hard.

Since this is enforcing spec compliant behavior I think it's worth doing, but it's probably worth experimenting with it to see if reducing it further (100ms) causes more power usage and if setting it higher (500ms) reduces power. We then might decide in the future that on battery power we'll intervene and fire this only every 500ms or something.
Status: Assigned (was: Untriaged)
Cc: brucedaw...@chromium.org
Components: Internals>Media
+Bruce for timer update frequency affecting system resource utilization.
📍 Couldn't reproduce a difference.
https://pinpoint-dot-chromeperf.appspot.com/job/12c717c2440000
📍 Couldn't reproduce a difference.
https://pinpoint-dot-chromeperf.appspot.com/job/14c717c2440000
Cc: sullivan@chromium.org
Components: Speed>Bisection
+sullivan@

Pinpoint blamed me (fair enough) but then could not reproduce a difference on a full revert of my CL (see comment 25).
Cc: dtu@chromium.org simonhatch@chromium.org
+dtu and simonhatch are working on improving the UI for this type of case right now.

What I think is happening:
1) For all the try jobs in #26, 27, 31, and 32, it's using the return_code as a metric, and saying it "Couldn't reproduce a difference" means it saw a return code of 1 in all cases. This is super confusing and we're working on it showing the original metric instead.
2) So how do you see the metric? You would click on "Analyze benchmark results", but for two of these I only see benchmark_total_duration, and for the other two the files fail to load.

Dave, Simon, can one of you pull the numbers to see if the revert improves performance? 

The broader UI issues are being tracked here: https://github.com/catapult-project/catapult/issues/4298

Comment 37 by dtu@chromium.org, Mar 6 2018

I kicked off a job (I guess 2 jobs, by mistake?) using the "Test a patch" button on the Job page. The "+" button on the Jobs listing is for perf try jobs without a metric specified.
So I checked the results 2 for the nexus5 run specified in #c21, https://storage.cloud.google.com/chromeperf.appspot.com/results2/14c717c2440000.html

And if I'm reading that correctly, it implies a about a 7.5% improvement in cpu usage with chcunningham@'s revert cl applied.
Excited about the coming UI fixes. Simon, the results2 link you provided gives me a 403 error. Attempting to get results2 from my jobs (clicking 'Analyze benchmark results') gives me a 500 error. 


Now that we know the full revert does fix the issue, I'll kick off 2 additional bisects to see if simply increasing the timer delay to 2s per second has the same effect.

With that confirmed, we can decide what next. 

> but it's probably worth experimenting with it to see if reducing it further (100ms) causes more power usage and if setting it higher (500ms) reduces power. We then might decide in the future that on battery power we'll intervene and fire this only every 500ms or something.

We haven't had any alerts come in for power usage yet. If we can get the results2 links working I may be able to see what power differences were observed by the revert. 
^^ thats the android job.

Mac job is here: https://pinpoint-dot-chromeperf.appspot.com/job/15d424b2440000
Ah, if it's just cpu usage w/o any power usage change I wouldn't be too worried about this, though you should make sure nothing unexpected is happening. Testing the lower and higher rate versions to see if the effects match seems sufficient.
📍 Found a significant difference after 1 commit.
https://pinpoint-dot-chromeperf.appspot.com/job/14d17072440000

Reduce HTMLMediaElement timeupdate to 2x per second to explore CPU side effects by chcunningham@chromium.org
https://chromium-review.googlesource.com/c/chromium/src/+/946728/1

Understanding performance regressions:
  http://g.co/ChromePerformanceRegressions
📍 Found a significant difference after 1 commit.
https://pinpoint-dot-chromeperf.appspot.com/job/16a8c992440000

Revert "Improve HTMLMediaElement scheduling of timeupdate" by chcunningham@chromium.org
https://chromium-review.googlesource.com/c/chromium/src/+/949664/1

Understanding performance regressions:
  http://g.co/ChromePerformanceRegressions
📍 Found a significant difference after 1 commit.
https://pinpoint-dot-chromeperf.appspot.com/job/14f4ee62440000

Revert "Improve HTMLMediaElement scheduling of timeupdate" by chcunningham@chromium.org
https://chromium-review.googlesource.com/c/chromium/src/+/949664/1

Understanding performance regressions:
  http://g.co/ChromePerformanceRegressions
Status: WontFix (was: Assigned)
Pinpoint results show timer frequency likely accounts for the CPU % difference.

Job in Comment 43 shows a 7% CPU time decrease for reducing timer to 2x / sec.

Job in Comment 44 shows a 4.5% CPU time decrease for full revert (so some noise in the measurement, but good enough). 

Closing per Comment 42.

Sign in to add a comment