Add historical logging to settings provider
This change adds historical operations to the dump state
of the settings provider. The historica operations are
currently appended only on user-debug and eng builds.
These change is needed to help diagnose the referred
bug and improve the settings provider's maintenance.
bug:30561721
Change-Id: I58a1ba0d598c4d28adcb5e654ebb78cf947e94db
diff --git a/packages/SettingsProvider/src/com/android/providers/settings/EventLogTags.logtags b/packages/SettingsProvider/src/com/android/providers/settings/EventLogTags.logtags
index 298d776..7eff16b 100644
--- a/packages/SettingsProvider/src/com/android/providers/settings/EventLogTags.logtags
+++ b/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)
diff --git a/packages/SettingsProvider/src/com/android/providers/settings/SettingsProvider.java b/packages/SettingsProvider/src/com/android/providers/settings/SettingsProvider.java
index d27f1f8..0f7fe6f 100644
--- a/packages/SettingsProvider/src/com/android/providers/settings/SettingsProvider.java
+++ b/packages/SettingsProvider/src/com/android/providers/settings/SettingsProvider.java
@@ -544,7 +544,7 @@
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 @@
}
}
- 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 @@
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) {
diff --git a/packages/SettingsProvider/src/com/android/providers/settings/SettingsState.java b/packages/SettingsProvider/src/com/android/providers/settings/SettingsState.java
index 4710d5a..bc91545 100644
--- a/packages/SettingsProvider/src/com/android/providers/settings/SettingsState.java
+++ b/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.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.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 @@
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 @@
// 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;
@@ -117,6 +126,9 @@
};
@GuardedBy("mLock")
+ private final List<HistoricalOperation> mHistoricalOperations;
+
+ @GuardedBy("mLock")
public final int mKey;
@GuardedBy("mLock")
@@ -134,6 +146,9 @@
@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 @@
mMaxBytesPerAppPackage = maxBytesPerAppPackage;
mPackageToMemoryUsage = null;
}
+
+ mHistoricalOperations = Build.IS_DEBUGGABLE
+ ? new ArrayList<>(HISTORICAL_OPERATION_COUNT) : null;
+
synchronized (mLock) {
readStateSyncLocked();
}
@@ -238,16 +257,20 @@
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);
- mSettings.put(name, state);
+ newState = new Setting(name, value, packageName);
+ mSettings.put(name, newState);
}
+ addHistoricalOperationLocked(HISTORICAL_OPERATION_UPDATE, newState);
+
updateMemoryUsagePerPackageLocked(packageName, oldValue, value);
scheduleWriteIfNeededLocked();
@@ -271,6 +294,8 @@
updateMemoryUsagePerPackageLocked(oldState.packageName, oldState.value, null);
+ addHistoricalOperationLocked(HISTORICAL_OPERATION_DELETE, oldState);
+
scheduleWriteIfNeededLocked();
return true;
@@ -290,6 +315,51 @@
}
}
+ 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 @@
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 @@
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 @@
}
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 @@
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: "
- + mStatePersistFile , e);
+ String message = "Failed parsing settings file: " + mStatePersistFile;
+ Slog.wtf(LOG_TAG, message);
+ throw new IllegalStateException(message , e);
} finally {
IoUtils.closeQuietly(in);
}
@@ -567,6 +645,19 @@
}
}
+ 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 @@
this.id = String.valueOf(mNextId++);
return true;
}
+
+ public String toString() {
+ return "Setting{name=" + value + " from " + packageName + "}";
+ }
}
/**
diff --git a/packages/SettingsProvider/test/src/com/android/providers/settings/SettingsStateTest.java b/packages/SettingsProvider/test/src/com/android/providers/settings/SettingsStateTest.java
index b5bd8ad..9964467 100644
--- a/packages/SettingsProvider/test/src/com/android/providers/settings/SettingsStateTest.java
+++ b/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 @@
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 @@
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 @@
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");