Don't unbind from the sync adapter before cancelSync().
- Also remove the unused method from ISyncAdapter.aidl
Bug: 63773598
Test: Manual test
Change-Id: Ifb2fc520759e83ad961032f9e217100e038e1a8c
diff --git a/core/java/android/content/AbstractThreadedSyncAdapter.java b/core/java/android/content/AbstractThreadedSyncAdapter.java
index 58bd5cd..2629929 100644
--- a/core/java/android/content/AbstractThreadedSyncAdapter.java
+++ b/core/java/android/content/AbstractThreadedSyncAdapter.java
@@ -17,11 +17,12 @@
package android.content;
import android.accounts.Account;
+import android.os.Build;
import android.os.Bundle;
import android.os.IBinder;
import android.os.Process;
-import android.os.RemoteException;
import android.os.Trace;
+import android.util.Log;
import java.util.HashMap;
import java.util.concurrent.atomic.AtomicInteger;
@@ -95,6 +96,8 @@
* </ul>
*/
public abstract class AbstractThreadedSyncAdapter {
+ private static final String TAG = "SyncAdapter";
+
/**
* Kernel event log tag. Also listed in data/etc/event-log-tags.
* @deprecated Private constant. May go away in the next release.
@@ -102,6 +105,8 @@
@Deprecated
public static final int LOG_SYNC_DETAILS = 2743;
+ private static final boolean ENABLE_LOG = Build.IS_DEBUGGABLE && Log.isLoggable(TAG, Log.DEBUG);
+
private final Context mContext;
private final AtomicInteger mNumSyncStarts;
private final ISyncAdapterImpl mISyncAdapterImpl;
@@ -163,71 +168,104 @@
@Override
public void startSync(ISyncContext syncContext, String authority, Account account,
Bundle extras) {
- final SyncContext syncContextClient = new SyncContext(syncContext);
-
- boolean alreadyInProgress;
- // synchronize to make sure that mSyncThreads doesn't change between when we
- // check it and when we use it
- final Account threadsKey = toSyncKey(account);
- synchronized (mSyncThreadLock) {
- if (!mSyncThreads.containsKey(threadsKey)) {
- if (mAutoInitialize
- && extras != null
- && extras.getBoolean(ContentResolver.SYNC_EXTRAS_INITIALIZE, false)) {
- try {
- if (ContentResolver.getIsSyncable(account, authority) < 0) {
- ContentResolver.setIsSyncable(account, authority, 1);
- }
- } finally {
- syncContextClient.onFinished(new SyncResult());
- }
- return;
- }
- SyncThread syncThread = new SyncThread(
- "SyncAdapterThread-" + mNumSyncStarts.incrementAndGet(),
- syncContextClient, authority, account, extras);
- mSyncThreads.put(threadsKey, syncThread);
- syncThread.start();
- alreadyInProgress = false;
- } else {
- alreadyInProgress = true;
+ if (ENABLE_LOG) {
+ if (extras != null) {
+ extras.size(); // Unparcel so its toString() will show the contents.
}
+ Log.d(TAG, "startSync() start " + authority + " " + account + " " + extras);
}
+ try {
+ final SyncContext syncContextClient = new SyncContext(syncContext);
- // do this outside since we don't want to call back into the syncContext while
- // holding the synchronization lock
- if (alreadyInProgress) {
- syncContextClient.onFinished(SyncResult.ALREADY_IN_PROGRESS);
+ boolean alreadyInProgress;
+ // synchronize to make sure that mSyncThreads doesn't change between when we
+ // check it and when we use it
+ final Account threadsKey = toSyncKey(account);
+ synchronized (mSyncThreadLock) {
+ if (!mSyncThreads.containsKey(threadsKey)) {
+ if (mAutoInitialize
+ && extras != null
+ && extras.getBoolean(
+ ContentResolver.SYNC_EXTRAS_INITIALIZE, false)) {
+ try {
+ if (ContentResolver.getIsSyncable(account, authority) < 0) {
+ ContentResolver.setIsSyncable(account, authority, 1);
+ }
+ } finally {
+ syncContextClient.onFinished(new SyncResult());
+ }
+ return;
+ }
+ SyncThread syncThread = new SyncThread(
+ "SyncAdapterThread-" + mNumSyncStarts.incrementAndGet(),
+ syncContextClient, authority, account, extras);
+ mSyncThreads.put(threadsKey, syncThread);
+ syncThread.start();
+ alreadyInProgress = false;
+ } else {
+ if (ENABLE_LOG) {
+ Log.d(TAG, " alreadyInProgress");
+ }
+ alreadyInProgress = true;
+ }
+ }
+
+ // do this outside since we don't want to call back into the syncContext while
+ // holding the synchronization lock
+ if (alreadyInProgress) {
+ syncContextClient.onFinished(SyncResult.ALREADY_IN_PROGRESS);
+ }
+ } catch (RuntimeException | Error th) {
+ if (ENABLE_LOG) {
+ Log.d(TAG, "startSync() caught exception", th);
+ }
+ throw th;
+ } finally {
+ if (ENABLE_LOG) {
+ Log.d(TAG, "startSync() finishing");
+ }
}
}
@Override
public void cancelSync(ISyncContext syncContext) {
- // synchronize to make sure that mSyncThreads doesn't change between when we
- // check it and when we use it
- SyncThread info = null;
- synchronized (mSyncThreadLock) {
- for (SyncThread current : mSyncThreads.values()) {
- if (current.mSyncContext.getSyncContextBinder() == syncContext.asBinder()) {
- info = current;
- break;
+ try {
+ // synchronize to make sure that mSyncThreads doesn't change between when we
+ // check it and when we use it
+ SyncThread info = null;
+ synchronized (mSyncThreadLock) {
+ for (SyncThread current : mSyncThreads.values()) {
+ if (current.mSyncContext.getSyncContextBinder() == syncContext.asBinder()) {
+ info = current;
+ break;
+ }
}
}
- }
- if (info != null) {
- if (mAllowParallelSyncs) {
- onSyncCanceled(info);
+ if (info != null) {
+ if (ENABLE_LOG) {
+ Log.d(TAG, "cancelSync() " + info.mAuthority + " " + info.mAccount);
+ }
+ if (mAllowParallelSyncs) {
+ onSyncCanceled(info);
+ } else {
+ onSyncCanceled();
+ }
} else {
- onSyncCanceled();
+ if (ENABLE_LOG) {
+ Log.w(TAG, "cancelSync() unknown context");
+ }
+ }
+ } catch (RuntimeException | Error th) {
+ if (ENABLE_LOG) {
+ Log.d(TAG, "cancelSync() caught exception", th);
+ }
+ throw th;
+ } finally {
+ if (ENABLE_LOG) {
+ Log.d(TAG, "cancelSync() finishing");
}
}
}
-
- public void initialize(Account account, String authority) throws RemoteException {
- Bundle extras = new Bundle();
- extras.putBoolean(ContentResolver.SYNC_EXTRAS_INITIALIZE, true);
- startSync(null, authority, account, extras);
- }
}
/**
@@ -256,6 +294,10 @@
public void run() {
Process.setThreadPriority(Process.THREAD_PRIORITY_BACKGROUND);
+ if (ENABLE_LOG) {
+ Log.d(TAG, "Thread started");
+ }
+
// Trace this sync instance. Note, conceptually this should be in
// SyncStorageEngine.insertStartSyncEvent(), but the trace functions require unique
// threads in order to track overlapping operations, so we'll do it here for now.
@@ -265,8 +307,15 @@
ContentProviderClient provider = null;
try {
if (isCanceled()) {
+ if (ENABLE_LOG) {
+ Log.d(TAG, "Already canceled");
+ }
return;
}
+ if (ENABLE_LOG) {
+ Log.d(TAG, "Calling onPerformSync...");
+ }
+
provider = mContext.getContentResolver().acquireContentProviderClient(mAuthority);
if (provider != null) {
AbstractThreadedSyncAdapter.this.onPerformSync(mAccount, mExtras,
@@ -274,10 +323,23 @@
} else {
syncResult.databaseError = true;
}
+
+ if (ENABLE_LOG) {
+ Log.d(TAG, "onPerformSync done");
+ }
+
} catch (SecurityException e) {
+ if (ENABLE_LOG) {
+ Log.d(TAG, "SecurityException", e);
+ }
AbstractThreadedSyncAdapter.this.onSecurityException(mAccount, mExtras,
mAuthority, syncResult);
syncResult.databaseError = true;
+ } catch (RuntimeException | Error th) {
+ if (ENABLE_LOG) {
+ Log.d(TAG, "caught exception", th);
+ }
+ throw th;
} finally {
Trace.traceEnd(Trace.TRACE_TAG_SYNC_MANAGER);
@@ -292,6 +354,10 @@
synchronized (mSyncThreadLock) {
mSyncThreads.remove(mThreadsKey);
}
+
+ if (ENABLE_LOG) {
+ Log.d(TAG, "Thread finished");
+ }
}
}
diff --git a/core/java/android/content/ISyncAdapter.aidl b/core/java/android/content/ISyncAdapter.aidl
index dd9d14e..4660527 100644
--- a/core/java/android/content/ISyncAdapter.aidl
+++ b/core/java/android/content/ISyncAdapter.aidl
@@ -44,12 +44,4 @@
* @param syncContext the ISyncContext that was passed to {@link #startSync}
*/
void cancelSync(ISyncContext syncContext);
-
- /**
- * Initialize the SyncAdapter for this account and authority.
- *
- * @param account the account that should be synced
- * @param authority the authority that should be synced
- */
- void initialize(in Account account, String authority);
}
diff --git a/services/core/java/com/android/server/content/SyncLogger.java b/services/core/java/com/android/server/content/SyncLogger.java
index db79464..d93bdc9 100644
--- a/services/core/java/com/android/server/content/SyncLogger.java
+++ b/services/core/java/com/android/server/content/SyncLogger.java
@@ -22,6 +22,7 @@
import android.os.FileUtils;
import android.os.SystemProperties;
import android.text.format.DateUtils;
+import android.util.Log;
import android.util.Slog;
import com.android.internal.annotations.GuardedBy;
@@ -127,6 +128,8 @@
@GuardedBy("mLock")
private boolean mErrorShown;
+ private static final boolean DO_LOGCAT = Log.isLoggable(TAG, Log.DEBUG);
+
RotatingFileLogger() {
mLogPath = new File(Environment.getDataSystemDirectory(), "syncmanager-log");
}
@@ -158,6 +161,8 @@
mStringBuilder.append(android.os.Process.myTid());
mStringBuilder.append(' ');
+ final int messageStart = mStringBuilder.length();
+
for (Object o : message) {
mStringBuilder.append(o);
}
@@ -166,6 +171,11 @@
try {
mLogWriter.append(mStringBuilder);
mLogWriter.flush();
+
+ // Also write on logcat.
+ if (DO_LOGCAT) {
+ Log.d(TAG, mStringBuilder.substring(messageStart));
+ }
} catch (IOException e) {
handleException("Failed to write log", e);
}
diff --git a/services/core/java/com/android/server/content/SyncManager.java b/services/core/java/com/android/server/content/SyncManager.java
index c250005..3e05d50 100644
--- a/services/core/java/com/android/server/content/SyncManager.java
+++ b/services/core/java/com/android/server/content/SyncManager.java
@@ -1704,6 +1704,8 @@
// Include "this" in the message so that the handler can ignore it if this
// ActiveSyncContext is no longer the mActiveSyncContext at message handling
// time.
+ mLogger.log("onFinished result=", result, " endpoint=",
+ (mSyncOperation == null ? "null" : mSyncOperation.target));
sendSyncFinishedOrCanceledMessage(this, result);
}
@@ -1745,6 +1747,7 @@
Context.BIND_AUTO_CREATE | Context.BIND_NOT_FOREGROUND
| Context.BIND_ALLOW_OOM_MANAGEMENT,
new UserHandle(mSyncOperation.target.userId));
+ mLogger.log("bindService() returned=", mBound, " for ", this);
if (!bindResult) {
mBound = false;
} else {
@@ -1767,6 +1770,7 @@
}
if (mBound) {
mBound = false;
+ mLogger.log("unbindService for ", this);
mContext.unbindService(this);
try {
mBatteryStats.noteSyncFinish(mEventName, mSyncAdapterUid);
@@ -2729,9 +2733,14 @@
// outstanding
try {
if (currentSyncContext.mSyncAdapter != null) {
+ mLogger.log("Calling cancelSync for SERVICE_DISCONNECTED ",
+ currentSyncContext,
+ " adapter=", currentSyncContext.mSyncAdapter);
currentSyncContext.mSyncAdapter.cancelSync(currentSyncContext);
+ mLogger.log("Canceled");
}
} catch (RemoteException e) {
+ mLogger.log("RemoteException ", Log.getStackTraceString(e));
// We don't need to retry this in this case.
}
@@ -3217,14 +3226,15 @@
mLogger.log("Sync start: account=" + syncOperation.target.account,
" authority=", syncOperation.target.provider,
" reason=", SyncOperation.reasonToString(null, syncOperation.reason),
- " extras=", SyncOperation.extrasToString(syncOperation.extras));
+ " extras=", SyncOperation.extrasToString(syncOperation.extras),
+ " adapter=", activeSyncContext.mSyncAdapter);
activeSyncContext.mSyncAdapter = ISyncAdapter.Stub.asInterface(syncAdapter);
activeSyncContext.mSyncAdapter
.startSync(activeSyncContext, syncOperation.target.provider,
syncOperation.target.account, syncOperation.extras);
- mLogger.log("Sync finish");
+ mLogger.log("Sync is running now...");
} catch (RemoteException remoteExc) {
mLogger.log("Sync failed with RemoteException: ", remoteExc.toString());
Log.d(TAG, "maybeStartNextSync: caught a RemoteException, rescheduling", remoteExc);
@@ -3297,7 +3307,6 @@
activeSyncContext.mSyncAdapter.asBinder().unlinkToDeath(activeSyncContext, 0);
activeSyncContext.mIsLinkedToDeath = false;
}
- closeActiveSyncContext(activeSyncContext);
final long elapsedTime = SystemClock.elapsedRealtime() - activeSyncContext.mStartTime;
String historyMessage;
int downstreamActivity;
@@ -3355,8 +3364,12 @@
}
if (activeSyncContext.mSyncAdapter != null) {
try {
+ mLogger.log("Calling cancelSync for runSyncFinishedOrCanceled ",
+ activeSyncContext, " adapter=", activeSyncContext.mSyncAdapter);
activeSyncContext.mSyncAdapter.cancelSync(activeSyncContext);
+ mLogger.log("Canceled");
} catch (RemoteException e) {
+ mLogger.log("RemoteException ", Log.getStackTraceString(e));
// we don't need to retry this in this case
}
}
@@ -3365,6 +3378,9 @@
upstreamActivity = 0;
}
+ // Close and unbind the service. Don't use activeSyncContext.mSyncAdapter after this.
+ closeActiveSyncContext(activeSyncContext);
+
stopSyncEvent(activeSyncContext.mHistoryRowId, syncOperation, historyMessage,
upstreamActivity, downstreamActivity, elapsedTime);
// Check for full-resync and schedule it after closing off the last sync.