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
This commit is contained in:
Svetoslav Ganov
2016-08-02 18:24:49 -07:00
parent ba3d4f6ea1
commit a340bfd7a1
4 changed files with 124 additions and 17 deletions

View File

@@ -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)

View File

@@ -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) {

View File

@@ -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);
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 @@ 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: "
+ 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 @@ 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 + "}";
}
}
/**

View File

@@ -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");