Merge "Merge "Revert "Add ActivityInfo logging."" into oc-dev am: 61196fef1f" into oc-dr1-dev
diff --git a/core/java/android/os/FileUtils.java b/core/java/android/os/FileUtils.java
index 50b4f8c..56d6e0a 100644
--- a/core/java/android/os/FileUtils.java
+++ b/core/java/android/os/FileUtils.java
@@ -369,11 +369,11 @@
* constraints remain.
*
* @param minCount Always keep at least this many files.
- * @param minAge Always keep files younger than this age.
+ * @param minAgeMs Always keep files younger than this age, in milliseconds.
* @return if any files were deleted.
*/
- public static boolean deleteOlderFiles(File dir, int minCount, long minAge) {
- if (minCount < 0 || minAge < 0) {
+ public static boolean deleteOlderFiles(File dir, int minCount, long minAgeMs) {
+ if (minCount < 0 || minAgeMs < 0) {
throw new IllegalArgumentException("Constraints must be positive or 0");
}
@@ -393,9 +393,9 @@
for (int i = minCount; i < files.length; i++) {
final File file = files[i];
- // Keep files newer than minAge
+ // Keep files newer than minAgeMs
final long age = System.currentTimeMillis() - file.lastModified();
- if (age > minAge) {
+ if (age > minAgeMs) {
if (file.delete()) {
Log.d(TAG, "Deleted old file " + file);
deleted = true;
diff --git a/services/core/java/com/android/server/content/ContentService.java b/services/core/java/com/android/server/content/ContentService.java
index 13054a6..468cb29 100644
--- a/services/core/java/com/android/server/content/ContentService.java
+++ b/services/core/java/com/android/server/content/ContentService.java
@@ -60,6 +60,7 @@
import android.util.SparseIntArray;
import com.android.internal.annotations.GuardedBy;
+import com.android.internal.util.ArrayUtils;
import com.android.internal.util.DumpUtils;
import com.android.internal.util.IndentingPrintWriter;
import com.android.server.LocalServices;
@@ -166,6 +167,8 @@
if (!DumpUtils.checkDumpAndUsageStatsPermission(mContext, TAG, pw_)) return;
final IndentingPrintWriter pw = new IndentingPrintWriter(pw_, " ");
+ final boolean dumpAll = ArrayUtils.contains(args, "-a");
+
// This makes it so that future permission checks will be in the context of this
// process rather than the caller's process. We will restore this before returning.
final long identityToken = clearCallingIdentity();
@@ -173,7 +176,7 @@
if (mSyncManager == null) {
pw.println("No SyncManager created! (Disk full?)");
} else {
- mSyncManager.dump(fd, pw);
+ mSyncManager.dump(fd, pw, dumpAll);
}
pw.println();
pw.println("Observer tree:");
@@ -603,7 +606,7 @@
SyncStorageEngine.EndPoint info;
info = new SyncStorageEngine.EndPoint(account, authority, userId);
syncManager.clearScheduledSyncOperations(info);
- syncManager.cancelActiveSync(info, null /* all syncs for this adapter */);
+ syncManager.cancelActiveSync(info, null /* all syncs for this adapter */, "API");
}
} finally {
restoreCallingIdentity(identityToken);
@@ -631,7 +634,7 @@
}
// Cancel active syncs and clear pending syncs from the queue.
syncManager.cancelScheduledSyncOperation(info, extras);
- syncManager.cancelActiveSync(info, extras);
+ syncManager.cancelActiveSync(info, extras, "API");
} finally {
restoreCallingIdentity(identityToken);
}
diff --git a/services/core/java/com/android/server/content/SyncJobService.java b/services/core/java/com/android/server/content/SyncJobService.java
index a621d73..1f02ebf 100644
--- a/services/core/java/com/android/server/content/SyncJobService.java
+++ b/services/core/java/com/android/server/content/SyncJobService.java
@@ -34,6 +34,8 @@
private Messenger mMessenger;
private SparseArray<JobParameters> jobParamsMap = new SparseArray<JobParameters>();
+ private final SyncLogger mLogger = SyncLogger.getInstance();
+
/**
* This service is started by the SyncManager which passes a messenger object to
* communicate back with it. It never stops while the device is running.
@@ -63,6 +65,9 @@
@Override
public boolean onStartJob(JobParameters params) {
+
+ mLogger.purgeOldLogs();
+
boolean isLoggable = Log.isLoggable(TAG, Log.VERBOSE);
synchronized (jobParamsMap) {
jobParamsMap.put(params.getJobId(), params);
@@ -70,6 +75,9 @@
Message m = Message.obtain();
m.what = SyncManager.SyncHandler.MESSAGE_START_SYNC;
SyncOperation op = SyncOperation.maybeCreateFromJobExtras(params.getExtras());
+
+ mLogger.log("onStopJob() jobid=", params.getJobId(), " op=", op);
+
if (op == null) {
Slog.e(TAG, "Got invalid job " + params.getJobId());
return false;
@@ -88,7 +96,7 @@
Slog.v(TAG, "onStopJob called " + params.getJobId() + ", reason: "
+ params.getStopReason());
}
-
+ mLogger.log("onStopJob() ", mLogger.jobParametersToString(params));
synchronized (jobParamsMap) {
jobParamsMap.remove(params.getJobId());
}
@@ -108,9 +116,13 @@
return false;
}
- public void callJobFinished(int jobId, boolean needsReschedule) {
+ public void callJobFinished(int jobId, boolean needsReschedule, String why) {
synchronized (jobParamsMap) {
JobParameters params = jobParamsMap.get(jobId);
+ mLogger.log("callJobFinished()",
+ " needsReschedule=", needsReschedule,
+ " ", mLogger.jobParametersToString(params),
+ " why=", why);
if (params != null) {
jobFinished(params, needsReschedule);
jobParamsMap.remove(jobId);
diff --git a/services/core/java/com/android/server/content/SyncLogger.java b/services/core/java/com/android/server/content/SyncLogger.java
new file mode 100644
index 0000000..db79464
--- /dev/null
+++ b/services/core/java/com/android/server/content/SyncLogger.java
@@ -0,0 +1,252 @@
+/*
+ * 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.app.job.JobParameters;
+import android.os.Build;
+import android.os.Environment;
+import android.os.FileUtils;
+import android.os.SystemProperties;
+import android.text.format.DateUtils;
+import android.util.Slog;
+
+import com.android.internal.annotations.GuardedBy;
+
+import libcore.io.IoUtils;
+
+import java.io.BufferedReader;
+import java.io.File;
+import java.io.FileReader;
+import java.io.FileWriter;
+import java.io.IOException;
+import java.io.PrintWriter;
+import java.io.Reader;
+import java.io.Writer;
+import java.text.SimpleDateFormat;
+import java.util.Arrays;
+import java.util.Date;
+import java.util.concurrent.TimeUnit;
+
+/**
+ * Implements a rotating file logger for the sync manager, which is enabled only on userdebug/eng
+ * builds (unless debug.synclog is set to 1).
+ *
+ * Note this class could be used for other purposes too, but in general we don't want various
+ * system components to log to files, so it's put in a local package here.
+ */
+public class SyncLogger {
+ private static final String TAG = "SyncLogger";
+
+ private static SyncLogger sInstance;
+
+ SyncLogger() {
+ }
+
+ /**
+ * @return the singleton instance.
+ */
+ public static synchronized SyncLogger getInstance() {
+ if (sInstance == null) {
+ final boolean enable = "1".equals(SystemProperties.get("debug.synclog",
+ Build.IS_DEBUGGABLE ? "1" : "0"));
+ if (enable) {
+ sInstance = new RotatingFileLogger();
+ } else {
+ sInstance = new SyncLogger();
+ }
+ }
+ return sInstance;
+ }
+
+ /**
+ * Write strings to the log file.
+ */
+ public void log(Object... message) {
+ }
+
+ /**
+ * Remove old log files.
+ */
+ public void purgeOldLogs() {
+ // The default implementation is no-op.
+ }
+
+ public String jobParametersToString(JobParameters params) {
+ // The default implementation is no-op.
+ return "";
+ }
+
+ /**
+ * Dump all existing log files into a given writer.
+ */
+ public void dumpAll(PrintWriter pw) {
+ }
+
+ /**
+ * Actual implementation which is only used on userdebug/eng builds (by default).
+ */
+ private static class RotatingFileLogger extends SyncLogger {
+ private final Object mLock = new Object();
+
+ private final long mKeepAgeMs = TimeUnit.DAYS.toMillis(7);
+
+ private static final SimpleDateFormat sTimestampFormat
+ = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS");
+
+ private static final SimpleDateFormat sFilenameDateFormat
+ = new SimpleDateFormat("yyyy-MM-dd");
+
+ @GuardedBy("mLock")
+ private final Date mCachedDate = new Date();
+
+ @GuardedBy("mLock")
+ private final StringBuilder mStringBuilder = new StringBuilder();
+
+ private final File mLogPath;
+
+ @GuardedBy("mLock")
+ private long mCurrentLogFileDayTimestamp;
+
+ @GuardedBy("mLock")
+ private Writer mLogWriter;
+
+ @GuardedBy("mLock")
+ private boolean mErrorShown;
+
+ RotatingFileLogger() {
+ mLogPath = new File(Environment.getDataSystemDirectory(), "syncmanager-log");
+ }
+
+ private void handleException(String message, Exception e) {
+ if (!mErrorShown) {
+ Slog.e(TAG, message, e);
+ mErrorShown = true;
+ }
+ }
+
+ @Override
+ public void log(Object... message) {
+ if (message == null) {
+ return;
+ }
+ synchronized (mLock) {
+ final long now = System.currentTimeMillis();
+ openLogLocked(now);
+ if (mLogWriter == null) {
+ return; // Couldn't open log file?
+ }
+
+ mStringBuilder.setLength(0);
+ mCachedDate.setTime(now);
+ mStringBuilder.append(sTimestampFormat.format(mCachedDate));
+ mStringBuilder.append(' ');
+
+ mStringBuilder.append(android.os.Process.myTid());
+ mStringBuilder.append(' ');
+
+ for (Object o : message) {
+ mStringBuilder.append(o);
+ }
+ mStringBuilder.append('\n');
+
+ try {
+ mLogWriter.append(mStringBuilder);
+ mLogWriter.flush();
+ } catch (IOException e) {
+ handleException("Failed to write log", e);
+ }
+ }
+ }
+
+ private void openLogLocked(long now) {
+ // If we already have a log file opened and the date has't changed, just use it.
+ final long day = now % DateUtils.DAY_IN_MILLIS;
+ if ((mLogWriter != null) && (day == mCurrentLogFileDayTimestamp)) {
+ return;
+ }
+
+ // Otherwise create a new log file.
+ closeCurrentLogLocked();
+
+ mCurrentLogFileDayTimestamp = day;
+
+ mCachedDate.setTime(now);
+ final String filename = "synclog-" + sFilenameDateFormat.format(mCachedDate) + ".log";
+ final File file = new File(mLogPath, filename);
+
+ file.getParentFile().mkdirs();
+
+ try {
+ mLogWriter = new FileWriter(file, /* append= */ true);
+ } catch (IOException e) {
+ handleException("Failed to open log file: " + file, e);
+ }
+ }
+
+ private void closeCurrentLogLocked() {
+ IoUtils.closeQuietly(mLogWriter);
+ mLogWriter = null;
+ }
+
+ @Override
+ public void purgeOldLogs() {
+ synchronized (mLock) {
+ FileUtils.deleteOlderFiles(mLogPath, /* keepCount= */ 1, mKeepAgeMs);
+ }
+ }
+
+ @Override
+ public String jobParametersToString(JobParameters params) {
+ if (params == null) {
+ return "job:null";
+ } else {
+ return "job:#" + params.getJobId() + ":"
+ + SyncOperation.maybeCreateFromJobExtras(params.getExtras());
+ }
+ }
+
+ @Override
+ public void dumpAll(PrintWriter pw) {
+ synchronized (mLock) {
+ final String[] files = mLogPath.list();
+ if (files == null || (files.length == 0)) {
+ return;
+ }
+ Arrays.sort(files);
+
+ for (String file : files) {
+ dumpFile(pw, new File(mLogPath, file));
+ }
+ }
+ }
+
+ private void dumpFile(PrintWriter pw, File file) {
+ Slog.w(TAG, "Dumping " + file);
+ final char[] buffer = new char[32 * 1024];
+
+ try (Reader in = new BufferedReader(new FileReader(file))) {
+ int read;
+ while ((read = in.read(buffer)) >= 0) {
+ if (read > 0) {
+ pw.write(buffer, 0, read);
+ }
+ }
+ } catch (IOException e) {
+ }
+ }
+ }
+}
diff --git a/services/core/java/com/android/server/content/SyncManager.java b/services/core/java/com/android/server/content/SyncManager.java
index e3e2658..3559142 100644
--- a/services/core/java/com/android/server/content/SyncManager.java
+++ b/services/core/java/com/android/server/content/SyncManager.java
@@ -241,6 +241,8 @@
private final Random mRand;
+ private final SyncLogger mLogger;
+
private boolean isJobIdInUseLockedH(int jobId, List<JobInfo> pendingJobs) {
for (JobInfo job: pendingJobs) {
if (job.getId() == jobId) {
@@ -289,13 +291,15 @@
mStorageIsLow = true;
cancelActiveSync(
SyncStorageEngine.EndPoint.USER_ALL_PROVIDER_ALL_ACCOUNTS_ALL,
- null /* any sync */);
+ null /* any sync */,
+ "storage low");
} else if (Intent.ACTION_DEVICE_STORAGE_OK.equals(action)) {
if (Log.isLoggable(TAG, Log.VERBOSE)) {
Slog.v(TAG, "Internal storage is ok.");
}
mStorageIsLow = false;
- rescheduleSyncs(EndPoint.USER_ALL_PROVIDER_ALL_ACCOUNTS_ALL);
+ rescheduleSyncs(EndPoint.USER_ALL_PROVIDER_ALL_ACCOUNTS_ALL,
+ "storage ok");
}
}
};
@@ -378,15 +382,16 @@
if (Log.isLoggable(TAG, Log.VERBOSE)) {
Slog.v(TAG, "Reconnection detected: clearing all backoffs");
}
+ // Note the location of this code was wrong from nyc to oc; fixed in DR.
+ clearAllBackoffs("network reconnect");
}
- clearAllBackoffs();
}
}
};
- private void clearAllBackoffs() {
+ private void clearAllBackoffs(String why) {
mSyncStorageEngine.clearAllBackoffsLocked();
- rescheduleSyncs(EndPoint.USER_ALL_PROVIDER_ALL_ACCOUNTS_ALL);
+ rescheduleSyncs(EndPoint.USER_ALL_PROVIDER_ALL_ACCOUNTS_ALL, why);
}
private boolean readDataConnectionState() {
@@ -502,6 +507,8 @@
// and creating threads and so on; it may fail if the disk is full.
mContext = context;
+ mLogger = SyncLogger.getInstance();
+
SyncStorageEngine.init(context);
mSyncStorageEngine = SyncStorageEngine.getSingleton();
mSyncStorageEngine.setOnSyncRequestListener(new OnSyncRequestListener() {
@@ -1145,8 +1152,12 @@
mSyncHandler.sendMessage(msg);
}
- private void sendCancelSyncsMessage(final SyncStorageEngine.EndPoint info, Bundle extras) {
+ private void sendCancelSyncsMessage(final SyncStorageEngine.EndPoint info, Bundle extras,
+ String why) {
if (Log.isLoggable(TAG, Log.VERBOSE)) Slog.v(TAG, "sending MESSAGE_CANCEL");
+
+ mLogger.log("sendCancelSyncsMessage() ep=", info, " why=", why);
+
Message msg = mSyncHandler.obtainMessage();
msg.what = SyncHandler.MESSAGE_CANCEL;
msg.setData(extras);
@@ -1227,7 +1238,7 @@
}
}
- private void clearBackoffSetting(EndPoint target) {
+ private void clearBackoffSetting(EndPoint target, String why) {
Pair<Long, Long> backoff = mSyncStorageEngine.getBackoff(target);
if (backoff != null && backoff.first == SyncStorageEngine.NOT_IN_BACKOFF_MODE &&
backoff.second == SyncStorageEngine.NOT_IN_BACKOFF_MODE) {
@@ -1240,7 +1251,7 @@
SyncStorageEngine.NOT_IN_BACKOFF_MODE,
SyncStorageEngine.NOT_IN_BACKOFF_MODE);
- rescheduleSyncs(target);
+ rescheduleSyncs(target, why);
}
private void increaseBackoffSetting(EndPoint target) {
@@ -1281,14 +1292,16 @@
Slog.v(TAG, "Backoff until: " + backoff + ", delayTime: " + newDelayInMs);
}
mSyncStorageEngine.setBackoff(target, backoff, newDelayInMs);
- rescheduleSyncs(target);
+ rescheduleSyncs(target, "increaseBackoffSetting");
}
/**
* Reschedule all scheduled syncs for this EndPoint. The syncs will be scheduled according
* to current backoff and delayUntil values of this EndPoint.
*/
- private void rescheduleSyncs(EndPoint target) {
+ private void rescheduleSyncs(EndPoint target, String why) {
+ mLogger.log("rescheduleSyncs() ep=", target, " why=", why);
+
List<SyncOperation> ops = getAllPendingSyncs();
int count = 0;
for (SyncOperation op: ops) {
@@ -1316,7 +1329,7 @@
if (Log.isLoggable(TAG, Log.VERBOSE)) {
Slog.v(TAG, "Delay Until time set to " + newDelayUntilTime + " for " + target);
}
- rescheduleSyncs(target);
+ rescheduleSyncs(target, "delayUntil newDelayUntilTime: " + newDelayUntilTime);
}
private boolean isAdapterDelayed(EndPoint target) {
@@ -1338,8 +1351,8 @@
* have null account/provider info to specify all accounts/providers.
* @param extras if non-null, specifies the exact sync to remove.
*/
- public void cancelActiveSync(SyncStorageEngine.EndPoint info, Bundle extras) {
- sendCancelSyncsMessage(info, extras);
+ public void cancelActiveSync(SyncStorageEngine.EndPoint info, Bundle extras, String why) {
+ sendCancelSyncsMessage(info, extras, why);
}
/**
@@ -1599,7 +1612,8 @@
null /* any account */,
null /* any authority */,
userId),
- null /* any sync. */
+ null /* any sync. */,
+ "onUserStopped"
);
}
@@ -1759,10 +1773,15 @@
}
}
- protected void dump(FileDescriptor fd, PrintWriter pw) {
+ protected void dump(FileDescriptor fd, PrintWriter pw, boolean dumpAll) {
final IndentingPrintWriter ipw = new IndentingPrintWriter(pw, " ");
dumpSyncState(ipw);
dumpSyncAdapters(ipw);
+
+ if (dumpAll) {
+ ipw.println("Detailed Sync History");
+ mLogger.dumpAll(pw);
+ }
}
static String formatTime(long time) {
@@ -2644,7 +2663,7 @@
Log.d(TAG, "handleSyncHandlerMessage: MESSAGE_CANCEL: "
+ endpoint + " bundle: " + extras);
}
- cancelActiveSyncH(endpoint, extras);
+ cancelActiveSyncH(endpoint, extras, "MESSAGE_CANCEL");
break;
case SyncHandler.MESSAGE_SYNC_FINISHED:
@@ -2660,7 +2679,8 @@
Slog.v(TAG, "syncFinished" + payload.activeSyncContext.mSyncOperation);
}
mSyncJobService.callJobFinished(
- payload.activeSyncContext.mSyncOperation.jobId, false);
+ payload.activeSyncContext.mSyncOperation.jobId, false,
+ "sync finished");
runSyncFinishedOrCanceledH(payload.syncResult,
payload.activeSyncContext);
break;
@@ -2704,7 +2724,8 @@
SyncResult syncResult = new SyncResult();
syncResult.stats.numIoExceptions++;
mSyncJobService.callJobFinished(
- currentSyncContext.mSyncOperation.jobId, false);
+ currentSyncContext.mSyncOperation.jobId, false,
+ "service disconnected");
runSyncFinishedOrCanceledH(syncResult, currentSyncContext);
}
break;
@@ -2722,7 +2743,8 @@
"Detected sync making no progress for %s. cancelling.",
monitoredSyncContext));
mSyncJobService.callJobFinished(
- monitoredSyncContext.mSyncOperation.jobId, false);
+ monitoredSyncContext.mSyncOperation.jobId, false,
+ "no network activity");
runSyncFinishedOrCanceledH(
null /* cancel => no result */, monitoredSyncContext);
} else {
@@ -2754,8 +2776,10 @@
* delay. This is equivalent to a failure. If this is a periodic sync, a delayed one-off
* sync will be scheduled.
*/
- private void deferSyncH(SyncOperation op, long delay) {
- mSyncJobService.callJobFinished(op.jobId, false);
+ private void deferSyncH(SyncOperation op, long delay, String why) {
+ mLogger.log("deferSyncH() ", (op.isPeriodic ? "periodic " : ""),
+ "sync. op=", op, " delay=", delay, " why=", why);
+ mSyncJobService.callJobFinished(op.jobId, false, why);
if (op.isPeriodic) {
scheduleSyncOperationH(op.createOneTimeSyncOperation(), delay);
} else {
@@ -2779,10 +2803,10 @@
/**
* Cancel an active sync and reschedule it on the JobScheduler with some delay.
*/
- private void deferActiveSyncH(ActiveSyncContext asc) {
+ private void deferActiveSyncH(ActiveSyncContext asc, String why) {
SyncOperation op = asc.mSyncOperation;
runSyncFinishedOrCanceledH(null, asc);
- deferSyncH(op, SYNC_DELAY_ON_CONFLICT);
+ deferSyncH(op, SYNC_DELAY_ON_CONFLICT, why);
}
private void startSyncH(SyncOperation op) {
@@ -2790,7 +2814,7 @@
if (isLoggable) Slog.v(TAG, op.toString());
if (mStorageIsLow) {
- deferSyncH(op, SYNC_DELAY_ON_LOW_STORAGE);
+ deferSyncH(op, SYNC_DELAY_ON_LOW_STORAGE, "storage low");
return;
}
@@ -2800,7 +2824,8 @@
List<SyncOperation> ops = getAllPendingSyncs();
for (SyncOperation syncOperation: ops) {
if (syncOperation.sourcePeriodicId == op.jobId) {
- mSyncJobService.callJobFinished(op.jobId, false);
+ mSyncJobService.callJobFinished(op.jobId, false,
+ "periodic sync, pending");
return;
}
}
@@ -2808,13 +2833,14 @@
// executing according to some backoff criteria.
for (ActiveSyncContext asc: mActiveSyncContexts) {
if (asc.mSyncOperation.sourcePeriodicId == op.jobId) {
- mSyncJobService.callJobFinished(op.jobId, false);
+ mSyncJobService.callJobFinished(op.jobId, false,
+ "periodic sync, already running");
return;
}
}
// Check for adapter delays.
if (isAdapterDelayed(op.target)) {
- deferSyncH(op, 0 /* No minimum delay */);
+ deferSyncH(op, 0 /* No minimum delay */, "backing off");
return;
}
}
@@ -2828,13 +2854,13 @@
if (isLoggable) {
Slog.v(TAG, "Rescheduling sync due to conflict " + op.toString());
}
- deferSyncH(op, SYNC_DELAY_ON_CONFLICT);
+ deferSyncH(op, SYNC_DELAY_ON_CONFLICT, "delay on conflict");
return;
} else {
if (isLoggable) {
Slog.v(TAG, "Pushing back running sync due to a higher priority sync");
}
- deferActiveSyncH(asc);
+ deferActiveSyncH(asc, "preempted");
break;
}
}
@@ -2844,12 +2870,13 @@
switch (syncOpState) {
case SYNC_OP_STATE_INVALID_NO_ACCOUNT_ACCESS:
case SYNC_OP_STATE_INVALID: {
- mSyncJobService.callJobFinished(op.jobId, false);
+ mSyncJobService.callJobFinished(op.jobId, false,
+ "invalid op state: " + syncOpState);
} return;
}
if (!dispatchSyncOperation(op)) {
- mSyncJobService.callJobFinished(op.jobId, false);
+ mSyncJobService.callJobFinished(op.jobId, false, "dispatchSyncOperation() failed");
}
setAuthorityPendingState(op.target);
@@ -3019,7 +3046,8 @@
if (op.sourcePeriodicId == syncOperation.jobId || op.jobId == syncOperation.jobId) {
ActiveSyncContext asc = findActiveSyncContextH(syncOperation.jobId);
if (asc != null) {
- mSyncJobService.callJobFinished(syncOperation.jobId, false);
+ mSyncJobService.callJobFinished(syncOperation.jobId, false,
+ "removePeriodicSyncInternalH");
runSyncFinishedOrCanceledH(null, asc);
}
getJobScheduler().cancel(op.jobId);
@@ -3131,6 +3159,8 @@
final RegisteredServicesCache.ServiceInfo<SyncAdapterType> syncAdapterInfo;
syncAdapterInfo = mSyncAdapters.getServiceInfo(syncAdapterType, info.userId);
if (syncAdapterInfo == null) {
+ mLogger.log("dispatchSyncOperation() failed: no sync adapter info for ",
+ syncAdapterType);
Log.d(TAG, "can't find a sync adapter for " + syncAdapterType
+ ", removing settings for it");
mSyncStorageEngine.removeAuthority(info);
@@ -3151,6 +3181,8 @@
postMonitorSyncProgressMessage(activeSyncContext);
if (!activeSyncContext.bindToSyncAdapter(targetComponent, info.userId)) {
+ mLogger.log("dispatchSyncOperation() failed: bind failed. target: ",
+ targetComponent);
Slog.e(TAG, "Bind attempt failed - target: " + targetComponent);
closeActiveSyncContext(activeSyncContext);
return false;
@@ -3166,16 +3198,25 @@
activeSyncContext.mIsLinkedToDeath = true;
syncAdapter.linkToDeath(activeSyncContext, 0);
+ mLogger.log("Sync start: account=" + syncOperation.target.account,
+ " authority=", syncOperation.target.provider,
+ " reason=", SyncOperation.reasonToString(null, syncOperation.reason),
+ " extras=", SyncOperation.extrasToString(syncOperation.extras));
+
activeSyncContext.mSyncAdapter = ISyncAdapter.Stub.asInterface(syncAdapter);
activeSyncContext.mSyncAdapter
.startSync(activeSyncContext, syncOperation.target.provider,
syncOperation.target.account, syncOperation.extras);
+
+ mLogger.log("Sync finish");
} catch (RemoteException remoteExc) {
+ mLogger.log("Sync failed with RemoteException: ", remoteExc.toString());
Log.d(TAG, "maybeStartNextSync: caught a RemoteException, rescheduling", remoteExc);
closeActiveSyncContext(activeSyncContext);
increaseBackoffSetting(syncOperation.target);
scheduleSyncOperationH(syncOperation);
} catch (RuntimeException exc) {
+ mLogger.log("Sync failed with RuntimeException: ", exc.toString());
closeActiveSyncContext(activeSyncContext);
Slog.e(TAG, "Caught RuntimeException while starting the sync " + syncOperation, exc);
}
@@ -3186,7 +3227,8 @@
* @param info Can have null fields to indicate all the active syncs for that field.
* @param extras Can be null to indicate <strong>all</strong> syncs for the given endpoint.
*/
- private void cancelActiveSyncH(SyncStorageEngine.EndPoint info, Bundle extras) {
+ private void cancelActiveSyncH(SyncStorageEngine.EndPoint info, Bundle extras,
+ String why) {
ArrayList<ActiveSyncContext> activeSyncs =
new ArrayList<ActiveSyncContext>(mActiveSyncContexts);
for (ActiveSyncContext activeSyncContext : activeSyncs) {
@@ -3202,7 +3244,8 @@
false /* no config settings */)) {
continue;
}
- mSyncJobService.callJobFinished(activeSyncContext.mSyncOperation.jobId, false);
+ mSyncJobService.callJobFinished(activeSyncContext.mSyncOperation.jobId, false,
+ why);
runSyncFinishedOrCanceledH(null /* cancel => no result */, activeSyncContext);
}
}
@@ -3250,6 +3293,7 @@
// potentially rescheduling all pending jobs to respect new backoff values.
getJobScheduler().cancel(syncOperation.jobId);
}
+ mLogger.log("runSyncFinishedOrCanceledH() op=", syncOperation, " result=", syncResult);
if (syncResult != null) {
if (isLoggable) {
@@ -3262,7 +3306,7 @@
// TODO: set these correctly when the SyncResult is extended to include it
downstreamActivity = 0;
upstreamActivity = 0;
- clearBackoffSetting(syncOperation.target);
+ clearBackoffSetting(syncOperation.target, "sync success");
// If the operation completes successfully and it was scheduled due to
// a periodic operation failing, we reschedule the periodic operation to
diff --git a/services/core/java/com/android/server/content/SyncOperation.java b/services/core/java/com/android/server/content/SyncOperation.java
index b46426c..7d2cc00 100644
--- a/services/core/java/com/android/server/content/SyncOperation.java
+++ b/services/core/java/com/android/server/content/SyncOperation.java
@@ -237,6 +237,9 @@
* contain a valid sync operation.
*/
static SyncOperation maybeCreateFromJobExtras(PersistableBundle jobExtras) {
+ if (jobExtras == null) {
+ return null;
+ }
String accountName, accountType;
String provider;
int userId, owningUid;
@@ -445,6 +448,10 @@
}
static void extrasToStringBuilder(Bundle bundle, StringBuilder sb) {
+ if (bundle == null) {
+ sb.append("null");
+ return;
+ }
sb.append("[");
for (String key : bundle.keySet()) {
sb.append(key).append("=").append(bundle.get(key)).append(" ");
@@ -452,6 +459,12 @@
sb.append("]");
}
+ static String extrasToString(Bundle bundle) {
+ final StringBuilder sb = new StringBuilder();
+ extrasToStringBuilder(bundle, sb);
+ return sb.toString();
+ }
+
String wakeLockName() {
if (wakeLockName != null) {
return wakeLockName;