Merge "Add local logs to NetworkTimeUpdateService" am: 6bda795c2b am: 7e16f6e837

Original change: https://android-review.googlesource.com/c/platform/frameworks/base/+/1998851

Change-Id: I2b8f1b52565e59e87ba383a6cbf6f35257c8e10b

2 files changed, 43 insertions, 4 deletions

diff --git a/core/java/android/util/NtpTrustedTime.java b/core/java/android/util/NtpTrustedTime.java
index 4ac3178ecb4c..8604078b5ae5 100644
--- a/core/java/android/util/NtpTrustedTime.java
+++ b/core/java/android/util/NtpTrustedTime.java
@@ -81,7 +81,16 @@ public class NtpTrustedTime implements TrustedTime {
 
         /** Calculates and returns the age of this result. */
         public long getAgeMillis() {
-            return SystemClock.elapsedRealtime() - mElapsedRealtimeMillis;
+            return getAgeMillis(SystemClock.elapsedRealtime());
+        }
+
+        /**
+         * Calculates and returns the age of this result relative to currentElapsedRealtimeMillis.
+         *
+         * @param currentElapsedRealtimeMillis - reference elapsed real time
+         */
+        public long getAgeMillis(long currentElapsedRealtimeMillis) {
+            return currentElapsedRealtimeMillis - mElapsedRealtimeMillis;
         }
 
         @Override
diff --git a/services/core/java/com/android/server/NetworkTimeUpdateService.java b/services/core/java/com/android/server/NetworkTimeUpdateService.java
index ff2308c35b9f..a0f239d43927 100644
--- a/services/core/java/com/android/server/NetworkTimeUpdateService.java
+++ b/services/core/java/com/android/server/NetworkTimeUpdateService.java
@@ -16,6 +16,7 @@
 
 package com.android.server;
 
+import android.annotation.NonNull;
 import android.app.AlarmManager;
 import android.app.PendingIntent;
 import android.app.timedetector.NetworkTimeSuggestion;
@@ -38,6 +39,7 @@ import android.os.PowerManager;
 import android.os.SystemClock;
 import android.os.TimestampedValue;
 import android.provider.Settings;
+import android.util.LocalLog;
 import android.util.Log;
 import android.util.NtpTrustedTime;
 import android.util.TimeUtils;
@@ -95,6 +97,13 @@ public class NetworkTimeUpdateService extends Binder {
     // connection to happen.
     private int mTryAgainCounter;
 
+    /**
+     * A log that records the decisions to fetch a network time update.
+     * This is logged in bug reports to assist with debugging issues with network time suggestions.
+     */
+    @NonNull
+    private final LocalLog mLocalLog = new LocalLog(30, false /* useLocalTimestamps */);
+
     public NetworkTimeUpdateService(Context context) {
         mContext = context;
         mTime = NtpTrustedTime.getInstance(context);
@@ -155,15 +164,29 @@ public class NetworkTimeUpdateService extends Binder {
     }
 
     private void onPollNetworkTimeUnderWakeLock(int event) {
+        long currentElapsedRealtimeMillis = SystemClock.elapsedRealtime();
         // Force an NTP fix when outdated
         NtpTrustedTime.TimeResult cachedNtpResult = mTime.getCachedTimeResult();
-        if (cachedNtpResult == null || cachedNtpResult.getAgeMillis() >= mPollingIntervalMs) {
+        if (cachedNtpResult == null || cachedNtpResult.getAgeMillis(currentElapsedRealtimeMillis)
+                >= mPollingIntervalMs) {
             if (DBG) Log.d(TAG, "Stale NTP fix; forcing refresh");
-            mTime.forceRefresh();
+            boolean isSuccessful = mTime.forceRefresh();
+            if (!isSuccessful) {
+                String logMsg = "forceRefresh() returned false: cachedNtpResult=" + cachedNtpResult
+                        + ", currentElapsedRealtimeMillis=" + currentElapsedRealtimeMillis;
+
+                if (DBG) {
+                    Log.d(TAG, logMsg);
+                }
+                mLocalLog.log(logMsg);
+            }
+
             cachedNtpResult = mTime.getCachedTimeResult();
         }
 
-        if (cachedNtpResult != null && cachedNtpResult.getAgeMillis() < mPollingIntervalMs) {
+        if (cachedNtpResult != null
+                && cachedNtpResult.getAgeMillis(currentElapsedRealtimeMillis)
+                < mPollingIntervalMs) {
             // Obtained fresh fix; schedule next normal update
             resetAlarm(mPollingIntervalMs);
 
@@ -180,6 +203,11 @@ public class NetworkTimeUpdateService extends Binder {
                 resetAlarm(mPollingIntervalShorterMs);
             } else {
                 // Try much later
+                String logMsg = "mTryAgainTimesMax exceeded, cachedNtpResult=" + cachedNtpResult;
+                if (DBG) {
+                    Log.d(TAG, logMsg);
+                }
+                mLocalLog.log(logMsg);
                 mTryAgainCounter = 0;
                 resetAlarm(mPollingIntervalMs);
             }
@@ -285,6 +313,8 @@ public class NetworkTimeUpdateService extends Binder {
         if (ntpResult != null) {
             pw.println("NTP result age: " + ntpResult.getAgeMillis());
         }
+        pw.println("Local logs:");
+        mLocalLog.dump(fd, pw, args);
         pw.println();
     }
 }