Add detailed log around requestSync.
Bug: 113136683
Test: Boot and trigger sync
Change-Id: I6b79696c57fbe80d77dcde85bebe57a1adc3e935
diff --git a/services/core/java/com/android/server/content/ContentService.java b/services/core/java/com/android/server/content/ContentService.java
index c145d646..d8d650b 100644
--- a/services/core/java/com/android/server/content/ContentService.java
+++ b/services/core/java/com/android/server/content/ContentService.java
@@ -385,7 +385,7 @@
@Override
public void notifyChange(Uri uri, IContentObserver observer,
boolean observerWantsSelfNotifications, int flags, int userHandle,
- int targetSdkVersion) {
+ int targetSdkVersion, String callingPackage) {
if (DEBUG) Slog.d(TAG, "Notifying update of " + uri + " for user " + userHandle
+ " from observer " + observer + ", flags " + Integer.toHexString(flags));
@@ -393,11 +393,11 @@
throw new NullPointerException("Uri must not be null");
}
- final int uid = Binder.getCallingUid();
- final int pid = Binder.getCallingPid();
+ final int callingUid = Binder.getCallingUid();
+ final int callingPid = Binder.getCallingPid();
final int callingUserHandle = UserHandle.getCallingUserId();
- userHandle = handleIncomingUser(uri, pid, uid,
+ userHandle = handleIncomingUser(uri, callingPid, callingUid,
Intent.FLAG_GRANT_WRITE_URI_PERMISSION, true, userHandle);
final String msg = LocalServices.getService(ActivityManagerInternal.class)
@@ -410,7 +410,7 @@
// Sigh, we need to quietly let apps targeting older API
// levels notify on non-existent providers.
} else {
- Log.w(TAG, "Ignoring notify for " + uri + " from " + uid + ": " + msg);
+ Log.w(TAG, "Ignoring notify for " + uri + " from " + callingUid + ": " + msg);
return;
}
}
@@ -453,8 +453,10 @@
if ((flags&ContentResolver.NOTIFY_SYNC_TO_NETWORK) != 0) {
SyncManager syncManager = getSyncManager();
if (syncManager != null) {
- syncManager.scheduleLocalSync(null /* all accounts */, callingUserHandle, uid,
- uri.getAuthority(), getSyncExemptionForCaller(uid));
+ syncManager.scheduleLocalSync(null /* all accounts */, callingUserHandle,
+ callingUid,
+ uri.getAuthority(), getSyncExemptionForCaller(callingUid),
+ callingUid, callingPid, callingPackage);
}
}
@@ -477,10 +479,11 @@
}
public void notifyChange(Uri uri, IContentObserver observer,
- boolean observerWantsSelfNotifications, boolean syncToNetwork) {
+ boolean observerWantsSelfNotifications, boolean syncToNetwork,
+ String callingPackage) {
notifyChange(uri, observer, observerWantsSelfNotifications,
syncToNetwork ? ContentResolver.NOTIFY_SYNC_TO_NETWORK : 0,
- UserHandle.getCallingUserId(), Build.VERSION_CODES.CUR_DEVELOPMENT);
+ UserHandle.getCallingUserId(), Build.VERSION_CODES.CUR_DEVELOPMENT, callingPackage);
}
/**
@@ -504,14 +507,16 @@
}
@Override
- public void requestSync(Account account, String authority, Bundle extras) {
+ public void requestSync(Account account, String authority, Bundle extras,
+ String callingPackage) {
Bundle.setDefusable(extras, true);
ContentResolver.validateSyncExtrasBundle(extras);
int userId = UserHandle.getCallingUserId();
- int uId = Binder.getCallingUid();
+ final int callingUid = Binder.getCallingUid();
+ final int callingPid = Binder.getCallingPid();
- validateExtras(uId, extras);
- final int syncExemption = getSyncExemptionAndCleanUpExtrasForCaller(uId, extras);
+ validateExtras(callingUid, extras);
+ final int syncExemption = getSyncExemptionAndCleanUpExtrasForCaller(callingUid, extras);
// 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.
@@ -519,9 +524,9 @@
try {
SyncManager syncManager = getSyncManager();
if (syncManager != null) {
- syncManager.scheduleSync(account, userId, uId, authority, extras,
+ syncManager.scheduleSync(account, userId, callingUid, authority, extras,
SyncStorageEngine.AuthorityInfo.UNDEFINED,
- syncExemption);
+ syncExemption, callingUid, callingPid, callingPackage);
}
} finally {
restoreCallingIdentity(identityToken);
@@ -538,8 +543,8 @@
* @param request The request object. Validation of this object is done by its builder.
*/
@Override
- public void sync(SyncRequest request) {
- syncAsUser(request, UserHandle.getCallingUserId());
+ public void sync(SyncRequest request, String callingPackage) {
+ syncAsUser(request, UserHandle.getCallingUserId(), callingPackage);
}
private long clampPeriod(long period) {
@@ -557,14 +562,15 @@
* INTERACT_ACROSS_USERS_FULL permission.
*/
@Override
- public void syncAsUser(SyncRequest request, int userId) {
+ public void syncAsUser(SyncRequest request, int userId, String callingPackage) {
enforceCrossUserPermission(userId, "no permission to request sync as user: " + userId);
- int callerUid = Binder.getCallingUid();
+ final int callingUid = Binder.getCallingUid();
+ final int callingPid = Binder.getCallingPid();
final Bundle extras = request.getBundle();
- validateExtras(callerUid, extras);
- final int syncExemption = getSyncExemptionAndCleanUpExtrasForCaller(callerUid, extras);
+ validateExtras(callingUid, extras);
+ final int syncExemption = getSyncExemptionAndCleanUpExtrasForCaller(callingUid, extras);
// 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.
@@ -590,9 +596,9 @@
flextime, extras);
} else {
syncManager.scheduleSync(
- request.getAccount(), userId, callerUid, request.getProvider(), extras,
+ request.getAccount(), userId, callingUid, request.getProvider(), extras,
SyncStorageEngine.AuthorityInfo.UNDEFINED,
- syncExemption);
+ syncExemption, callingUid, callingPid, callingPackage);
}
} finally {
restoreCallingIdentity(identityToken);
@@ -781,6 +787,7 @@
enforceCrossUserPermission(userId,
"no permission to modify the sync settings for user " + userId);
final int callingUid = Binder.getCallingUid();
+ final int callingPid = Binder.getCallingPid();
final int syncExemptionFlag = getSyncExemptionForCaller(callingUid);
long identityToken = clearCallingIdentity();
@@ -788,7 +795,7 @@
SyncManager syncManager = getSyncManager();
if (syncManager != null) {
syncManager.getSyncStorageEngine().setSyncAutomatically(account, userId,
- providerName, sync, syncExemptionFlag, callingUid);
+ providerName, sync, syncExemptionFlag, callingUid, callingPid);
}
} finally {
restoreCallingIdentity(identityToken);
@@ -916,6 +923,7 @@
syncable = normalizeSyncable(syncable);
final int callingUid = Binder.getCallingUid();
+ final int callingPid = Binder.getCallingPid();
int userId = UserHandle.getCallingUserId();
long identityToken = clearCallingIdentity();
@@ -923,7 +931,7 @@
SyncManager syncManager = getSyncManager();
if (syncManager != null) {
syncManager.getSyncStorageEngine().setIsSyncable(
- account, userId, providerName, syncable, callingUid);
+ account, userId, providerName, syncable, callingUid, callingPid);
}
} finally {
restoreCallingIdentity(identityToken);
@@ -971,13 +979,14 @@
"no permission to write the sync settings");
final int callingUid = Binder.getCallingUid();
+ final int callingPid = Binder.getCallingPid();
long identityToken = clearCallingIdentity();
try {
SyncManager syncManager = getSyncManager();
if (syncManager != null) {
syncManager.getSyncStorageEngine().setMasterSyncAutomatically(flag, userId,
- getSyncExemptionForCaller(callingUid), callingUid);
+ getSyncExemptionForCaller(callingUid), callingUid, callingPid);
}
} finally {
restoreCallingIdentity(identityToken);
diff --git a/services/core/java/com/android/server/content/SyncManager.java b/services/core/java/com/android/server/content/SyncManager.java
index f4d20b3..8b93e04 100644
--- a/services/core/java/com/android/server/content/SyncManager.java
+++ b/services/core/java/com/android/server/content/SyncManager.java
@@ -584,9 +584,9 @@
mSyncStorageEngine.setOnSyncRequestListener(new OnSyncRequestListener() {
@Override
public void onSyncRequest(SyncStorageEngine.EndPoint info, int reason, Bundle extras,
- @SyncExemption int syncExemptionFlag) {
+ @SyncExemption int syncExemptionFlag, int callingUid, int callingPid) {
scheduleSync(info.account, info.userId, reason, info.provider, extras,
- AuthorityInfo.UNDEFINED, syncExemptionFlag);
+ AuthorityInfo.UNDEFINED, syncExemptionFlag, callingUid, callingPid, null);
}
});
@@ -619,7 +619,8 @@
scheduleSync(null, UserHandle.USER_ALL,
SyncOperation.REASON_SERVICE_CHANGED,
type.authority, null, AuthorityInfo.UNDEFINED,
- ContentResolver.SYNC_EXEMPTION_NONE);
+ ContentResolver.SYNC_EXEMPTION_NONE,
+ Process.myUid(), -1, null);
}
}
}, mSyncHandler);
@@ -666,7 +667,8 @@
scheduleSync(account, UserHandle.getUserId(uid),
SyncOperation.REASON_ACCOUNTS_UPDATED,
null, null, AuthorityInfo.SYNCABLE_NO_ACCOUNT_ACCESS,
- ContentResolver.SYNC_EXEMPTION_NONE);
+ ContentResolver.SYNC_EXEMPTION_NONE,
+ Process.myUid(), -2, null);
}
});
@@ -893,9 +895,11 @@
*/
public void scheduleSync(Account requestedAccount, int userId, int reason,
String requestedAuthority, Bundle extras, int targetSyncState,
- @SyncExemption int syncExemptionFlag) {
+ @SyncExemption int syncExemptionFlag, int callingUid, int callingPid,
+ String callingPackage) {
scheduleSync(requestedAccount, userId, reason, requestedAuthority, extras, targetSyncState,
- 0 /* min delay */, true /* checkIfAccountReady */, syncExemptionFlag);
+ 0 /* min delay */, true /* checkIfAccountReady */, syncExemptionFlag,
+ callingUid, callingPid, callingPackage);
}
/**
@@ -904,18 +908,21 @@
private void scheduleSync(Account requestedAccount, int userId, int reason,
String requestedAuthority, Bundle extras, int targetSyncState,
final long minDelayMillis, boolean checkIfAccountReady,
- @SyncExemption int syncExemptionFlag) {
- final boolean isLoggable = Log.isLoggable(TAG, Log.VERBOSE);
+ @SyncExemption int syncExemptionFlag,
+ int callingUid, int callingPid, String callingPackage) {
if (extras == null) {
extras = new Bundle();
}
- if (isLoggable) {
- Log.d(TAG, "one-time sync for: " + requestedAccount + " " + extras.toString() + " "
- + requestedAuthority
- + " reason=" + reason
- + " checkIfAccountReady=" + checkIfAccountReady
- + " syncExemptionFlag=" + syncExemptionFlag);
- }
+ extras.size(); // Force unpacel.
+ mLogger.log("scheduleSync: account=", requestedAccount,
+ " u", userId,
+ " authority=", requestedAuthority,
+ " reason=", reason,
+ " extras=", extras,
+ " cuid=", callingUid, " cpid=", callingPid, " cpkg=", callingPackage,
+ " mdm=", minDelayMillis,
+ " ciar=", checkIfAccountReady,
+ " sef=", syncExemptionFlag);
AccountAndUser[] accounts = null;
if (requestedAccount != null) {
@@ -934,9 +941,7 @@
}
if (ArrayUtils.isEmpty(accounts)) {
- if (isLoggable) {
- Slog.v(TAG, "scheduleSync: no accounts configured, dropping");
- }
+ mLogger.log("scheduleSync: no accounts configured, dropping");
return;
}
@@ -1007,10 +1012,8 @@
final int owningUid = syncAdapterInfo.uid;
if (isSyncable == AuthorityInfo.SYNCABLE_NO_ACCOUNT_ACCESS) {
- if (isLoggable) {
- Slog.v(TAG, " Not scheduling sync operation: "
+ mLogger.log("scheduleSync: Not scheduling sync operation: "
+ "isSyncable == SYNCABLE_NO_ACCOUNT_ACCESS");
- }
Bundle finalExtras = new Bundle(extras);
String packageName = syncAdapterInfo.componentName.getPackageName();
// If the app did not run and has no account access, done
@@ -1025,7 +1028,8 @@
scheduleSync(account.account, userId, reason, authority,
finalExtras, targetSyncState, minDelayMillis,
true /* checkIfAccountReady */,
- syncExemptionFlag);
+ syncExemptionFlag, callingUid, callingPid,
+ callingPackage);
}
}
));
@@ -1037,7 +1041,7 @@
if (!checkIfAccountReady && isSyncable < 0 && isAlwaysSyncable) {
mSyncStorageEngine.setIsSyncable(
account.account, account.userId, authority, AuthorityInfo.SYNCABLE,
- SyncLogger.CALLING_UID_SELF);
+ callingUid, callingPid);
isSyncable = AuthorityInfo.SYNCABLE;
}
@@ -1056,10 +1060,8 @@
&& mSyncStorageEngine.getSyncAutomatically(account.account,
account.userId, authority));
if (!syncAllowed) {
- if (isLoggable) {
- Log.d(TAG, "scheduleSync: sync of " + account + ", " + authority
- + " is not allowed, dropping request");
- }
+ mLogger.log("scheduleSync: sync of ", account, " ", authority,
+ " is not allowed, dropping request");
continue;
}
SyncStorageEngine.EndPoint info =
@@ -1077,21 +1079,16 @@
sendOnUnsyncableAccount(mContext, syncAdapterInfo, account.userId,
() -> scheduleSync(account.account, account.userId, reason,
authority, finalExtras, targetSyncState, minDelayMillis,
- false, syncExemptionFlag));
+ false, syncExemptionFlag, callingUid, callingPid,
+ callingPackage));
} else {
// Initialisation sync.
Bundle newExtras = new Bundle();
newExtras.putBoolean(ContentResolver.SYNC_EXTRAS_INITIALIZE, true);
- if (isLoggable) {
- Slog.v(TAG, "schedule initialisation Sync:"
- + ", delay until " + delayUntil
- + ", run by " + 0
- + ", flexMillis " + 0
- + ", source " + source
- + ", account " + account
- + ", authority " + authority
- + ", extras " + newExtras);
- }
+
+ mLogger.log("scheduleSync: schedule initialisation sync ",
+ account, " ", authority);
+
postScheduleSyncMessage(
new SyncOperation(account.account, account.userId,
owningUid, owningPackage, reason, source,
@@ -1102,20 +1099,17 @@
}
} else if (targetSyncState == AuthorityInfo.UNDEFINED
|| targetSyncState == isSyncable) {
- if (isLoggable) {
- Slog.v(TAG, "scheduleSync:"
- + " delay until " + delayUntil
- + ", source " + source
- + ", account " + account
- + ", authority " + authority
- + ", extras " + extras);
- }
+ mLogger.log("scheduleSync: scheduling sync ",
+ account, " ", authority);
postScheduleSyncMessage(
new SyncOperation(account.account, account.userId,
owningUid, owningPackage, reason, source,
authority, extras, allowParallelSyncs, syncExemptionFlag),
minDelayMillis
);
+ } else {
+ mLogger.log("scheduleSync: not handling ",
+ account, " ", authority);
}
}
}
@@ -1227,12 +1221,13 @@
* ms to batch syncs.
*/
public void scheduleLocalSync(Account account, int userId, int reason, String authority,
- @SyncExemption int syncExemptionFlag) {
+ @SyncExemption int syncExemptionFlag,
+ int callingUid, int callingPid, String callingPackage) {
final Bundle extras = new Bundle();
extras.putBoolean(ContentResolver.SYNC_EXTRAS_UPLOAD, true);
scheduleSync(account, userId, reason, authority, extras,
AuthorityInfo.UNDEFINED, LOCAL_SYNC_DELAY, true /* checkIfAccountReady */,
- syncExemptionFlag);
+ syncExemptionFlag, callingUid, callingPid, callingPackage);
}
public SyncAdapterType[] getSyncAdapterTypes(int userId) {
@@ -1769,7 +1764,8 @@
mContext.getOpPackageName());
for (Account account : accounts) {
scheduleSync(account, userId, SyncOperation.REASON_USER_START, null, null,
- AuthorityInfo.NOT_INITIALIZED, ContentResolver.SYNC_EXEMPTION_NONE);
+ AuthorityInfo.NOT_INITIALIZED, ContentResolver.SYNC_EXEMPTION_NONE,
+ Process.myUid(), -3, null);
}
}
@@ -3272,7 +3268,7 @@
scheduleSync(syncTargets.account, syncTargets.userId,
SyncOperation.REASON_ACCOUNTS_UPDATED, syncTargets.provider,
null, AuthorityInfo.NOT_INITIALIZED,
- ContentResolver.SYNC_EXEMPTION_NONE);
+ ContentResolver.SYNC_EXEMPTION_NONE, Process.myUid(), -4, null);
}
}
diff --git a/services/core/java/com/android/server/content/SyncStorageEngine.java b/services/core/java/com/android/server/content/SyncStorageEngine.java
index 391e3b0..bfd1791 100644
--- a/services/core/java/com/android/server/content/SyncStorageEngine.java
+++ b/services/core/java/com/android/server/content/SyncStorageEngine.java
@@ -357,7 +357,7 @@
/** Called when a sync is needed on an account(s) due to some change in state. */
public void onSyncRequest(EndPoint info, int reason, Bundle extras,
- @SyncExemption int syncExemptionFlag);
+ @SyncExemption int syncExemptionFlag, int callingUid, int callingPid);
}
interface PeriodicSyncAddedListener {
@@ -669,7 +669,7 @@
}
public void setSyncAutomatically(Account account, int userId, String providerName,
- boolean sync, @SyncExemption int syncExemptionFlag, int callingUid) {
+ boolean sync, @SyncExemption int syncExemptionFlag, int callingUid, int callingPid) {
if (Log.isLoggable(TAG, Log.VERBOSE)) {
Slog.d(TAG, "setSyncAutomatically: " + /* account + */" provider " + providerName
+ ", user " + userId + " -> " + sync);
@@ -678,7 +678,9 @@
" user=", userId,
" authority=", providerName,
" value=", Boolean.toString(sync),
- " callingUid=", callingUid);
+ " cuid=", callingUid,
+ " cpid=", callingPid
+ );
synchronized (mAuthorities) {
AuthorityInfo authority =
getOrCreateAuthorityLocked(
@@ -704,7 +706,7 @@
if (sync) {
requestSync(account, userId, SyncOperation.REASON_SYNC_AUTO, providerName,
new Bundle(),
- syncExemptionFlag);
+ syncExemptionFlag, callingUid, callingPid);
}
reportChange(ContentResolver.SYNC_OBSERVER_TYPE_SETTINGS);
queueBackup();
@@ -736,9 +738,9 @@
}
public void setIsSyncable(Account account, int userId, String providerName, int syncable,
- int callingUid) {
+ int callingUid, int callingPid) {
setSyncableStateForEndPoint(new EndPoint(account, providerName, userId), syncable,
- callingUid);
+ callingUid, callingPid);
}
/**
@@ -747,10 +749,12 @@
* @param target target to set value for.
* @param syncable 0 indicates unsyncable, <0 unknown, >0 is active/syncable.
*/
- private void setSyncableStateForEndPoint(EndPoint target, int syncable, int callingUid) {
+ private void setSyncableStateForEndPoint(EndPoint target, int syncable,
+ int callingUid, int callingPid) {
AuthorityInfo aInfo;
mLogger.log("Set syncable ", target, " value=", Integer.toString(syncable),
- " callingUid=", callingUid);
+ " cuid=", callingUid,
+ " cpid=", callingPid);
synchronized (mAuthorities) {
aInfo = getOrCreateAuthorityLocked(target, -1, false);
if (syncable < AuthorityInfo.NOT_INITIALIZED) {
@@ -770,7 +774,7 @@
}
if (syncable == AuthorityInfo.SYNCABLE) {
requestSync(aInfo, SyncOperation.REASON_IS_SYNCABLE, new Bundle(),
- ContentResolver.SYNC_EXEMPTION_NONE);
+ ContentResolver.SYNC_EXEMPTION_NONE, callingUid, callingPid);
}
reportChange(ContentResolver.SYNC_OBSERVER_TYPE_SETTINGS);
}
@@ -932,9 +936,10 @@
}
public void setMasterSyncAutomatically(boolean flag, int userId,
- @SyncExemption int syncExemptionFlag, int callingUid) {
+ @SyncExemption int syncExemptionFlag, int callingUid, int callingPid) {
mLogger.log("Set master enabled=", flag, " user=", userId,
- " caller=" + callingUid);
+ " cuid=", callingUid,
+ " cpid=", callingPid);
synchronized (mAuthorities) {
Boolean auto = mMasterSyncAutomatically.get(userId);
if (auto != null && auto.equals(flag)) {
@@ -946,7 +951,7 @@
if (flag) {
requestSync(null, userId, SyncOperation.REASON_MASTER_SYNC_AUTO, null,
new Bundle(),
- syncExemptionFlag);
+ syncExemptionFlag, callingUid, callingPid);
}
reportChange(ContentResolver.SYNC_OBSERVER_TYPE_SETTINGS);
mContext.sendBroadcast(ContentResolver.ACTION_SYNC_CONN_STATUS_CHANGED);
@@ -2064,11 +2069,11 @@
}
private void requestSync(AuthorityInfo authorityInfo, int reason, Bundle extras,
- @SyncExemption int syncExemptionFlag) {
+ @SyncExemption int syncExemptionFlag, int callingUid, int callingPid) {
if (android.os.Process.myUid() == android.os.Process.SYSTEM_UID
&& mSyncRequestListener != null) {
mSyncRequestListener.onSyncRequest(authorityInfo.target, reason, extras,
- syncExemptionFlag);
+ syncExemptionFlag, callingUid, callingPid);
} else {
SyncRequest.Builder req =
new SyncRequest.Builder()
@@ -2080,7 +2085,7 @@
}
private void requestSync(Account account, int userId, int reason, String authority,
- Bundle extras, @SyncExemption int syncExemptionFlag) {
+ Bundle extras, @SyncExemption int syncExemptionFlag, int callingUid, int callingPid) {
// If this is happening in the system process, then call the syncrequest listener
// to make a request back to the SyncManager directly.
// If this is probably a test instance, then call back through the ContentResolver
@@ -2089,7 +2094,7 @@
&& mSyncRequestListener != null) {
mSyncRequestListener.onSyncRequest(
new EndPoint(account, authority, userId),
- reason, extras, syncExemptionFlag);
+ reason, extras, syncExemptionFlag, callingUid, callingPid);
} else {
ContentResolver.requestSync(account, authority, extras);
}