commit 24e12dc59de6efcc72e52a22d1430d15e2c3f940
author Fyodor Kupolov <fkupolov@google.com> Tue Jan 17 12:20:36 2017 -0800
committer Fyodor Kupolov <fkupolov@google.com> Wed Jan 18 14:54:59 2017 -0800
tree dd7a7be413db195da6ea1fb407b9456e2073a4d6
parent 673de10bd0999a9b816eff51e7e6d33aa4784d3a

Log excessive boot times

This should help to identify devices that report unusually long
boot_completed timings.

Test: manual
Bug: 32807863
Change-Id: Ic6c7103d43b3e395accb38ec418094bc580c7c40

services/core/java/com/android/server/am/UserController.java

diff --git a/services/core/java/com/android/server/am/UserController.java b/services/core/java/com/android/server/am/UserController.java
index 71ebad9..f516e99 100644
--- a/services/core/java/com/android/server/am/UserController.java
+++ b/services/core/java/com/android/server/am/UserController.java
@@ -259,6 +259,11 @@
                     int uptimeSeconds = (int)(SystemClock.elapsedRealtime() / 1000);
                     MetricsLogger.histogram(mInjector.getContext(),
                             "framework_locked_boot_completed", uptimeSeconds);
+                    final int MAX_UPTIME_SECONDS = 120;
+                    if (uptimeSeconds > MAX_UPTIME_SECONDS) {
+                        Slog.wtf("SystemServerTiming",
+                                "finishUserBoot took too long. uptimeSeconds=" + uptimeSeconds);
+                    }
                 }
 
                 mHandler.sendMessage(mHandler.obtainMessage(REPORT_LOCKED_BOOT_COMPLETE_MSG,

services/java/com/android/server/SystemServer.java

diff --git a/services/java/com/android/server/SystemServer.java b/services/java/com/android/server/SystemServer.java
index 68cb0c5..5d2be6c 100644
--- a/services/java/com/android/server/SystemServer.java
+++ b/services/java/com/android/server/SystemServer.java
@@ -381,8 +381,13 @@
             Slog.i(TAG, "Enabled StrictMode for system server main thread.");
         }
         if (!mRuntimeRestart && !mFirstBoot) {
-            MetricsLogger.histogram(null, "boot_system_server_ready",
-                    (int) SystemClock.elapsedRealtime());
+            int uptimeMillis = (int) SystemClock.elapsedRealtime();
+            MetricsLogger.histogram(null, "boot_system_server_ready", uptimeMillis);
+            final int MAX_UPTIME_MILLIS = 60 * 1000;
+            if (uptimeMillis > MAX_UPTIME_MILLIS) {
+                Slog.wtf("SystemServerTiming",
+                        "SystemServer init took too long. uptimeMillis=" + uptimeMillis);
+            }
         }
 
         // Loop forever.