Chromium Code Reviews
|
|
Chromium Code Reviews
Issue
1084533005:
Support total and per-second task/threadtime timeline metrics (Closed)
|
Created:
5 years, 7 months ago by jdduke (slow) Modified:
5 years, 7 months ago CC:
chromium-reviews, telemetry-reviews_chromium.org, Rick Byers Base URL:
https://chromium.googlesource.com/chromium/src.git@master Target Ref:
refs/pending/heads/master Project:
chromium Visibility:
Public. |
DescriptionSupport total and per-second task/threadtime timeline metrics
The current threadtime timeline measurement only supports per-frame
metrics. Generalize this to support total and per-second metrics for
threadtimes and tasks.
BUG=466213
CQ_EXTRA_TRYBOTS=tryserver.chromium.perf:mac_perf_bisect;tryserver.chromium.perf:android_nexus5_perf_bisect
Committed: https://crrev.com/ce2699e20c3eae9dc17573fd2eb0885875341f44
Cr-Commit-Position: refs/heads/master@{#329322}
Patch Set 1 #Patch Set 2 : Cleanup #
Total comments: 9
Patch Set 3 : Support for per-second threadtimes #Patch Set 4 : Cleanup and working tests #Patch Set 5 : Filter metrics #Patch Set 6 : Cleanup #
Total comments: 2
Patch Set 7 : Use time from interaction_records #
Total comments: 8
Patch Set 8 : Code review #Patch Set 9 : Cleanup #
Total comments: 5
Patch Set 10 : Code review (use %) #
Total comments: 2
Patch Set 11 : Change interval to seconds #
Total comments: 2
Patch Set 12 : Precomputed expectations #
Messages
Total messages: 38 (10 generated)
jdduke@chromium.org changed reviewers: + nednguyen@google.com
As requested, here's the change that implements the measurement/metric changes with tests. https://codereview.chromium.org/1084533005/diff/20001/tools/perf/metrics/time... File tools/perf/metrics/timeline.py (right): https://codereview.chromium.org/1084533005/diff/20001/tools/perf/metrics/time... tools/perf/metrics/timeline.py:130: def ThreadCpuTimeResultName(thread_category, measure_per_frame=True): I'm not married to the |measure_per_frame| name.
nednguyen@google.com changed reviewers: + sullivan@chromium.org
Before even introducing new metrics, we should first start with experimenting a metric that would catch crbug.com/462752. I want to see an experimental metric that clearly regresses if you revert the fix in 462752. https://codereview.chromium.org/1084533005/diff/20001/tools/perf/metrics/time... File tools/perf/metrics/timeline.py (right): https://codereview.chromium.org/1084533005/diff/20001/tools/perf/metrics/time... tools/perf/metrics/timeline.py:130: def ThreadCpuTimeResultName(thread_category, measure_per_frame=True): On 2015/04/29 18:07:17, jdduke wrote: > I'm not married to the |measure_per_frame| name. I don't thing these helpers function add any value in making the code more readable or shorter. We should get rid of these. https://codereview.chromium.org/1084533005/diff/20001/tools/perf/metrics/time... tools/perf/metrics/timeline.py:134: return "thread_" + thread_category + "_cpu_time_total" How stable is this thread_X_cpu_time_total metric? Note that we sometime have situation that page waits on some js condition. Since the waiting logic is polling, I suspect that this metric has high variance. https://codereview.chromium.org/1084533005/diff/20001/tools/perf/metrics/time... tools/perf/metrics/timeline.py:139: return "tasks_" + thread_category Same here, I think you should come up with a new ThreadTimeTotal metric that computes something like tasks/seconds to avoid the timing issue. https://codereview.chromium.org/1084533005/diff/20001/tools/perf/metrics/time... tools/perf/metrics/timeline.py:255: def __init__(self, measure_per_frame=True): Can you refactor this differently so we have two different classes instead of one class with param like this? The idea here is later, we gonna port thread_times benchmark to use timeline based measurement instead. And in TBM model, all the timeline_based_metric should be directly constructible so we can do things like: for all subclass S of timeline based metrics: S.AddResults(...)
On 2015/04/30 05:07:45, nednguyen wrote: > Before even introducing new metrics, we should first start with experimenting a > metric that would catch crbug.com/462752. > > I want to see an experimental metric that clearly regresses if you revert the > fix in 462752. Now I'm confused. The metric you speak of IS this metric. All of the threadtimes/tasks counts here regress significantly in all of the "screen off" key_power_cases you were reviewing (https://codereview.chromium.org/1097463004/) without the fix we made to crbug.com/462752. Maybe I wasn't clear, but that patch is indeed a regression test for crbug.com/462752.
https://codereview.chromium.org/1084533005/diff/20001/tools/perf/metrics/time... File tools/perf/metrics/timeline.py (right): https://codereview.chromium.org/1084533005/diff/20001/tools/perf/metrics/time... tools/perf/metrics/timeline.py:134: return "thread_" + thread_category + "_cpu_time_total" On 2015/04/30 05:07:45, nednguyen wrote: > How stable is this thread_X_cpu_time_total metric? Note that we sometime have > situation that page waits on some js condition. Since the waiting logic is > polling, I suspect that this metric has high variance. In local testing, it's quite stable. Part of that may be that, with each page measurement (for key_power_cases) we simply wait N seconds. That is, we do all of the work before the actual measurement is run (load the page, turn off the screen, wait a couple seconds for stability, then actually start the measurement). However, measuring per second will probably scale a lot more nicely in the future (at least for this case... that won't be useful for the case rbyers@ mentioned with testing taps, but at least if we generalize the normalization category we'll be ready to do per-event timings or otherwise). I'll make the change and reupload. https://codereview.chromium.org/1084533005/diff/20001/tools/perf/metrics/time... tools/perf/metrics/timeline.py:139: return "tasks_" + thread_category On 2015/04/30 05:07:45, nednguyen wrote: > Same here, I think you should come up with a new ThreadTimeTotal metric that > computes something like tasks/seconds to avoid the timing issue. Will do. https://codereview.chromium.org/1084533005/diff/20001/tools/perf/metrics/time... tools/perf/metrics/timeline.py:255: def __init__(self, measure_per_frame=True): On 2015/04/30 05:07:45, nednguyen wrote: > Can you refactor this differently so we have two different classes instead of > one class with param like this? > > The idea here is later, we gonna port thread_times benchmark to use timeline > based measurement instead. And in TBM model, all the timeline_based_metric > should be directly constructible so we can do things like: > > for all subclass S of timeline based metrics: > S.AddResults(...) Sure, what about a PerFrameThreadTimesTimelineMetric/PerSecondThreadTimesTimelineMetric that essentially just expose the denominator to the base class?
On 2015/04/30 14:21:58, jdduke wrote: > On 2015/04/30 05:07:45, nednguyen wrote: > > Before even introducing new metrics, we should first start with experimenting > a > > metric that would catch crbug.com/462752. > > > > I want to see an experimental metric that clearly regresses if you revert the > > fix in 462752. > > Now I'm confused. The metric you speak of IS this metric. All of the > threadtimes/tasks counts here regress significantly in all of the "screen off" > key_power_cases you were reviewing (https://codereview.chromium.org/1097463004/) > without the fix we made to crbug.com/462752. Maybe I wasn't clear, but that > patch is indeed a regression test for crbug.com/462752. Great. I just want to make sure that you run the experiment locally and verify that this metrics do regress.
Patchset #3 (id:40001) has been deleted
I've made the adjustment to use per-second thread times. Mind taking another look? https://codereview.chromium.org/1084533005/diff/20001/tools/perf/metrics/time... File tools/perf/metrics/timeline.py (right): https://codereview.chromium.org/1084533005/diff/20001/tools/perf/metrics/time... tools/perf/metrics/timeline.py:130: def ThreadCpuTimeResultName(thread_category, measure_per_frame=True): On 2015/04/30 05:07:45, nednguyen wrote: > On 2015/04/29 18:07:17, jdduke wrote: > > I'm not married to the |measure_per_frame| name. > > I don't thing these helpers function add any value in making the code more > readable or shorter. We should get rid of these. Done.
Thanks for your patience, this is my first non-trivial telemetry change =/. Per offline discussion, I've changed the metric to report all interval types, filtering out the ones we don't want.
https://codereview.chromium.org/1084533005/diff/120001/tools/perf/metrics/tim... File tools/perf/metrics/timeline.py (right): https://codereview.chromium.org/1084533005/diff/120001/tools/perf/metrics/tim... tools/perf/metrics/timeline.py:293: num_seconds = all_threads.ComputeSliceTimeRange() / 1000.0 Don't you want to use num_seconds = sum all the time of the interaction records instead of the total time of all thread's slices? If I recall correctly, these metrics are supposed to be for interaction records on each thread, not for the whole threads.
On 2015/05/01 19:15:10, nednguyen wrote: > https://codereview.chromium.org/1084533005/diff/120001/tools/perf/metrics/tim... > File tools/perf/metrics/timeline.py (right): > > https://codereview.chromium.org/1084533005/diff/120001/tools/perf/metrics/tim... > tools/perf/metrics/timeline.py:293: num_seconds = > all_threads.ComputeSliceTimeRange() / 1000.0 > Don't you want to use num_seconds = sum all the time of the interaction records > instead of the total time of all thread's slices? > > If I recall correctly, these metrics are supposed to be for interaction records > on each thread, not for the whole threads. We don't want to sum anything. We want the duration of the interaction, independent of the number of slices or threads. Is there a better way to find that beside finding the first and last event and computing the interval?
On 2015/05/01 19:29:10, jdduke wrote: > On 2015/05/01 19:15:10, nednguyen wrote: > > > https://codereview.chromium.org/1084533005/diff/120001/tools/perf/metrics/tim... > > File tools/perf/metrics/timeline.py (right): > > > > > https://codereview.chromium.org/1084533005/diff/120001/tools/perf/metrics/tim... > > tools/perf/metrics/timeline.py:293: num_seconds = > > all_threads.ComputeSliceTimeRange() / 1000.0 > > Don't you want to use num_seconds = sum all the time of the interaction > records > > instead of the total time of all thread's slices? > > > > If I recall correctly, these metrics are supposed to be for interaction > records > > on each thread, not for the whole threads. > > We don't want to sum anything. We want the duration of the interaction, > independent of the number of slices or threads. > > Is there a better way to find that beside finding the first and last event and > computing the interval? interaction_record api has GetBounds and GetOverlappedThreatimeForSlice that you can use.
https://codereview.chromium.org/1084533005/diff/120001/tools/perf/metrics/tim... File tools/perf/metrics/timeline.py (right): https://codereview.chromium.org/1084533005/diff/120001/tools/perf/metrics/tim... tools/perf/metrics/timeline.py:293: num_seconds = all_threads.ComputeSliceTimeRange() / 1000.0 On 2015/05/01 19:15:10, nednguyen wrote: > Don't you want to use num_seconds = sum all the time of the interaction records > instead of the total time of all thread's slices? > > If I recall correctly, these metrics are supposed to be for interaction records > on each thread, not for the whole threads. I see now, so we can just reuse ResultsForThread.all_action_time?
Patchset #7 (id:100002) has been deleted
On 2015/05/01 21:08:47, jdduke wrote: > https://codereview.chromium.org/1084533005/diff/120001/tools/perf/metrics/tim... > File tools/perf/metrics/timeline.py (right): > > https://codereview.chromium.org/1084533005/diff/120001/tools/perf/metrics/tim... > tools/perf/metrics/timeline.py:293: num_seconds = > all_threads.ComputeSliceTimeRange() / 1000.0 > On 2015/05/01 19:15:10, nednguyen wrote: > > Don't you want to use num_seconds = sum all the time of the interaction > records > > instead of the total time of all thread's slices? > > > > If I recall correctly, these metrics are supposed to be for interaction > records > > on each thread, not for the whole threads. > > I see now, so we can just reuse ResultsForThread.all_action_time? That's what I went with, definitely works for our needs.
nednguyen@chromium.org changed reviewers: + nednguyen@chromium.org
For the case it turn outs to be ms/ms, we probably want to multiply by 100 and put % as units. https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... File tools/perf/metrics/timeline.py (right): https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... tools/perf/metrics/timeline.py:104: IntervalNames = ["frame", "second"] Instead of seconds, we probably want to use ms for consistency with existing metrics. https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... tools/perf/metrics/timeline.py:146: "" if interval_name == "frame" else "_per_" + interval_name) This is a bit hard to read, can you change this to: if internal_name == "frame": .. elif internal_name == "ms": .. https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... tools/perf/metrics/timeline.py:214: mean_frame_time = Rate(self.all_action_time, num_frames) This computation only applies for per_frames metric. https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... tools/perf/metrics/timeline.py:233: 'ms', self_time_result)) With the per second metrics, the unit 'ms' here isn't correct. Also for consistency, we probably want to use per ms, I think.
https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... File tools/perf/metrics/timeline.py (right): https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... tools/perf/metrics/timeline.py:104: IntervalNames = ["frame", "second"] On 2015/05/01 22:00:45, nednguyen(REVIEW IN OTHER ACC) wrote: > Instead of seconds, we probably want to use ms for consistency with existing > metrics. Done. https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... tools/perf/metrics/timeline.py:146: "" if interval_name == "frame" else "_per_" + interval_name) On 2015/05/01 22:00:45, nednguyen(REVIEW IN OTHER ACC) wrote: > This is a bit hard to read, can you change this to: > if internal_name == "frame": > .. > elif internal_name == "ms": > .. Done. https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... tools/perf/metrics/timeline.py:214: mean_frame_time = Rate(self.all_action_time, num_frames) On 2015/05/01 22:00:45, nednguyen(REVIEW IN OTHER ACC) wrote: > This computation only applies for per_frames metric. Right, I'll move it out. https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... tools/perf/metrics/timeline.py:233: 'ms', self_time_result)) On 2015/05/01 22:00:44, nednguyen(REVIEW IN OTHER ACC) wrote: > With the per second metrics, the unit 'ms' here isn't correct. > Also for consistency, we probably want to use per ms, I think. Seconds as an interval is nice because it's slightly easier to reason about, particularly for tasks, but yeah I can see it being confusing. As we're primarily interested in how this metric changes relatively, rather than the absolute number, it's probably best to be consistent as you say. I'm slightly wary of using a % as we could have >100% cpu time per system time for any multicore device, but if you think that's better I'm OK with it as well. Note that the smaller interval means that the baseline threadtime/task counts per MS will be very low, but again I guess it doesn't matter as it's relative.
On 2015/05/01 23:49:02, jdduke wrote: > https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... > File tools/perf/metrics/timeline.py (right): > > https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... > tools/perf/metrics/timeline.py:104: IntervalNames = ["frame", "second"] > On 2015/05/01 22:00:45, nednguyen(REVIEW IN OTHER ACC) wrote: > > Instead of seconds, we probably want to use ms for consistency with existing > > metrics. > > Done. > > https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... > tools/perf/metrics/timeline.py:146: "" if interval_name == "frame" else "_per_" > + interval_name) > On 2015/05/01 22:00:45, nednguyen(REVIEW IN OTHER ACC) wrote: > > This is a bit hard to read, can you change this to: > > if internal_name == "frame": > > .. > > elif internal_name == "ms": > > .. > > Done. > > https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... > tools/perf/metrics/timeline.py:214: mean_frame_time = Rate(self.all_action_time, > num_frames) > On 2015/05/01 22:00:45, nednguyen(REVIEW IN OTHER ACC) wrote: > > This computation only applies for per_frames metric. > > Right, I'll move it out. > > https://codereview.chromium.org/1084533005/diff/150001/tools/perf/metrics/tim... > tools/perf/metrics/timeline.py:233: 'ms', self_time_result)) > On 2015/05/01 22:00:44, nednguyen(REVIEW IN OTHER ACC) wrote: > > With the per second metrics, the unit 'ms' here isn't correct. > > Also for consistency, we probably want to use per ms, I think. > > Seconds as an interval is nice because it's slightly easier to reason about, > particularly for tasks, but yeah I can see it being confusing. As we're > primarily interested in how this metric changes relatively, rather than the > absolute number, it's probably best to be consistent as you say. > > I'm slightly wary of using a % as we could have >100% cpu time per system time > for any multicore device, but if you think that's better I'm OK with it as well. I'm ok with this, as long as we have documentation explaining what does > 100% mean. value objects has the description field (https://code.google.com/p/chromium/codesearch#chromium/src/tools/telemetry/te...), how about adding descriptions to the values here in a subsequent patch? > Note that the smaller interval means that the baseline threadtime/task counts > per MS will be very low, but again I guess it doesn't matter as it's relative. It may matter depending on the regression algorithm of the dashboard. But we can always expand the interval with telemetry's interaction records to make the range contain more meaningful data if needed.
https://codereview.chromium.org/1084533005/diff/190001/tools/perf/metrics/tim... File tools/perf/metrics/timeline.py (right): https://codereview.chromium.org/1084533005/diff/190001/tools/perf/metrics/tim... tools/perf/metrics/timeline.py:207: 'ms', cpu_per_interval)) Update unit here and other places? https://codereview.chromium.org/1084533005/diff/190001/tools/perf/metrics/tim... File tools/perf/metrics/timeline_unittest.py (right): https://codereview.chromium.org/1084533005/diff/190001/tools/perf/metrics/tim... tools/perf/metrics/timeline_unittest.py:159: (timeline.ThreadDetailResultName(main_thread, 'frame', 'idle'), 'ms', 0) What about the detail results for per ms cases? https://codereview.chromium.org/1084533005/diff/190001/tools/perf/metrics/tim... tools/perf/metrics/timeline_unittest.py:160: ] Also can you add assertion for mean_frame_times to make sure that its value stay the same after your patch.
> I'm ok with this, as long as we have documentation explaining what does > 100% mean. value objects has the description field (https://code.google.com/p/chromium/codesearch#chromium/src/tools/telemetry/te...), how about adding descriptions to the values here in a subsequent patch? Sounds good, I made the switch to % for the the "ms thread time per ms system time" metrics. https://codereview.chromium.org/1084533005/diff/190001/tools/perf/metrics/tim... File tools/perf/metrics/timeline_unittest.py (right): https://codereview.chromium.org/1084533005/diff/190001/tools/perf/metrics/tim... tools/perf/metrics/timeline_unittest.py:159: (timeline.ThreadDetailResultName(main_thread, 'frame', 'idle'), 'ms', 0) On 2015/05/04 00:39:46, nednguyen (ooo til 05-07) wrote: > What about the detail results for per ms cases? Done. https://codereview.chromium.org/1084533005/diff/190001/tools/perf/metrics/tim... tools/perf/metrics/timeline_unittest.py:160: ] On 2015/05/04 00:39:46, nednguyen (ooo til 05-07) wrote: > Also can you add assertion for mean_frame_times to make sure that its value stay > the same after your patch. Hmm, we already check timeline.ThreadMeanFrameTimeResultName(cc_thread). What other assertion did you have in mind?
Ned, anything else you'd like to see here? Wasn't sure if "%" or "percent" would be more appropriate.
This is great. Just want to make sure that these metrics also catch the regression you mentioned since we change from the total to per ms. https://codereview.chromium.org/1084533005/diff/210001/tools/perf/metrics/tim... File tools/perf/metrics/timeline_unittest.py (left): https://codereview.chromium.org/1084533005/diff/210001/tools/perf/metrics/tim... tools/perf/metrics/timeline_unittest.py:148: (timeline.ThreadTasksResultName(main_thread), 'tasks', 0.5), Why do these get removed?
Here are the results without/with the regression: https://drive.google.com/file/d/0ByhHNaAkRQvCSjR2bzBVM21Cekk/view?usp=sharing It definitely catches the regression, but both tasks/ms and threadtime % values are *really* small, and when showing only to the hundredths place we lose the actual value. I suppose we could track threadtime % per second (the magnitude would be the same as now), and tasks per second. The task counts would look a lot more sane, and it's not less consistent than the per ms value. Thoughts? https://codereview.chromium.org/1084533005/diff/210001/tools/perf/metrics/tim... File tools/perf/metrics/timeline_unittest.py (left): https://codereview.chromium.org/1084533005/diff/210001/tools/perf/metrics/tim... tools/perf/metrics/timeline_unittest.py:148: (timeline.ThreadTasksResultName(main_thread), 'tasks', 0.5), On 2015/05/08 21:13:19, nednguyen wrote: > Why do these get removed? Ah, they're still there but I moved them below the "MeanFrameTime" result (as that result only has one unit of measurement so I thought it slightly easier to read).
Patchset #11 (id:230001) has been deleted
Per offline discussion, I went ahead and changed the interval to seconds. The % stays the same, but the task metrics are a lot more readable.
https://codereview.chromium.org/1084533005/diff/250001/tools/perf/metrics/tim... File tools/perf/metrics/timeline_unittest.py (right): https://codereview.chromium.org/1084533005/diff/250001/tools/perf/metrics/tim... tools/perf/metrics/timeline_unittest.py:178: ] Nits: I would prefer the style of the left where the actual value are variables free. My reasoning here is: assertEqual(Add(1, 2), 3) is a better unittest than: assertEqual(Add(1, 2), 1 + 2)
On 2015/05/11 22:56:02, nednguyen (slow review) wrote: > https://codereview.chromium.org/1084533005/diff/250001/tools/perf/metrics/tim... > File tools/perf/metrics/timeline_unittest.py (right): > > https://codereview.chromium.org/1084533005/diff/250001/tools/perf/metrics/tim... > tools/perf/metrics/timeline_unittest.py:178: ] > Nits: I would prefer the style of the left where the actual value are variables > free. > My reasoning here is: > assertEqual(Add(1, 2), 3) > is a better unittest than: > assertEqual(Add(1, 2), 1 + 2) lgtm btw
Thanks for review! https://codereview.chromium.org/1084533005/diff/250001/tools/perf/metrics/tim... File tools/perf/metrics/timeline_unittest.py (right): https://codereview.chromium.org/1084533005/diff/250001/tools/perf/metrics/tim... tools/perf/metrics/timeline_unittest.py:178: ] On 2015/05/11 22:56:02, nednguyen (slow review) wrote: > Nits: I would prefer the style of the left where the actual value are variables > free. > My reasoning here is: > assertEqual(Add(1, 2), 3) > is a better unittest than: > assertEqual(Add(1, 2), 1 + 2) Done.
The CQ bit was checked by jdduke@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from nednguyen@google.com Link to the patchset: https://codereview.chromium.org/1084533005/#ps270001 (title: "Precomputed expectations")
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/patch-status/1084533005/270001
The CQ bit was unchecked by jdduke@chromium.org
The CQ bit was checked by jdduke@chromium.org
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/patch-status/1084533005/270001
Message was sent while issue was closed.
Committed patchset #12 (id:270001)
Message was sent while issue was closed.
Patchset 12 (id:??) landed as https://crrev.com/ce2699e20c3eae9dc17573fd2eb0885875341f44 Cr-Commit-Position: refs/heads/master@{#329322} |
|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
