MainEntryPointTime should be based on base::TimeTicks::Now() |
||
Issue descriptionThe histogram "Startup.BrowserMessageLoopStartTimeFromMainEntry2" and similar ones where the counting starts from the "main() entry point" currently goes through conversion from wallclock to ticks (via StartupTimeToTimeTicks()). This conversion is done early and only once to minimize the difference between the skew of both clocks. In order to make the metric more precise, thread priority is manipulated, which is avoided on OS_MACOSX because of negative side effects on this platform. The distribution looks 'kinda regular' on Windows/MacOS. On Linux we do not have enough data. On Android the distribution has a very long tail which makes this family of histograms non-actionable for preventing regressions on this platform. In the lab we also see his metric to be about 2x more noisy than the same-clock counterparts (experimental.startup.android.coldish/messageloop_start_time_avg vs. start_with_url.cold.startup_pages/messageloop_start_time). I see these possible explanations: 1. The System.currentTimeMillis() is skewed from the base::Time::Now() that we use on the native side as a base for correction 2. Thread priority manipulation introduces random delays on Android 3. Launching Chrome correlates with heavy wallclock skew, possibly going online causes NTP sync .. As a workaround we could fix (1) by calling into Java for currentTimeMillis(), which would be a small patch. However, I would like to eliminate other potential issues with something that would read simpler: * register main entry point time in timeticks and remove the wallclock-to-ticks conversion * start by creating "Startup.BrowserMessageLoopStartTimeFromMainEntry3", compare the noise with the previous one * if the new histogram is more actionable and consistent on all platforms, add the rest to the camp and remove the old ones once the code reaches Stable (provided that consistency remains) I think recording the main entry point in wallclock is there for historical reasons. In the old times it might have had some metrics that mix both the main entry point and process start, the latter being wallclock-based might have asked for the former one to be wallclock-based as well. I have not confirmed the theory, too much `git log|blame` for my taste. We still have a few metrics that start counting from process creation, not useful on Android, not proposing to change how they work.
,
Dec 27 2017
Correction: System.uptimeMillis() does not exist, please read as SystemClock.uptimeMillis().
,
Dec 27 2017
Proposed first step: https://chromium-review.googlesource.com/c/chromium/src/+/844775
,
Jan 8 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/5e0c3a9b941801c86bc35fda0fce9e8719028bb2 commit 5e0c3a9b941801c86bc35fda0fce9e8719028bb2 Author: Egor Pasko <pasko@chromium.org> Date: Mon Jan 08 17:43:47 2018 Add Startup.BrowserMessageLoopStartTimeFromMainEntry3 Keep the old Startup.BrowserMessageLoopStartTimeFromMainEntry2 for comparison on benchmarks and in the field. The new histogram records the same value, but is based solely on TimeTicks::Now() instead of going through wallclock-to-ticks conversion. This change adds a use of base::TimeTicks::FromInternalValue(), which is discouraged and causes a presubmit warning. Explained the legitimacy of it in a comment and pinged http://crbug.com/634507 to ask for alternatives. Bug: 797762 Change-Id: I364f5c8011f3883fc95bebff667dcffae4e56294 Reviewed-on: https://chromium-review.googlesource.com/844775 Commit-Queue: Egor Pasko <pasko@chromium.org> Reviewed-by: Yuri Wiitala <miu@chromium.org> Reviewed-by: Ken Rockot <rockot@chromium.org> Reviewed-by: Maria Khomenko <mariakhomenko@chromium.org> Reviewed-by: Yaron Friedman <yfriedman@chromium.org> Reviewed-by: Ilya Sherman <isherman@chromium.org> Reviewed-by: Ted Choc (back but slow, ping me) <tedchoc@chromium.org> Reviewed-by: François Doray <fdoray@chromium.org> Cr-Commit-Position: refs/heads/master@{#527665} [modify] https://crrev.com/5e0c3a9b941801c86bc35fda0fce9e8719028bb2/chrome/android/java/src/org/chromium/chrome/browser/DeferredStartupHandler.java [modify] https://crrev.com/5e0c3a9b941801c86bc35fda0fce9e8719028bb2/chrome/android/java/src/org/chromium/chrome/browser/firstrun/FirstRunActivityBase.java [modify] https://crrev.com/5e0c3a9b941801c86bc35fda0fce9e8719028bb2/chrome/android/java/src/org/chromium/chrome/browser/metrics/UmaUtils.java [modify] https://crrev.com/5e0c3a9b941801c86bc35fda0fce9e8719028bb2/chrome/app/android/chrome_main_delegate_android.cc [modify] https://crrev.com/5e0c3a9b941801c86bc35fda0fce9e8719028bb2/chrome/app/chrome_main_delegate.cc [modify] https://crrev.com/5e0c3a9b941801c86bc35fda0fce9e8719028bb2/chrome/browser/android/metrics/uma_utils.cc [modify] https://crrev.com/5e0c3a9b941801c86bc35fda0fce9e8719028bb2/chrome/browser/android/metrics/uma_utils.h [modify] https://crrev.com/5e0c3a9b941801c86bc35fda0fce9e8719028bb2/chrome/browser/metrics/startup_metrics_browsertest.cc [modify] https://crrev.com/5e0c3a9b941801c86bc35fda0fce9e8719028bb2/components/startup_metric_utils/browser/startup_metric_utils.cc [modify] https://crrev.com/5e0c3a9b941801c86bc35fda0fce9e8719028bb2/components/startup_metric_utils/browser/startup_metric_utils.h [modify] https://crrev.com/5e0c3a9b941801c86bc35fda0fce9e8719028bb2/tools/metrics/histograms/histograms.xml
,
Jan 10 2018
The following revision refers to this bug: https://chromium.googlesource.com/catapult/+/dd8254fcbbd6b46efc780916c0ff5eda4be4b816 commit dd8254fcbbd6b46efc780916c0ff5eda4be4b816 Author: Egor Pasko <pasko@chromium.org> Date: Wed Jan 10 13:59:26 2018 Update the messageloop_start_time metric Also keep the old version for now, with a TODO to remove it. The new metric is based on a new trace event introduced in http://crrev.com/527665, it features two trace events with a slightly different time interval registered. Bug: chromium:797762 Change-Id: I9479269bd40f5739feb752359bbd942634c50095 Reviewed-on: https://chromium-review.googlesource.com/846802 Commit-Queue: Egor Pasko <pasko@chromium.org> Reviewed-by: Ned Nguyen <nednguyen@google.com> [modify] https://crrev.com/dd8254fcbbd6b46efc780916c0ff5eda4be4b816/tracing/tracing/metrics/android_startup_metric_test.html [modify] https://crrev.com/dd8254fcbbd6b46efc780916c0ff5eda4be4b816/tracing/tracing/metrics/android_startup_metric.html
,
Jan 10 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/39dca145e6fcea2f30ff9cc95f4c8ec58daf3de1 commit 39dca145e6fcea2f30ff9cc95f4c8ec58daf3de1 Author: Egor Pasko <pasko@chromium.org> Date: Wed Jan 10 16:11:00 2018 startup_metric_utils: use constexpr c-tor for TimeTicks globals This is a followup to a previous change where one such constexpr constructor was introduced. Now make the remaining globals constexpr-constructed with mostly a mechanical change. Bug: 797762 Change-Id: I08572182f5827ab06046255fbcbab7dfb9bd81ef Reviewed-on: https://chromium-review.googlesource.com/859783 Commit-Queue: Egor Pasko <pasko@chromium.org> Reviewed-by: Gabriel Charette <gab@chromium.org> Cr-Commit-Position: refs/heads/master@{#528330} [modify] https://crrev.com/39dca145e6fcea2f30ff9cc95f4c8ec58daf3de1/components/startup_metric_utils/browser/startup_metric_utils.cc
,
Jan 18 2018
The following revision refers to this bug: https://chromium.googlesource.com/catapult/+/b4706e73204bf551ca2f85fce8cbe23ef7d0df31 commit b4706e73204bf551ca2f85fce8cbe23ef7d0df31 Author: Egor Pasko <pasko@chromium.org> Date: Thu Jan 18 15:36:36 2018 androidStartupMetric: Remove old wallclock-based metric On the bot the metrics are usually within a couple ms from each other. This cleanup removes the old telemetry-side metric. Nothing should change for androidStartupMetric/messageloop_start_time. Bug: chromium:797762 Change-Id: If7a278fa9216ac131fcffdd3afa0b0f36081ff69 Reviewed-on: https://chromium-review.googlesource.com/864802 Reviewed-by: Ned Nguyen <nednguyen@google.com> Commit-Queue: Egor Pasko <pasko@chromium.org> [modify] https://crrev.com/b4706e73204bf551ca2f85fce8cbe23ef7d0df31/tracing/tracing/metrics/android_startup_metric_test.html [modify] https://crrev.com/b4706e73204bf551ca2f85fce8cbe23ef7d0df31/tracing/tracing/metrics/android_startup_metric.html
,
Jan 23 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/57c01825f409616c3112d03679dde0f11f2cb45b commit 57c01825f409616c3112d03679dde0f11f2cb45b Author: Egor Pasko <pasko@chromium.org> Date: Tue Jan 23 11:59:16 2018 Add base::TimeTicks::FromUptimeMillis() This allows creating a base::TimeTicks from SystemClock.uptimeMillis(). Android-only. Also add a use this new method once instead of FromInternalValue(), which is discouraged. Bug: 634507, 797762 Change-Id: I8b5e3f4d0da1919f21c1f96918ca36a4e434ae0d Reviewed-on: https://chromium-review.googlesource.com/865314 Commit-Queue: Egor Pasko <pasko@chromium.org> Reviewed-by: Maria Khomenko <mariakhomenko@chromium.org> Reviewed-by: Yaron Friedman <yfriedman@chromium.org> Reviewed-by: Yuri Wiitala <miu@chromium.org> Cr-Commit-Position: refs/heads/master@{#531208} [modify] https://crrev.com/57c01825f409616c3112d03679dde0f11f2cb45b/base/BUILD.gn [modify] https://crrev.com/57c01825f409616c3112d03679dde0f11f2cb45b/base/time/time.h [add] https://crrev.com/57c01825f409616c3112d03679dde0f11f2cb45b/base/time/time_android.cc [modify] https://crrev.com/57c01825f409616c3112d03679dde0f11f2cb45b/base/time/time_unittest.cc [modify] https://crrev.com/57c01825f409616c3112d03679dde0f11f2cb45b/chrome/browser/android/metrics/uma_utils.cc
,
Jun 18 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/f86681ce5f9530a0180d2d52bed591861351b8c0 commit f86681ce5f9530a0180d2d52bed591861351b8c0 Author: Egor Pasko <pasko@chromium.org> Date: Mon Jun 18 22:06:12 2018 startup_metric_utils: remove main entry computed ticks For a little while we have been recording startup metrics based on main entry point time using two techniques: * (old way) by converting process creation wall time using StartupTimeToTimeTicks() * (new way) by calling base::TimeTicks::Now() The new way is theoretically cleaner and removes a few possible skews (see details in the bug). During a few months of overlap we have been computing these two histograms for the identical time interval: * (old way) Startup.BrowserMessageLoopStartTimeFromMainEntry2 * (new way) Startup.BrowserMessageLoopStartTimeFromMainEntry3 On Windows the skew between the two is super tiny (2-3 UMA samples with difference during the day). On Android the difference is between 0.5% and 0.7% for the same day for various quantiles. The overflow bucket (1 hour and more) for the new histogram is 3.5x smaller - nice. Also the new histogram looks a tiny bit smoother on Android. Overall the shape of the distribution does not change our subjective perception of the startup metrics on Android. Based on these observations this change proposes to: * Switch the remaining calculations based on the main entry point to the new way - calling base::TimeTicks::Now() (no conversion to ticks, not using the wallclock) * Avoid renaming the histograms because the expected difference is likely not worth worrying * Celebrate cleanup :) Bug: 797762 Change-Id: I5c32541280c359d6571cbcc5c6e7500b79002011 Reviewed-on: https://chromium-review.googlesource.com/1104696 Reviewed-by: François Doray <fdoray@chromium.org> Commit-Queue: Egor Pasko <pasko@chromium.org> Cr-Commit-Position: refs/heads/master@{#568189} [modify] https://crrev.com/f86681ce5f9530a0180d2d52bed591861351b8c0/components/startup_metric_utils/browser/startup_metric_utils.cc
,
Jun 19 2018
,
Aug 17
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/46b0d6a919ebd3cb078969265a8831906bdd0ade commit 46b0d6a919ebd3cb078969265a8831906bdd0ade Author: Egor Pasko <pasko@chromium.org> Date: Fri Aug 17 10:35:24 2018 startup_metric_utils: Remove wallclock leftovers Trivial cleanup: removing parameters/functions that are not used in producing startup metrics (The RecordMainEntryPointTime() used to take wall clock time into account, but now on all platforms wallclock time is not needed except for executable start time). Bug: 797762 Change-Id: I1242246ad6af2b4b3e955b0225144154084e568f Reviewed-on: https://chromium-review.googlesource.com/1174548 Reviewed-by: Yaron Friedman <yfriedman@chromium.org> Reviewed-by: François Doray <fdoray@chromium.org> Reviewed-by: Jay Civelli <jcivelli@chromium.org> Commit-Queue: Egor Pasko <pasko@chromium.org> Cr-Commit-Position: refs/heads/master@{#584015} [modify] https://crrev.com/46b0d6a919ebd3cb078969265a8831906bdd0ade/chrome/android/java/src/org/chromium/chrome/browser/metrics/UmaUtils.java [modify] https://crrev.com/46b0d6a919ebd3cb078969265a8831906bdd0ade/chrome/app/android/chrome_main_delegate_android.cc [modify] https://crrev.com/46b0d6a919ebd3cb078969265a8831906bdd0ade/chrome/app/chrome_main_delegate.cc [modify] https://crrev.com/46b0d6a919ebd3cb078969265a8831906bdd0ade/chrome/browser/android/metrics/uma_utils.cc [modify] https://crrev.com/46b0d6a919ebd3cb078969265a8831906bdd0ade/chrome/browser/android/metrics/uma_utils.h [modify] https://crrev.com/46b0d6a919ebd3cb078969265a8831906bdd0ade/components/startup_metric_utils/browser/startup_metric_utils.cc [modify] https://crrev.com/46b0d6a919ebd3cb078969265a8831906bdd0ade/components/startup_metric_utils/browser/startup_metric_utils.h |
||
►
Sign in to add a comment |
||
Comment 1 by pasko@chromium.org
, Dec 27 2017