Merge "Enhance recent sync log in dumpsys content" into oc-dr1-dev

am: a014ce292a

Change-Id: I37135899d96cbd0eed2df224aef061d1f02857ec
This commit is contained in:
Makoto Onuki
2017-06-20 19:26:49 +00:00
committed by android-build-merger
8 changed files with 338 additions and 64 deletions

View File

@@ -24,7 +24,11 @@ import java.util.ArrayList;
/** @hide */
public class SyncStatusInfo implements Parcelable {
static final int VERSION = 2;
private static final String TAG = "Sync";
static final int VERSION = 3;
private static final int MAX_EVENT_COUNT = 10;
public final int authorityId;
public long totalElapsedTime;
@@ -47,7 +51,8 @@ public class SyncStatusInfo implements Parcelable {
// no race conditions when accessing this list
private ArrayList<Long> periodicSyncTimes;
private static final String TAG = "Sync";
private final ArrayList<Long> mLastEventTimes = new ArrayList<>();
private final ArrayList<String> mLastEvents = new ArrayList<>();
public SyncStatusInfo(int authorityId) {
this.authorityId = authorityId;
@@ -92,6 +97,11 @@ public class SyncStatusInfo implements Parcelable {
} else {
parcel.writeInt(-1);
}
parcel.writeInt(mLastEventTimes.size());
for (int i = 0; i < mLastEventTimes.size(); i++) {
parcel.writeLong(mLastEventTimes.get(i));
parcel.writeString(mLastEvents.get(i));
}
}
public SyncStatusInfo(Parcel parcel) {
@@ -117,15 +127,24 @@ public class SyncStatusInfo implements Parcelable {
if (version == 1) {
periodicSyncTimes = null;
} else {
int N = parcel.readInt();
if (N < 0) {
final int count = parcel.readInt();
if (count < 0) {
periodicSyncTimes = null;
} else {
periodicSyncTimes = new ArrayList<Long>();
for (int i=0; i<N; i++) {
for (int i = 0; i < count; i++) {
periodicSyncTimes.add(parcel.readLong());
}
}
if (version >= 3) {
mLastEventTimes.clear();
mLastEvents.clear();
final int nEvents = parcel.readInt();
for (int i = 0; i < nEvents; i++) {
mLastEventTimes.add(parcel.readLong());
mLastEvents.add(parcel.readString());
}
}
}
}
@@ -149,6 +168,8 @@ public class SyncStatusInfo implements Parcelable {
if (other.periodicSyncTimes != null) {
periodicSyncTimes = new ArrayList<Long>(other.periodicSyncTimes);
}
mLastEventTimes.addAll(other.mLastEventTimes);
mLastEvents.addAll(other.mLastEvents);
}
public void setPeriodicSyncTime(int index, long when) {
@@ -172,6 +193,31 @@ public class SyncStatusInfo implements Parcelable {
}
}
/** */
public void addEvent(String message) {
if (mLastEventTimes.size() >= MAX_EVENT_COUNT) {
mLastEventTimes.remove(MAX_EVENT_COUNT - 1);
mLastEvents.remove(MAX_EVENT_COUNT - 1);
}
mLastEventTimes.add(0, System.currentTimeMillis());
mLastEvents.add(0, message);
}
/** */
public int getEventCount() {
return mLastEventTimes.size();
}
/** */
public long getEventTime(int i) {
return mLastEventTimes.get(i);
}
/** */
public String getEvent(int i) {
return mLastEvents.get(i);
}
public static final Creator<SyncStatusInfo> CREATOR = new Creator<SyncStatusInfo>() {
public SyncStatusInfo createFromParcel(Parcel in) {
return new SyncStatusInfo(in);

View File

@@ -74,7 +74,6 @@ import android.os.UserHandle;
import android.os.UserManager;
import android.os.WorkSource;
import android.provider.Settings;
import android.text.format.DateUtils;
import android.text.format.Time;
import android.util.EventLog;
import android.util.Log;
@@ -113,6 +112,7 @@ import java.util.Map;
import java.util.Objects;
import java.util.Random;
import java.util.Set;
import java.util.function.Predicate;
/**
* Implementation details:
@@ -1761,10 +1761,7 @@ public class SyncManager {
protected void dump(FileDescriptor fd, PrintWriter pw) {
final IndentingPrintWriter ipw = new IndentingPrintWriter(pw, " ");
dumpPendingSyncs(pw);
dumpPeriodicSyncs(pw);
dumpSyncState(ipw);
dumpSyncHistory(ipw);
dumpSyncAdapters(ipw);
}
@@ -1774,9 +1771,58 @@ public class SyncManager {
return tobj.format("%Y-%m-%d %H:%M:%S");
}
private final static Comparator<SyncOperation> sOpDumpComparator = (op1, op2) -> {
int res = Integer.compare(op1.target.userId, op2.target.userId);
if (res != 0) return res;
final Comparator<String> stringComparator = String.CASE_INSENSITIVE_ORDER;
res = stringComparator.compare(op1.target.account.type, op2.target.account.type);
if (res != 0) return res;
res = stringComparator.compare(op1.target.account.name, op2.target.account.name);
if (res != 0) return res;
res = stringComparator.compare(op1.target.provider, op2.target.provider);
if (res != 0) return res;
res = Integer.compare(op1.reason, op2.reason);
if (res != 0) return res;
res = Long.compare(op1.periodMillis, op2.periodMillis);
if (res != 0) return res;
res = Long.compare(op1.expectedRuntime, op2.expectedRuntime);
if (res != 0) return res;
res = Long.compare(op1.jobId, op2.jobId);
if (res != 0) return res;
return 0;
};
private final static Comparator<SyncOperation> sOpRuntimeComparator = (op1, op2) -> {
int res = Long.compare(op1.expectedRuntime, op2.expectedRuntime);
if (res != 0) return res;
return sOpDumpComparator.compare(op1, op2);
};
private static <T> int countIf(Collection<T> col, Predicate<T> p) {
int ret = 0;
for (T item : col) {
if (p.test(item)) ret++;
}
return ret;
}
protected void dumpPendingSyncs(PrintWriter pw) {
pw.println("Pending Syncs:");
List<SyncOperation> pendingSyncs = getAllPendingSyncs();
pw.print("Pending Syncs: ");
pw.println(countIf(pendingSyncs, op -> !op.isPeriodic));
Collections.sort(pendingSyncs, sOpRuntimeComparator);
int count = 0;
for (SyncOperation op: pendingSyncs) {
if (!op.isPeriodic) {
@@ -1784,13 +1830,16 @@ public class SyncManager {
count++;
}
}
pw.println("Total: " + count);
pw.println();
}
protected void dumpPeriodicSyncs(PrintWriter pw) {
pw.println("Periodic Syncs:");
List<SyncOperation> pendingSyncs = getAllPendingSyncs();
pw.print("Periodic Syncs: ");
pw.println(countIf(pendingSyncs, op -> op.isPeriodic));
Collections.sort(pendingSyncs, sOpDumpComparator);
int count = 0;
for (SyncOperation op: pendingSyncs) {
if (op.isPeriodic) {
@@ -1798,11 +1847,62 @@ public class SyncManager {
count++;
}
}
pw.println("Total: " + count);
pw.println();
}
/**
* Similar to {@link android.util.TimeUtils#formatDuration}, but it's more suitable and concise
* for the sync manager dumpsys. (Don't add the leading + sign, don't show milliseconds.)
*/
public static StringBuilder formatDurationHMS(StringBuilder sb, long duration) {
duration /= 1000;
if (duration < 0) {
sb.append('-');
duration = -duration;
}
final long seconds = duration % 60;
duration /= 60;
final long minutes = duration % 60;
duration /= 60;
final long hours = duration % 24;
duration /= 24;
final long days = duration;
boolean print = false;
if (days > 0) {
sb.append(days);
sb.append('d');
print = true;
}
print = printTwoDigitNumber(sb, hours, 'h', print);
print = printTwoDigitNumber(sb, minutes, 'm', print);
print = printTwoDigitNumber(sb, seconds, 's', print);
if (!print) {
sb.append("0s");
}
return sb;
}
private static boolean printTwoDigitNumber(StringBuilder sb, long value, char unit,
boolean always) {
if (!always && (value == 0)) {
return false;
}
if (always && (value < 10)) {
sb.append('0');
}
sb.append(value);
sb.append(unit);
return true;
}
protected void dumpSyncState(PrintWriter pw) {
final StringBuilder sb = new StringBuilder();
pw.print("data connected: "); pw.println(mDataConnectionIsConnected);
pw.print("auto sync: ");
List<UserInfo> users = getAllUsers();
@@ -1828,13 +1928,16 @@ public class SyncManager {
final long now = SystemClock.elapsedRealtime();
pw.print("now: "); pw.print(now);
pw.println(" (" + formatTime(System.currentTimeMillis()) + ")");
pw.println(" (HH:MM:SS)");
pw.print("uptime: "); pw.print(DateUtils.formatElapsedTime(now / 1000));
pw.println(" (HH:MM:SS)");
sb.setLength(0);
pw.print("uptime: "); pw.print(formatDurationHMS(sb, now));
pw.println();
pw.print("time spent syncing: ");
pw.print(DateUtils.formatElapsedTime(
mSyncHandler.mSyncTimeTracker.timeSpentSyncing() / 1000));
pw.print(" (HH:MM:SS), sync ");
sb.setLength(0);
pw.print(formatDurationHMS(sb,
mSyncHandler.mSyncTimeTracker.timeSpentSyncing()));
pw.print(", sync ");
pw.print(mSyncHandler.mSyncTimeTracker.mLastWasSyncing ? "" : "not ");
pw.println("in progress");
@@ -1842,17 +1945,24 @@ public class SyncManager {
pw.println("Active Syncs: " + mActiveSyncContexts.size());
final PackageManager pm = mContext.getPackageManager();
for (SyncManager.ActiveSyncContext activeSyncContext : mActiveSyncContexts) {
final long durationInSeconds = (now - activeSyncContext.mStartTime) / 1000;
final long durationInSeconds = (now - activeSyncContext.mStartTime);
pw.print(" ");
pw.print(DateUtils.formatElapsedTime(durationInSeconds));
sb.setLength(0);
pw.print(formatDurationHMS(sb, durationInSeconds));
pw.print(" - ");
pw.print(activeSyncContext.mSyncOperation.dump(pm, false));
pw.println();
}
pw.println();
dumpPendingSyncs(pw);
dumpPeriodicSyncs(pw);
// Join the installed sync adapter with the accounts list and emit for everything.
pw.println();
pw.println("Sync Status");
final ArrayList<Pair<EndPoint, SyncStatusInfo>> statuses = new ArrayList<>();
for (AccountAndUser account : accounts) {
pw.printf("Account %s u%d %s\n",
account.account.name, account.userId, account.account.type);
@@ -1872,7 +1982,7 @@ public class SyncManager {
"Tot", // 9
"Time", // 10
"Last Sync", // 11
"Etc" // 12
"Backoff" // 12
);
final List<RegisteredServicesCache.ServiceInfo<SyncAdapterType>> sorted =
@@ -1899,11 +2009,14 @@ public class SyncManager {
account.userId));
SyncStorageEngine.AuthorityInfo settings = syncAuthoritySyncStatus.first;
SyncStatusInfo status = syncAuthoritySyncStatus.second;
statuses.add(Pair.create(settings.target, status));
String authority = settings.target.provider;
if (authority.length() > 50) {
authority = authority.substring(authority.length() - 50);
}
table.set(row, 0, authority, settings.syncable, settings.enabled);
sb.setLength(0);
table.set(row, 4,
status.numSourceLocal,
status.numSourcePoll,
@@ -1911,7 +2024,7 @@ public class SyncManager {
status.numSourceServer,
status.numSourceUser,
status.numSyncs,
DateUtils.formatElapsedTime(status.totalElapsedTime / 1000));
formatDurationHMS(sb, status.totalElapsedTime));
int row1 = row;
if (settings.delayUntil > now) {
@@ -1938,6 +2051,34 @@ public class SyncManager {
}
table.writeTo(pw);
}
dumpSyncHistory(pw);
pw.println();
pw.println("Per Adapter History");
for (int i = 0; i < statuses.size(); i++) {
final Pair<EndPoint, SyncStatusInfo> event = statuses.get(i);
pw.print(" ");
pw.print(event.first.account.name);
pw.print('/');
pw.print(event.first.account.type);
pw.print(" u");
pw.print(event.first.userId);
pw.print(" [");
pw.print(event.first.provider);
pw.print("]");
pw.println();
for (int j = 0; j < event.second.getEventCount(); j++) {
pw.print(" ");
pw.print(formatTime(event.second.getEventTime(j)));
pw.print(' ');
pw.print(event.second.getEvent(j));
pw.println();
}
}
}
private void dumpTimeSec(PrintWriter pw, long time) {
@@ -3403,7 +3544,7 @@ public class SyncManager {
}
static class PrintTable {
private ArrayList<Object[]> mTable = Lists.newArrayList();
private ArrayList<String[]> mTable = Lists.newArrayList();
private final int mCols;
PrintTable(int cols) {
@@ -3416,13 +3557,17 @@ public class SyncManager {
" columns. can't set " + values.length + " at column " + col);
}
for (int i = mTable.size(); i <= row; i++) {
final Object[] list = new Object[mCols];
final String[] list = new String[mCols];
mTable.add(list);
for (int j = 0; j < mCols; j++) {
list[j] = "";
}
}
System.arraycopy(values, 0, mTable.get(row), col, values.length);
final String[] rowArray = mTable.get(row);
for (int i = 0; i < values.length; i++) {
final Object value = values[i];
rowArray[col + i] = (value == null) ? "" : value.toString();
}
}
void writeTo(PrintWriter out) {

View File

@@ -18,10 +18,11 @@ package com.android.server.content;
import android.accounts.Account;
import android.app.job.JobInfo;
import android.content.pm.PackageManager;
import android.content.ContentResolver;
import android.content.pm.PackageManager;
import android.os.Bundle;
import android.os.PersistableBundle;
import android.os.SystemClock;
import android.os.UserHandle;
import android.util.Slog;
@@ -350,37 +351,46 @@ public class SyncOperation {
return dump(null, true);
}
String dump(PackageManager pm, boolean useOneLine) {
String dump(PackageManager pm, boolean shorter) {
StringBuilder sb = new StringBuilder();
sb.append("JobId: ").append(jobId)
.append(", ")
sb.append("JobId=").append(jobId)
.append(" ")
.append(target.account.name)
.append(" u")
.append(target.userId).append(" (")
.append("/")
.append(target.account.type)
.append(")")
.append(", ")
.append(" u")
.append(target.userId)
.append(" [")
.append(target.provider)
.append(", ");
.append("] ");
sb.append(SyncStorageEngine.SOURCES[syncSource]);
if (extras.getBoolean(ContentResolver.SYNC_EXTRAS_EXPEDITED, false)) {
sb.append(", EXPEDITED");
if (expectedRuntime != 0) {
sb.append(" ExpectedIn=");
SyncManager.formatDurationHMS(sb,
(expectedRuntime - SystemClock.elapsedRealtime()));
}
sb.append(", reason: ");
if (extras.getBoolean(ContentResolver.SYNC_EXTRAS_EXPEDITED, false)) {
sb.append(" EXPEDITED");
}
sb.append(" Reason=");
sb.append(reasonToString(pm, reason));
if (isPeriodic) {
sb.append(", period: " + periodMillis).append(", flexMillis: " + flexMillis);
sb.append(" (period=");
SyncManager.formatDurationHMS(sb, periodMillis);
sb.append(" flex=");
SyncManager.formatDurationHMS(sb, flexMillis);
sb.append(")");
}
if (!useOneLine) {
sb.append("\n ");
sb.append("owningUid=");
if (!shorter) {
sb.append(" Owner={");
UserHandle.formatUid(sb, owningUid);
sb.append(" owningPackage=");
sb.append(" ");
sb.append(owningPackage);
}
if (!useOneLine && !extras.keySet().isEmpty()) {
sb.append("\n ");
extrasToStringBuilder(extras, sb);
sb.append("}");
if (!extras.keySet().isEmpty()) {
sb.append(" ");
extrasToStringBuilder(extras, sb);
}
}
return sb.toString();
}
@@ -434,7 +444,7 @@ public class SyncOperation {
return extras.getBoolean(ContentResolver.SYNC_EXTRAS_IGNORE_SETTINGS, false);
}
private static void extrasToStringBuilder(Bundle bundle, StringBuilder sb) {
static void extrasToStringBuilder(Bundle bundle, StringBuilder sb) {
sb.append("[");
for (String key : bundle.keySet()) {
sb.append(key).append("=").append(bundle.get(key)).append(" ");

View File

@@ -1183,6 +1183,16 @@ public class SyncStorageEngine extends Handler {
ds.failureCount++;
ds.failureTime += elapsedTime;
}
final StringBuilder event = new StringBuilder();
event.append("" + resultMessage + " Source=" + SyncStorageEngine.SOURCES[item.source]
+ " Elapsed=");
SyncManager.formatDurationHMS(event, elapsedTime);
event.append(" Reason=");
event.append(SyncOperation.reasonToString(null, item.reason));
event.append(" Extras=");
SyncOperation.extrasToStringBuilder(item.extras, event);
status.addEvent(event.toString());
if (writeStatusNow) {
writeStatusLocked();

View File

@@ -21,16 +21,22 @@ import java.util.ArrayList;
import android.database.ContentObserver;
import android.net.Uri;
import android.os.Handler;
import android.os.Looper;
import android.os.UserHandle;
import android.test.AndroidTestCase;
import android.test.suitebuilder.annotation.SmallTest;
import com.android.server.content.ContentService.ObserverCall;
import com.android.server.content.ContentService.ObserverNode;
/**
* bit FrameworksServicesTests:com.android.server.content.ObserverNodeTest
*/
@SmallTest
public class ObserverNodeTest extends AndroidTestCase {
static class TestObserver extends ContentObserver {
public TestObserver() {
super(new Handler());
super(new Handler(Looper.getMainLooper()));
}
}

View File

@@ -1,9 +1,32 @@
/*
* Copyright (C) 2017 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package com.android.server.content;
import android.os.Bundle;
import android.test.suitebuilder.annotation.SmallTest;
import junit.framework.TestCase;
/**
* Tests for SyncManager.
*
* bit FrameworksServicesTests:com.android.server.content.SyncManagerTest
*/
@SmallTest
public class SyncManagerTest extends TestCase {
final String KEY_1 = "key_1";
@@ -61,4 +84,42 @@ public class SyncManagerTest extends TestCase {
assertFalse("Extras considered equal when they are different.",
SyncManager.syncExtrasEquals(b1, b2, false /* don't care about system extras */));
}
public void testFormatDurationHMS() {
checkFormatDurationHMS("0s", 0, 0, 0, 0);
checkFormatDurationHMS("1s", 0, 0, 0, 1);
checkFormatDurationHMS("9s", 0, 0, 0, 9);
checkFormatDurationHMS("10s", 0, 0, 0, 10);
checkFormatDurationHMS("59s", 0, 0, 0, 59);
checkFormatDurationHMS("1m00s", 0, 0, 1, 0);
checkFormatDurationHMS("1m01s", 0, 0, 1, 1);
checkFormatDurationHMS("1m09s", 0, 0, 1, 9);
checkFormatDurationHMS("1m10s", 0, 0, 1, 10);
checkFormatDurationHMS("1m59s", 0, 0, 1, 59);
checkFormatDurationHMS("1h00m00s", 0, 1, 0, 0);
checkFormatDurationHMS("1h00m01s", 0, 1, 0, 1);
checkFormatDurationHMS("1h01m01s", 0, 1, 1, 1);
checkFormatDurationHMS("1h09m10s", 0, 1, 9, 10);
checkFormatDurationHMS("1h10m59s", 0, 1, 10, 59);
checkFormatDurationHMS("1h59m00s", 0, 1, 59, 0);
checkFormatDurationHMS("1d00h00m00s", 1, 0, 0, 0);
checkFormatDurationHMS("1d00h00m00s", 1, 0, 0, 0);
checkFormatDurationHMS("1d01h00m00s", 1, 1, 0, 0);
checkFormatDurationHMS("1d09h00m00s", 1, 9, 0, 0);
checkFormatDurationHMS("1d10h00m00s", 1, 10, 0, 0);
checkFormatDurationHMS("1d23h00m00s", 1, 23, 0, 0);
checkFormatDurationHMS("123d01h00m00s", 123, 1, 0, 0);
final StringBuilder sb = new StringBuilder();
assertEquals("-1m01s", SyncManager.formatDurationHMS(sb, -61000L).toString());
}
private void checkFormatDurationHMS(String expected,
int d, int h, int m, int s) {
final long time = (d * 24 * 3600) + (h * 3600) + (m * 60) + s;
final StringBuilder sb = new StringBuilder();
assertEquals(expected, SyncManager.formatDurationHMS(sb, time * 1000).toString());
}
}

View File

@@ -17,24 +17,17 @@
package com.android.server.content;
import android.accounts.Account;
import android.content.ContentResolver;
import android.content.Context;
import android.os.Bundle;
import android.os.PersistableBundle;
import android.os.SystemClock;
import android.provider.Settings;
import android.test.AndroidTestCase;
import android.test.suitebuilder.annotation.SmallTest;
/**
* You can run those tests with:
* Test for SyncOperation.
*
* adb shell am instrument
* -e debug false
* -w
* -e class android.content.SyncOperationTest com.android.frameworks.coretests/android.test.InstrumentationTestRunner
* bit FrameworksServicesTests:com.android.server.content.SyncOperationTest
*/
@SmallTest
public class SyncOperationTest extends AndroidTestCase {
Account mDummy;

View File

@@ -22,7 +22,6 @@ import android.content.ContentResolver;
import android.content.Context;
import android.content.ContextWrapper;
import android.content.Intent;
import android.content.PeriodicSync;
import android.content.res.Resources;
import android.os.Bundle;
import android.test.AndroidTestCase;
@@ -33,14 +32,18 @@ import android.test.suitebuilder.annotation.LargeTest;
import android.test.suitebuilder.annotation.MediumTest;
import android.test.suitebuilder.annotation.SmallTest;
import com.android.server.content.SyncStorageEngine.EndPoint;
import com.android.internal.os.AtomicFile;
import java.io.File;
import java.io.FileOutputStream;
import java.util.List;
/**
* Test for SyncStorageEngine.
*
* bit FrameworksServicesTests:com.android.server.content.SyncStorageEngineTest
*
* TODO Broken. Fix it. b/62485315
*/
public class SyncStorageEngineTest extends AndroidTestCase {
protected Account account1;