From 12cf0b6921bd4e464f4dbb4a698b078ac3e436fe Mon Sep 17 00:00:00 2001
From: Christopher Tate <ctate@google.com>
Date: Fri, 5 Jan 2018 18:40:14 -0800
Subject: [PATCH] Dump a few more bits of history about TIME_TICK

Bug: 70670726
Test: manual
Change-Id: I7d593da8ec236b505bbdba3ece0a638cc41388c2
---
 .../android/server/AlarmManagerService.java   | 25 +++++++++++++++++--
 1 file changed, 23 insertions(+), 2 deletions(-)

diff --git a/services/core/java/com/android/server/AlarmManagerService.java b/services/core/java/com/android/server/AlarmManagerService.java
index 472723dfa9093..a024d5a8e3ff0 100644
--- a/services/core/java/com/android/server/AlarmManagerService.java
+++ b/services/core/java/com/android/server/AlarmManagerService.java
@@ -149,6 +149,9 @@ class AlarmManagerService extends SystemService {
     private long mNextNonWakeup;
     private long mLastWakeupSet;
     private long mLastWakeup;
+    private long mLastTickSet;
+    private long mLastTickIssued; // elapsed
+    private long mLastTickReceived;
     int mBroadcastRefCount = 0;
     PowerManager.WakeLock mWakeLock;
     boolean mLastWakeLockUnimportantForLogging;
@@ -1596,6 +1599,7 @@ class AlarmManagerService extends SystemService {
             pw.println();
 
             mForceAppStandbyTracker.dump(pw, "  ");
+            pw.println();
 
             final long nowRTC = System.currentTimeMillis();
             final long nowELAPSED = SystemClock.elapsedRealtime();
@@ -1607,8 +1611,12 @@ class AlarmManagerService extends SystemService {
             pw.println();
             pw.print("  mLastTimeChangeClockTime="); pw.print(mLastTimeChangeClockTime);
             pw.print("="); pw.println(sdf.format(new Date(mLastTimeChangeClockTime)));
-            pw.print("  mLastTimeChangeRealtime=");
-            TimeUtils.formatDuration(mLastTimeChangeRealtime, pw);
+            pw.print("  mLastTimeChangeRealtime="); pw.println(mLastTimeChangeRealtime);
+            pw.print("  mLastTickIssued=");
+            TimeUtils.formatDuration(mLastTickIssued - nowELAPSED, pw);
+            pw.println();
+            pw.print("  mLastTickReceived="); pw.println(sdf.format(new Date(mLastTickReceived)));
+            pw.print("  mLastTickSet="); pw.println(sdf.format(new Date(mLastTickSet)));
             pw.println();
             if (!mInteractive) {
                 pw.print("  Time since non-interactive: ");
@@ -3284,6 +3292,9 @@ class AlarmManagerService extends SystemService {
                 if (DEBUG_BATCH) {
                     Slog.v(TAG, "Received TIME_TICK alarm; rescheduling");
                 }
+                synchronized (mLock) {
+                    mLastTickReceived = System.currentTimeMillis();
+                }
                 scheduleTimeTickEvent();
             } else if (intent.getAction().equals(Intent.ACTION_DATE_CHANGED)) {
                 // Since the kernel does not keep track of DST, we need to
@@ -3309,6 +3320,11 @@ class AlarmManagerService extends SystemService {
             setImpl(ELAPSED_REALTIME, SystemClock.elapsedRealtime() + tickEventDelay, 0,
                     0, mTimeTickSender, null, null, AlarmManager.FLAG_STANDALONE, workSource,
                     null, Process.myUid(), "android");
+
+            // Finally, remember when we set the tick alarm
+            synchronized (mLock) {
+                mLastTickSet = currentTime;
+            }
         }
 
         public void scheduleDateChangedEvent() {
@@ -3660,6 +3676,11 @@ class AlarmManagerService extends SystemService {
             if (alarm.operation != null) {
                 // PendingIntent alarm
                 mSendCount++;
+
+                if (alarm.priorityClass.priority == PRIO_TICK) {
+                    mLastTickIssued = nowELAPSED;
+                }
+
                 try {
                     alarm.operation.send(getContext(), 0,
                             mBackgroundIntent.putExtra(