Merge "Add historical logging to settings provider" into nyc-mr1-dev

packages/SettingsProvider/src/com/android/providers/settings/EventLogTags.logtags

@@ -1,5 +1,6 @@
-# See system/core/logcat/e for a description of the format of this file.
+# See system/core/logcat/event.logtags for a description of the format of this file.
 
 option java_package com.android.providers.settings;
 
 52100 unsupported_settings_query (uri|3),(selection|3),(whereArgs|3)
+52101 persist_setting_error (message|3)

packages/SettingsProvider/src/com/android/providers/settings/SettingsProvider.java

@@ -544,7 +544,7 @@ public class SettingsProvider extends ContentProvider {
                 final int userCount = users.size();
                 for (int i = 0; i < userCount; i++) {
                     UserInfo user = users.get(i);
-                    dumpForUser(user.id, pw);
+                    dumpForUserLocked(user.id, pw);
                 }
             } finally {
                 Binder.restoreCallingIdentity(identity);
@@ -552,12 +552,16 @@ public class SettingsProvider extends ContentProvider {
         }
     }
 
-    private void dumpForUser(int userId, PrintWriter pw) {
+    private void dumpForUserLocked(int userId, PrintWriter pw) {
         if (userId == UserHandle.USER_SYSTEM) {
             pw.println("GLOBAL SETTINGS (user " + userId + ")");
             Cursor globalCursor = getAllGlobalSettings(ALL_COLUMNS);
             dumpSettings(globalCursor, pw);
             pw.println();
+
+            SettingsState globalSettings = mSettingsRegistry.getSettingsLocked(
+                    SETTINGS_TYPE_GLOBAL, UserHandle.USER_SYSTEM);
+            globalSettings.dumpHistoricalOperations(pw);
         }
 
         pw.println("SECURE SETTINGS (user " + userId + ")");
@@ -565,10 +569,18 @@ public class SettingsProvider extends ContentProvider {
         dumpSettings(secureCursor, pw);
         pw.println();
 
+        SettingsState secureSettings = mSettingsRegistry.getSettingsLocked(
+                SETTINGS_TYPE_SECURE, userId);
+        secureSettings.dumpHistoricalOperations(pw);
+
         pw.println("SYSTEM SETTINGS (user " + userId + ")");
         Cursor systemCursor = getAllSystemSettings(userId, ALL_COLUMNS);
         dumpSettings(systemCursor, pw);
         pw.println();
+
+        SettingsState systemSettings = mSettingsRegistry.getSettingsLocked(
+                SETTINGS_TYPE_SYSTEM, userId);
+        systemSettings.dumpHistoricalOperations(pw);
     }
 
     private void dumpSettings(Cursor cursor, PrintWriter pw) {

packages/SettingsProvider/src/com/android/providers/settings/SettingsState.java

@@ -16,6 +16,7 @@
 
 package com.android.providers.settings;
 
+import android.os.Build;
 import android.os.Handler;
 import android.os.Looper;
 import android.os.Message;
@@ -26,6 +27,7 @@ import android.util.ArrayMap;
 import android.util.AtomicFile;
 import android.util.Base64;
 import android.util.Slog;
+import android.util.TimeUtils;
 import android.util.Xml;
 import com.android.internal.annotations.GuardedBy;
 import libcore.io.IoUtils;
@@ -39,6 +41,7 @@ import java.io.FileInputStream;
 import java.io.FileNotFoundException;
 import java.io.FileOutputStream;
 import java.io.IOException;
+import java.io.PrintWriter;
 import java.nio.charset.StandardCharsets;
 import java.util.ArrayList;
 import java.util.List;
@@ -60,7 +63,7 @@ final class SettingsState {
 
     private static final String LOG_TAG = "SettingsState";
 
-    static final int SETTINGS_VERSOIN_NEW_ENCODING = 121;
+    static final int SETTINGS_VERSION_NEW_ENCODING = 121;
 
     private static final long WRITE_SETTINGS_DELAY_MILLIS = 200;
     private static final long MAX_WRITE_SETTINGS_DELAY_MILLIS = 2000;
@@ -93,6 +96,12 @@ final class SettingsState {
     // This was used in version 120 and before.
     private static final String NULL_VALUE_OLD_STYLE = "null";
 
+    private static final int HISTORICAL_OPERATION_COUNT = 20;
+    private static final String HISTORICAL_OPERATION_UPDATE = "update";
+    private static final String HISTORICAL_OPERATION_DELETE = "delete";
+    private static final String HISTORICAL_OPERATION_PERSIST = "persist";
+    private static final String HISTORICAL_OPERATION_INITIALIZE = "initialize";
+
     private final Object mLock;
 
     private final Handler mHandler;
@@ -116,6 +125,9 @@ final class SettingsState {
         }
     };
 
+    @GuardedBy("mLock")
+    private final List<HistoricalOperation> mHistoricalOperations;
+
     @GuardedBy("mLock")
     public final int mKey;
 
@@ -134,6 +146,9 @@ final class SettingsState {
     @GuardedBy("mLock")
     private long mNextId;
 
+    @GuardedBy("mLock")
+    private int mNextHistoricalOpIdx;
+
     public SettingsState(Object lock, File file, int key, int maxBytesPerAppPackage,
             Looper looper) {
         // It is important that we use the same lock as the settings provider
@@ -150,6 +165,10 @@ final class SettingsState {
             mMaxBytesPerAppPackage = maxBytesPerAppPackage;
             mPackageToMemoryUsage = null;
         }
+
+        mHistoricalOperations = Build.IS_DEBUGGABLE
+                ? new ArrayList<>(HISTORICAL_OPERATION_COUNT) : null;
+
         synchronized (mLock) {
             readStateSyncLocked();
         }
@@ -238,16 +257,20 @@ final class SettingsState {
 
         Setting oldState = mSettings.get(name);
         String oldValue = (oldState != null) ? oldState.value : null;
+        Setting newState;
 
         if (oldState != null) {
             if (!oldState.update(value, packageName)) {
                 return false;
             }
+            newState = oldState;
         } else {
-            Setting state = new Setting(name, value, packageName);
+            newState = new Setting(name, value, packageName);
-            mSettings.put(name, state);
+            mSettings.put(name, newState);
         }
 
+        addHistoricalOperationLocked(HISTORICAL_OPERATION_UPDATE, newState);
+
         updateMemoryUsagePerPackageLocked(packageName, oldValue, value);
 
         scheduleWriteIfNeededLocked();
@@ -271,6 +294,8 @@ final class SettingsState {
 
         updateMemoryUsagePerPackageLocked(oldState.packageName, oldState.value, null);
 
+        addHistoricalOperationLocked(HISTORICAL_OPERATION_DELETE, oldState);
+
         scheduleWriteIfNeededLocked();
 
         return true;
@@ -290,6 +315,51 @@ final class SettingsState {
         }
     }
 
+    private void addHistoricalOperationLocked(String type, Setting setting) {
+        if (mHistoricalOperations == null) {
+            return;
+        }
+        HistoricalOperation operation = new HistoricalOperation(
+                SystemClock.elapsedRealtime(), type,
+                setting != null ? new Setting(setting) : null);
+        if (mNextHistoricalOpIdx >= mHistoricalOperations.size()) {
+            mHistoricalOperations.add(operation);
+        } else {
+            mHistoricalOperations.set(mNextHistoricalOpIdx, operation);
+        }
+        mNextHistoricalOpIdx++;
+        if (mNextHistoricalOpIdx >= HISTORICAL_OPERATION_COUNT) {
+            mNextHistoricalOpIdx = 0;
+        }
+    }
+
+    public void dumpHistoricalOperations(PrintWriter pw) {
+        synchronized (mLock) {
+            if (mHistoricalOperations == null) {
+                return;
+            }
+            pw.println("Historical operations");
+            final int operationCount = mHistoricalOperations.size();
+            for (int i = 0; i < operationCount; i++) {
+                int index = mNextHistoricalOpIdx - 1 - i;
+                if (index < 0) {
+                    index = operationCount + index;
+                }
+                HistoricalOperation operation = mHistoricalOperations.get(index);
+                pw.print(TimeUtils.formatForLogging(operation.mTimestamp));
+                pw.print(" ");
+                pw.print(operation.mOperation);
+                if (operation.mSetting != null) {
+                    pw.print("  ");
+                    pw.print(operation.mSetting);
+                }
+                pw.println();
+            }
+            pw.println();
+            pw.println();
+        }
+    }
+
     private void updateMemoryUsagePerPackageLocked(String packageName, String oldValue,
             String newValue) {
         if (mMaxBytesPerAppPackage == MAX_BYTES_PER_APP_PACKAGE_UNLIMITED) {
@@ -407,6 +477,10 @@ final class SettingsState {
             serializer.endDocument();
             destination.finishWrite(out);
 
+            synchronized (mLock) {
+                addHistoricalOperationLocked(HISTORICAL_OPERATION_PERSIST, null);
+            }
+
             if (DEBUG_PERSISTENCE) {
                 Slog.i(LOG_TAG, "[PERSIST END]");
             }
@@ -435,7 +509,7 @@ final class SettingsState {
 
     static void setValueAttribute(int version, XmlSerializer serializer, String value)
             throws IOException {
-        if (version >= SETTINGS_VERSOIN_NEW_ENCODING) {
+        if (version >= SETTINGS_VERSION_NEW_ENCODING) {
             if (value == null) {
                 // Null value -> No ATTR_VALUE nor ATTR_VALUE_BASE64.
             } else if (isBinary(value)) {
@@ -454,7 +528,7 @@ final class SettingsState {
     }
 
     private String getValueAttribute(XmlPullParser parser) {
-        if (mVersion >= SETTINGS_VERSOIN_NEW_ENCODING) {
+        if (mVersion >= SETTINGS_VERSION_NEW_ENCODING) {
             final String value = parser.getAttributeValue(null, ATTR_VALUE);
             if (value != null) {
                 return value;
@@ -479,22 +553,26 @@ final class SettingsState {
     private void readStateSyncLocked() {
         FileInputStream in;
         if (!mStatePersistFile.exists()) {
+            Slog.i(LOG_TAG, "No settings state " + mStatePersistFile);
+            addHistoricalOperationLocked(HISTORICAL_OPERATION_INITIALIZE, null);
             return;
         }
         try {
             in = new AtomicFile(mStatePersistFile).openRead();
         } catch (FileNotFoundException fnfe) {
-            Slog.i(LOG_TAG, "No settings state");
+            String message = "No settings state " + mStatePersistFile;
+            Slog.wtf(LOG_TAG, message);
+            Slog.i(LOG_TAG, message);
             return;
         }
         try {
             XmlPullParser parser = Xml.newPullParser();
             parser.setInput(in, StandardCharsets.UTF_8.name());
             parseStateLocked(parser);
-
         } catch (XmlPullParserException | IOException e) {
-            throw new IllegalStateException("Failed parsing settings file: "
+            String message = "Failed parsing settings file: " + mStatePersistFile;
-                    + mStatePersistFile , e);
+            Slog.wtf(LOG_TAG, message);
+            throw new IllegalStateException(message , e);
         } finally {
             IoUtils.closeQuietly(in);
         }
@@ -567,6 +645,19 @@ final class SettingsState {
         }
     }
 
+    private class HistoricalOperation {
+        final long mTimestamp;
+        final String mOperation;
+        final Setting mSetting;
+
+        public HistoricalOperation(long timestamp,
+                String operation, Setting setting) {
+            mTimestamp = timestamp;
+            mOperation = operation;
+            mSetting = setting;
+        }
+    }
+
     class Setting {
         private String name;
         private String value;
@@ -629,6 +720,10 @@ final class SettingsState {
             this.id = String.valueOf(mNextId++);
             return true;
         }
+
+        public String toString() {
+            return "Setting{name=" + value + " from " + packageName + "}";
+        }
     }
 
     /**

packages/SettingsProvider/test/src/com/android/providers/settings/SettingsStateTest.java

@@ -15,7 +15,6 @@
  */
 package com.android.providers.settings;
 
-import android.os.Handler;
 import android.os.Looper;
 import android.test.AndroidTestCase;
 import android.util.Xml;
@@ -99,10 +98,10 @@ public class SettingsStateTest extends AndroidTestCase {
         checkWriteSingleSetting(serializer, null, null);
         checkWriteSingleSetting(serializer, CRAZY_STRING, null);
         SettingsState.writeSingleSetting(
-                SettingsState.SETTINGS_VERSOIN_NEW_ENCODING,
+                SettingsState.SETTINGS_VERSION_NEW_ENCODING,
                 serializer, null, "k", "v", "package");
         SettingsState.writeSingleSetting(
-                SettingsState.SETTINGS_VERSOIN_NEW_ENCODING,
+                SettingsState.SETTINGS_VERSION_NEW_ENCODING,
                 serializer, "1", "k", "v", null);
     }
 
@@ -115,7 +114,7 @@ public class SettingsStateTest extends AndroidTestCase {
             String key, String value) throws Exception {
         // Make sure the XML serializer won't crash.
         SettingsState.writeSingleSetting(
-                SettingsState.SETTINGS_VERSOIN_NEW_ENCODING,
+                SettingsState.SETTINGS_VERSION_NEW_ENCODING,
                 serializer, "1", key, value, "package");
     }
 
@@ -129,7 +128,7 @@ public class SettingsStateTest extends AndroidTestCase {
 
         final SettingsState ssWriter = new SettingsState(lock, file, 1,
                 SettingsState.MAX_BYTES_PER_APP_PACKAGE_UNLIMITED, Looper.getMainLooper());
-        ssWriter.setVersionLocked(SettingsState.SETTINGS_VERSOIN_NEW_ENCODING);
+        ssWriter.setVersionLocked(SettingsState.SETTINGS_VERSION_NEW_ENCODING);
 
         ssWriter.insertSettingLocked("k1", "\u0000", "package");
         ssWriter.insertSettingLocked("k2", "abc", "p2");