Merge "UsageStats should deal with changing time" into lmp-dev

3 files changed, 175 insertions, 83 deletions

diff --git a/services/usage/java/com/android/server/usage/UsageStatsDatabase.java b/services/usage/java/com/android/server/usage/UsageStatsDatabase.java
index 62a7ec0..972c929 100644
--- a/services/usage/java/com/android/server/usage/UsageStatsDatabase.java
+++ b/services/usage/java/com/android/server/usage/UsageStatsDatabase.java
@@ -61,7 +61,7 @@ class UsageStatsDatabase {
     /**
      * Initialize any directories required and index what stats are available.
      */
-    void init() {
+    public void init(long currentTimeMillis) {
         synchronized (mLock) {
             for (File f : mIntervalDirs) {
                 f.mkdirs();
@@ -72,27 +72,53 @@ class UsageStatsDatabase {
             }
 
             checkVersionLocked();
+            indexFilesLocked();
 
-            final FilenameFilter backupFileFilter = new FilenameFilter() {
-                @Override
-                public boolean accept(File dir, String name) {
-                    return !name.endsWith(".bak");
+            // Delete files that are in the future.
+            for (TimeSparseArray<AtomicFile> files : mSortedStatFiles) {
+                final int startIndex = files.closestIndexOnOrAfter(currentTimeMillis);
+                if (startIndex < 0) {
+                    continue;
                 }
-            };
 
-            // Index the available usage stat files on disk.
-            for (int i = 0; i < mSortedStatFiles.length; i++) {
+                final int fileCount = files.size();
+                for (int i = startIndex; i < fileCount; i++) {
+                    files.valueAt(i).delete();
+                }
+
+                // Remove in a separate loop because any accesses (valueAt)
+                // will cause a gc in the SparseArray and mess up the order.
+                for (int i = startIndex; i < fileCount; i++) {
+                    files.removeAt(i);
+                }
+            }
+        }
+    }
+
+    private void indexFilesLocked() {
+        final FilenameFilter backupFileFilter = new FilenameFilter() {
+            @Override
+            public boolean accept(File dir, String name) {
+                return !name.endsWith(".bak");
+            }
+        };
+
+        // Index the available usage stat files on disk.
+        for (int i = 0; i < mSortedStatFiles.length; i++) {
+            if (mSortedStatFiles[i] == null) {
                 mSortedStatFiles[i] = new TimeSparseArray<>();
-                File[] files = mIntervalDirs[i].listFiles(backupFileFilter);
-                if (files != null) {
-                    if (DEBUG) {
-                        Slog.d(TAG, "Found " + files.length + " stat files for interval " + i);
-                    }
+            } else {
+                mSortedStatFiles[i].clear();
+            }
+            File[] files = mIntervalDirs[i].listFiles(backupFileFilter);
+            if (files != null) {
+                if (DEBUG) {
+                    Slog.d(TAG, "Found " + files.length + " stat files for interval " + i);
+                }
 
-                    for (File f : files) {
-                        final AtomicFile af = new AtomicFile(f);
-                        mSortedStatFiles[i].put(UsageStatsXml.parseBeginTime(af), af);
-                    }
+                for (File f : files) {
+                    final AtomicFile af = new AtomicFile(f);
+                    mSortedStatFiles[i].put(UsageStatsXml.parseBeginTime(af), af);
                 }
             }
         }
@@ -135,6 +161,38 @@ class UsageStatsDatabase {
         }
     }
 
+    public void onTimeChanged(long timeDiffMillis) {
+        synchronized (mLock) {
+            for (TimeSparseArray<AtomicFile> files : mSortedStatFiles) {
+                final int fileCount = files.size();
+                for (int i = 0; i < fileCount; i++) {
+                    final AtomicFile file = files.valueAt(i);
+                    final long newTime = files.keyAt(i) + timeDiffMillis;
+                    if (newTime < 0) {
+                        Slog.i(TAG, "Deleting file " + file.getBaseFile().getAbsolutePath()
+                                + " for it is in the future now.");
+                        file.delete();
+                    } else {
+                        try {
+                            file.openRead().close();
+                        } catch (IOException e) {
+                            // Ignore, this is just to make sure there are no backups.
+                        }
+                        final File newFile = new File(file.getBaseFile().getParentFile(),
+                                Long.toString(newTime));
+                        Slog.i(TAG, "Moving file " + file.getBaseFile().getAbsolutePath() + " to "
+                                + newFile.getAbsolutePath());
+                        file.getBaseFile().renameTo(newFile);
+                    }
+                }
+                files.clear();
+            }
+
+            // Now re-index the new files.
+            indexFilesLocked();
+        }
+    }
+
     /**
      * Get the latest stats that exist for this interval type.
      */
@@ -296,25 +354,24 @@ class UsageStatsDatabase {
     /**
      * Remove any usage stat files that are too old.
      */
-    public void prune() {
+    public void prune(final long currentTimeMillis) {
         synchronized (mLock) {
-            long timeNow = System.currentTimeMillis();
-            mCal.setTimeInMillis(timeNow);
+            mCal.setTimeInMillis(currentTimeMillis);
             mCal.addYears(-3);
             pruneFilesOlderThan(mIntervalDirs[UsageStatsManager.INTERVAL_YEARLY],
                     mCal.getTimeInMillis());
 
-            mCal.setTimeInMillis(timeNow);
+            mCal.setTimeInMillis(currentTimeMillis);
             mCal.addMonths(-6);
             pruneFilesOlderThan(mIntervalDirs[UsageStatsManager.INTERVAL_MONTHLY],
                     mCal.getTimeInMillis());
 
-            mCal.setTimeInMillis(timeNow);
+            mCal.setTimeInMillis(currentTimeMillis);
             mCal.addWeeks(-4);
             pruneFilesOlderThan(mIntervalDirs[UsageStatsManager.INTERVAL_WEEKLY],
                     mCal.getTimeInMillis());
 
-            mCal.setTimeInMillis(timeNow);
+            mCal.setTimeInMillis(currentTimeMillis);
             mCal.addDays(-7);
             pruneFilesOlderThan(mIntervalDirs[UsageStatsManager.INTERVAL_DAILY],
                     mCal.getTimeInMillis());
diff --git a/services/usage/java/com/android/server/usage/UsageStatsService.java b/services/usage/java/com/android/server/usage/UsageStatsService.java
index 92117c3..2ed9745 100644
--- a/services/usage/java/com/android/server/usage/UsageStatsService.java
+++ b/services/usage/java/com/android/server/usage/UsageStatsService.java
@@ -65,6 +65,7 @@ public class UsageStatsService extends SystemService implements
     private static final long TEN_SECONDS = 10 * 1000;
     private static final long TWENTY_MINUTES = 20 * 60 * 1000;
     private static final long FLUSH_INTERVAL = DEBUG ? TEN_SECONDS : TWENTY_MINUTES;
+    private static final long TIME_CHANGE_THRESHOLD_MILLIS = 2 * 1000; // Two seconds.
 
     // Handler message types.
     static final int MSG_REPORT_EVENT = 0;
@@ -171,18 +172,47 @@ public class UsageStatsService extends SystemService implements
         }
     }
 
-    private UserUsageStatsService getUserDataAndInitializeIfNeededLocked(int userId) {
+    private UserUsageStatsService getUserDataAndInitializeIfNeededLocked(int userId,
+            long currentTimeMillis) {
         UserUsageStatsService service = mUserState.get(userId);
         if (service == null) {
             service = new UserUsageStatsService(userId,
                     new File(mUsageStatsDir, Integer.toString(userId)), this);
-            service.init();
+            service.init(currentTimeMillis);
             mUserState.put(userId, service);
         }
         return service;
     }
 
     /**
+     * This should be the only way to get the time from the system.
+     */
+    private long checkAndGetTimeLocked() {
+        final long actualSystemTime = System.currentTimeMillis();
+        final long actualRealtime = SystemClock.elapsedRealtime();
+        final long expectedSystemTime = (actualRealtime - mRealTimeSnapshot) + mSystemTimeSnapshot;
+        if (Math.abs(actualSystemTime - expectedSystemTime) > TIME_CHANGE_THRESHOLD_MILLIS) {
+            // The time has changed.
+            final int userCount = mUserState.size();
+            for (int i = 0; i < userCount; i++) {
+                final UserUsageStatsService service = mUserState.valueAt(i);
+                service.onTimeChanged(expectedSystemTime, actualSystemTime);
+            }
+            mRealTimeSnapshot = actualRealtime;
+            mSystemTimeSnapshot = actualSystemTime;
+        }
+        return actualSystemTime;
+    }
+
+    /**
+     * Assuming the event's timestamp is measured in milliseconds since boot,
+     * convert it to a system wall time.
+     */
+    private void convertToSystemTimeLocked(UsageEvents.Event event) {
+        event.mTimeStamp = Math.max(0, event.mTimeStamp - mRealTimeSnapshot) + mSystemTimeSnapshot;
+    }
+
+    /**
      * Called by the Binder stub
      */
     void shutdown() {
@@ -197,7 +227,11 @@ public class UsageStatsService extends SystemService implements
      */
     void reportEvent(UsageEvents.Event event, int userId) {
         synchronized (mLock) {
-            final UserUsageStatsService service = getUserDataAndInitializeIfNeededLocked(userId);
+            final long timeNow = checkAndGetTimeLocked();
+            convertToSystemTimeLocked(event);
+
+            final UserUsageStatsService service =
+                    getUserDataAndInitializeIfNeededLocked(userId, timeNow);
             service.reportEvent(event);
         }
     }
@@ -226,12 +260,14 @@ public class UsageStatsService extends SystemService implements
      * Called by the Binder stub.
      */
     List<UsageStats> queryUsageStats(int userId, int bucketType, long beginTime, long endTime) {
-        if (!validRange(beginTime, endTime)) {
-            return null;
-        }
-
         synchronized (mLock) {
-            UserUsageStatsService service = getUserDataAndInitializeIfNeededLocked(userId);
+            final long timeNow = checkAndGetTimeLocked();
+            if (!validRange(timeNow, beginTime, endTime)) {
+                return null;
+            }
+
+            final UserUsageStatsService service =
+                    getUserDataAndInitializeIfNeededLocked(userId, timeNow);
             return service.queryUsageStats(bucketType, beginTime, endTime);
         }
     }
@@ -241,12 +277,14 @@ public class UsageStatsService extends SystemService implements
      */
     List<ConfigurationStats> queryConfigurationStats(int userId, int bucketType, long beginTime,
             long endTime) {
-        if (!validRange(beginTime, endTime)) {
-            return null;
-        }
-
         synchronized (mLock) {
-            UserUsageStatsService service = getUserDataAndInitializeIfNeededLocked(userId);
+            final long timeNow = checkAndGetTimeLocked();
+            if (!validRange(timeNow, beginTime, endTime)) {
+                return null;
+            }
+
+            final UserUsageStatsService service =
+                    getUserDataAndInitializeIfNeededLocked(userId, timeNow);
             return service.queryConfigurationStats(bucketType, beginTime, endTime);
         }
     }
@@ -255,19 +293,20 @@ public class UsageStatsService extends SystemService implements
      * Called by the Binder stub.
      */
     UsageEvents queryEvents(int userId, long beginTime, long endTime) {
-        if (!validRange(beginTime, endTime)) {
-            return null;
-        }
-
         synchronized (mLock) {
-            UserUsageStatsService service = getUserDataAndInitializeIfNeededLocked(userId);
+            final long timeNow = checkAndGetTimeLocked();
+            if (!validRange(timeNow, beginTime, endTime)) {
+                return null;
+            }
+
+            final UserUsageStatsService service =
+                    getUserDataAndInitializeIfNeededLocked(userId, timeNow);
             return service.queryEvents(beginTime, endTime);
         }
     }
 
-    private static boolean validRange(long beginTime, long endTime) {
-        final long timeNow = System.currentTimeMillis();
-        return beginTime <= timeNow && beginTime < endTime;
+    private static boolean validRange(long currentTime, long beginTime, long endTime) {
+        return beginTime <= currentTime && beginTime < endTime;
     }
 
     private void flushToDiskLocked() {
@@ -387,14 +426,6 @@ public class UsageStatsService extends SystemService implements
      */
     private class LocalService extends UsageStatsManagerInternal {
 
-        /**
-         * The system may have its time change, so at least make sure the events
-         * are monotonic in order.
-         */
-        private long computeMonotonicSystemTime(long realTime) {
-            return (realTime - mRealTimeSnapshot) + mSystemTimeSnapshot;
-        }
-
         @Override
         public void reportEvent(ComponentName component, int userId, int eventType) {
             if (component == null) {
@@ -405,7 +436,10 @@ public class UsageStatsService extends SystemService implements
             UsageEvents.Event event = new UsageEvents.Event();
             event.mPackage = component.getPackageName();
             event.mClass = component.getClassName();
-            event.mTimeStamp = computeMonotonicSystemTime(SystemClock.elapsedRealtime());
+
+            // This will later be converted to system time.
+            event.mTimeStamp = SystemClock.elapsedRealtime();
+
             event.mEventType = eventType;
             mHandler.obtainMessage(MSG_REPORT_EVENT, userId, 0, event).sendToTarget();
         }
@@ -419,7 +453,10 @@ public class UsageStatsService extends SystemService implements
 
             UsageEvents.Event event = new UsageEvents.Event();
             event.mPackage = "android";
-            event.mTimeStamp = computeMonotonicSystemTime(SystemClock.elapsedRealtime());
+
+            // This will later be converted to system time.
+            event.mTimeStamp = SystemClock.elapsedRealtime();
+
             event.mEventType = UsageEvents.Event.CONFIGURATION_CHANGE;
             event.mConfiguration = new Configuration(config);
             mHandler.obtainMessage(MSG_REPORT_EVENT, userId, 0, event).sendToTarget();
diff --git a/services/usage/java/com/android/server/usage/UserUsageStatsService.java b/services/usage/java/com/android/server/usage/UserUsageStatsService.java
index 2769666..4916ec2 100644
--- a/services/usage/java/com/android/server/usage/UserUsageStatsService.java
+++ b/services/usage/java/com/android/server/usage/UserUsageStatsService.java
@@ -22,6 +22,7 @@ import android.app.usage.UsageEvents;
 import android.app.usage.UsageStats;
 import android.app.usage.UsageStatsManager;
 import android.content.res.Configuration;
+import android.os.SystemClock;
 import android.util.ArraySet;
 import android.util.Slog;
 
@@ -62,10 +63,9 @@ class UserUsageStatsService {
         mLogPrefix = "User[" + Integer.toString(userId) + "] ";
     }
 
-    void init() {
-        mDatabase.init();
+    void init(final long currentTimeMillis) {
+        mDatabase.init(currentTimeMillis);
 
-        final long timeNow = System.currentTimeMillis();
         int nullCount = 0;
         for (int i = 0; i < mCurrentStats.length; i++) {
             mCurrentStats[i] = mDatabase.getLatestUsageStats(i);
@@ -73,11 +73,6 @@ class UserUsageStatsService {
                 // Find out how many intervals we don't have data for.
                 // Ideally it should be all or none.
                 nullCount++;
-            } else if (mCurrentStats[i].beginTime > timeNow) {
-                Slog.e(TAG, mLogPrefix + "Interval " + i + " has stat in the future " +
-                        mCurrentStats[i].beginTime);
-                mCurrentStats[i] = null;
-                nullCount++;
             }
         }
 
@@ -92,7 +87,7 @@ class UserUsageStatsService {
 
             // By calling loadActiveStats, we will
             // generate new stats for each bucket.
-            loadActiveStats();
+            loadActiveStats(currentTimeMillis, false);
         } else {
             // Set up the expiry date to be one day from the latest daily stat.
             // This may actually be today and we will rollover on the first event
@@ -123,6 +118,12 @@ class UserUsageStatsService {
         }
     }
 
+    void onTimeChanged(long oldTime, long newTime) {
+        persistActiveStats();
+        mDatabase.onTimeChanged(newTime - oldTime);
+        loadActiveStats(newTime, true);
+    }
+
     void reportEvent(UsageEvents.Event event) {
         if (DEBUG) {
             Slog.d(TAG, mLogPrefix + "Got usage event for " + event.mPackage
@@ -132,7 +133,7 @@ class UserUsageStatsService {
 
         if (event.mTimeStamp >= mDailyExpiryDate.getTimeInMillis()) {
             // Need to rollover
-            rolloverStats();
+            rolloverStats(event.mTimeStamp);
         }
 
         final IntervalStats currentDailyStats = mCurrentStats[UsageStatsManager.INTERVAL_DAILY];
@@ -330,8 +331,8 @@ class UserUsageStatsService {
         }
     }
 
-    private void rolloverStats() {
-        final long startTime = System.currentTimeMillis();
+    private void rolloverStats(final long currentTimeMillis) {
+        final long startTime = SystemClock.elapsedRealtime();
         Slog.i(TAG, mLogPrefix + "Rolling over usage stats");
 
         // Finish any ongoing events with an END_OF_DAY event. Make a note of which components
@@ -348,7 +349,7 @@ class UserUsageStatsService {
                     continuePreviousDay.add(pkgStats.mPackageName);
                     stat.update(pkgStats.mPackageName, mDailyExpiryDate.getTimeInMillis() - 1,
                             UsageEvents.Event.END_OF_DAY);
-                    mStatsChanged = true;
+                    notifyStatsChanged();
                 }
             }
 
@@ -356,8 +357,8 @@ class UserUsageStatsService {
         }
 
         persistActiveStats();
-        mDatabase.prune();
-        loadActiveStats();
+        mDatabase.prune(currentTimeMillis);
+        loadActiveStats(currentTimeMillis, false);
 
         final int continueCount = continuePreviousDay.size();
         for (int i = 0; i < continueCount; i++) {
@@ -366,12 +367,12 @@ class UserUsageStatsService {
             for (IntervalStats stat : mCurrentStats) {
                 stat.update(name, beginTime, UsageEvents.Event.CONTINUE_PREVIOUS_DAY);
                 stat.updateConfigurationStats(previousConfig, beginTime);
-                mStatsChanged = true;
+                notifyStatsChanged();
             }
         }
         persistActiveStats();
 
-        final long totalTime = System.currentTimeMillis() - startTime;
+        final long totalTime = SystemClock.elapsedRealtime() - startTime;
         Slog.i(TAG, mLogPrefix + "Rolling over usage stats complete. Took " + totalTime
                 + " milliseconds");
     }
@@ -383,15 +384,16 @@ class UserUsageStatsService {
         }
     }
 
-    private void loadActiveStats() {
-        final long timeNow = System.currentTimeMillis();
-
+    /**
+     * @param force To force all in-memory stats to be reloaded.
+     */
+    private void loadActiveStats(final long currentTimeMillis, boolean force) {
         final UnixCalendar tempCal = mDailyExpiryDate;
         for (int intervalType = 0; intervalType < mCurrentStats.length; intervalType++) {
-            tempCal.setTimeInMillis(timeNow);
+            tempCal.setTimeInMillis(currentTimeMillis);
             UnixCalendar.truncateTo(tempCal, intervalType);
 
-            if (mCurrentStats[intervalType] != null &&
+            if (!force && mCurrentStats[intervalType] != null &&
                     mCurrentStats[intervalType].beginTime == tempCal.getTimeInMillis()) {
                 // These are the same, no need to load them (in memory stats are always newer
                 // than persisted stats).
@@ -399,11 +401,7 @@ class UserUsageStatsService {
             }
 
             final long lastBeginTime = mDatabase.getLatestUsageStatsBeginTime(intervalType);
-            if (lastBeginTime > timeNow) {
-                Slog.e(TAG, mLogPrefix + "Latest usage stats for interval " +
-                        intervalType + " begins in the future");
-                mCurrentStats[intervalType] = null;
-            } else if (lastBeginTime >= tempCal.getTimeInMillis()) {
+            if (lastBeginTime >= tempCal.getTimeInMillis()) {
                 if (DEBUG) {
                     Slog.d(TAG, mLogPrefix + "Loading existing stats @ " +
                             sDateFormat.format(lastBeginTime) + "(" + lastBeginTime +
@@ -423,11 +421,11 @@ class UserUsageStatsService {
                 }
                 mCurrentStats[intervalType] = new IntervalStats();
                 mCurrentStats[intervalType].beginTime = tempCal.getTimeInMillis();
-                mCurrentStats[intervalType].endTime = timeNow;
+                mCurrentStats[intervalType].endTime = currentTimeMillis;
             }
         }
         mStatsChanged = false;
-        mDailyExpiryDate.setTimeInMillis(timeNow);
+        mDailyExpiryDate.setTimeInMillis(currentTimeMillis);
         mDailyExpiryDate.addDays(1);
         mDailyExpiryDate.truncateToDay();
         Slog.i(TAG, mLogPrefix + "Rollover scheduled @ " +