diff options
author | Wale Ogunwale <ogunwale@google.com> | 2015-03-05 18:51:32 +0000 |
---|---|---|
committer | Android (Google) Code Review <android-gerrit@google.com> | 2015-03-05 18:51:33 +0000 |
commit | 47d740b92b631b1f69b63702f5edfc83538345cf (patch) | |
tree | 0095ef1b04932e4559a7fcc79136dabef7fb3e93 /services | |
parent | 35da7d904b4eb6ef215ea57cef35bac31f05defd (diff) | |
parent | d57969f6ec38c7633ca65bcd5bdd766cd972cfe4 (diff) | |
download | frameworks_base-47d740b92b631b1f69b63702f5edfc83538345cf.zip frameworks_base-47d740b92b631b1f69b63702f5edfc83538345cf.tar.gz frameworks_base-47d740b92b631b1f69b63702f5edfc83538345cf.tar.bz2 |
Merge "Made AM package debug log more configurable."
Diffstat (limited to 'services')
5 files changed, 207 insertions, 110 deletions
diff --git a/services/core/java/com/android/server/am/ActiveServices.java b/services/core/java/com/android/server/am/ActiveServices.java index 059dde1..fc95b00 100755 --- a/services/core/java/com/android/server/am/ActiveServices.java +++ b/services/core/java/com/android/server/am/ActiveServices.java @@ -16,6 +16,8 @@ package com.android.server.am; +import static com.android.server.am.ActivityManagerDebugConfig.*; + import java.io.FileDescriptor; import java.io.IOException; import java.io.PrintWriter; @@ -33,6 +35,7 @@ import android.os.Looper; import android.os.SystemProperties; import android.util.ArrayMap; import android.util.ArraySet; + import com.android.internal.app.ProcessStats; import com.android.internal.os.BatteryStatsImpl; import com.android.internal.os.TransferPipe; @@ -67,14 +70,15 @@ import android.util.SparseArray; import android.util.TimeUtils; public final class ActiveServices { - static final boolean DEBUG_SERVICE = ActivityManagerService.DEBUG_SERVICE; - static final boolean DEBUG_SERVICE_EXECUTING = ActivityManagerService.DEBUG_SERVICE_EXECUTING; - static final boolean DEBUG_DELAYED_SERVICE = ActivityManagerService.DEBUG_SERVICE; - static final boolean DEBUG_DELAYED_STARTS = DEBUG_DELAYED_SERVICE; - static final boolean DEBUG_MU = ActivityManagerService.DEBUG_MU; - static final boolean LOG_SERVICE_START_STOP = false; - static final String TAG = ActivityManagerService.TAG; - static final String TAG_MU = ActivityManagerService.TAG_MU; + private static final String TAG = TAG_WITH_CLASS_NAME ? "ActiveServices" : TAG_AM; + private static final String TAG_MU = TAG + POSTFIX_MU; + private static final String TAG_SERVICE = TAG + POSTFIX_SERVICE; + private static final String TAG_SERVICE_EXECUTING = TAG + POSTFIX_SERVICE_EXECUTING; + + private static final boolean DEBUG_DELAYED_SERVICE = DEBUG_SERVICE; + private static final boolean DEBUG_DELAYED_STARTS = DEBUG_DELAYED_SERVICE; + + private static final boolean LOG_SERVICE_START_STOP = false; // How long we wait for a service to finish executing. static final int SERVICE_TIMEOUT = 20*1000; @@ -206,11 +210,12 @@ public final class ActiveServices { void ensureNotStartingBackground(ServiceRecord r) { if (mStartingBackground.remove(r)) { - if (DEBUG_DELAYED_STARTS) Slog.v(TAG, "No longer background starting: " + r); + if (DEBUG_DELAYED_STARTS) Slog.v(TAG_SERVICE, + "No longer background starting: " + r); rescheduleDelayedStarts(); } if (mDelayedStartList.remove(r)) { - if (DEBUG_DELAYED_STARTS) Slog.v(TAG, "No longer delaying start: " + r); + if (DEBUG_DELAYED_STARTS) Slog.v(TAG_SERVICE, "No longer delaying start: " + r); } } @@ -229,16 +234,17 @@ public final class ActiveServices { while (mDelayedStartList.size() > 0 && mStartingBackground.size() < mMaxStartingBackground) { ServiceRecord r = mDelayedStartList.remove(0); - if (DEBUG_DELAYED_STARTS) Slog.v(TAG, "REM FR DELAY LIST (exec next): " + r); + if (DEBUG_DELAYED_STARTS) Slog.v(TAG_SERVICE, + "REM FR DELAY LIST (exec next): " + r); if (r.pendingStarts.size() <= 0) { Slog.w(TAG, "**** NO PENDING STARTS! " + r + " startReq=" + r.startRequested + " delayedStop=" + r.delayedStop); } if (DEBUG_DELAYED_SERVICE) { if (mDelayedStartList.size() > 0) { - Slog.v(TAG, "Remaining delayed list:"); + Slog.v(TAG_SERVICE, "Remaining delayed list:"); for (int i=0; i<mDelayedStartList.size(); i++) { - Slog.v(TAG, " #" + i + ": " + mDelayedStartList.get(i)); + Slog.v(TAG_SERVICE, " #" + i + ": " + mDelayedStartList.get(i)); } } } @@ -248,7 +254,7 @@ public final class ActiveServices { if (mStartingBackground.size() > 0) { ServiceRecord next = mStartingBackground.get(0); long when = next.startingBgTimeout > now ? next.startingBgTimeout : now; - if (DEBUG_DELAYED_SERVICE) Slog.v(TAG, "Top bg start is " + next + if (DEBUG_DELAYED_SERVICE) Slog.v(TAG_SERVICE, "Top bg start is " + next + ", can delay others up to " + when); Message msg = obtainMessage(MSG_BG_START_TIMEOUT); sendMessageAtTime(msg, when); @@ -298,7 +304,7 @@ public final class ActiveServices { ComponentName startServiceLocked(IApplicationThread caller, Intent service, String resolvedType, int callingPid, int callingUid, int userId) { - if (DEBUG_DELAYED_STARTS) Slog.v(TAG, "startService: " + service + if (DEBUG_DELAYED_STARTS) Slog.v(TAG_SERVICE, "startService: " + service + " type=" + resolvedType + " args=" + service.getExtras()); final boolean callerFg; @@ -337,7 +343,7 @@ public final class ActiveServices { NeededUriGrants neededGrants = mAm.checkGrantUriPermissionFromIntentLocked( callingUid, r.packageName, service, service.getFlags(), null, r.userId); if (unscheduleServiceRestartLocked(r, callingUid, false)) { - if (DEBUG_SERVICE) Slog.v(TAG, "START SERVICE WHILE RESTART PENDING: " + r); + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "START SERVICE WHILE RESTART PENDING: " + r); } r.lastActivity = SystemClock.uptimeMillis(); r.startRequested = true; @@ -360,29 +366,30 @@ public final class ActiveServices { // service is started. This is especially the case for receivers, which // may start a service in onReceive() to do some additional work and have // initialized some global state as part of that. - if (DEBUG_DELAYED_SERVICE) Slog.v(TAG, "Potential start delay of " + r + " in " - + proc); + if (DEBUG_DELAYED_SERVICE) Slog.v(TAG_SERVICE, "Potential start delay of " + + r + " in " + proc); if (r.delayed) { // This service is already scheduled for a delayed start; just leave // it still waiting. - if (DEBUG_DELAYED_STARTS) Slog.v(TAG, "Continuing to delay: " + r); + if (DEBUG_DELAYED_STARTS) Slog.v(TAG_SERVICE, "Continuing to delay: " + r); return r.name; } if (smap.mStartingBackground.size() >= mMaxStartingBackground) { // Something else is starting, delay! - Slog.i(TAG, "Delaying start of: " + r); + Slog.i(TAG_SERVICE, "Delaying start of: " + r); smap.mDelayedStartList.add(r); r.delayed = true; return r.name; } - if (DEBUG_DELAYED_STARTS) Slog.v(TAG, "Not delaying: " + r); + if (DEBUG_DELAYED_STARTS) Slog.v(TAG_SERVICE, "Not delaying: " + r); addToStarting = true; } else if (proc.curProcState >= ActivityManager.PROCESS_STATE_SERVICE) { // We slightly loosen when we will enqueue this new service as a background // starting service we are waiting for, to also include processes that are // currently running other services or receivers. addToStarting = true; - if (DEBUG_DELAYED_STARTS) Slog.v(TAG, "Not delaying, but counting as bg: " + r); + if (DEBUG_DELAYED_STARTS) Slog.v(TAG_SERVICE, + "Not delaying, but counting as bg: " + r); } else if (DEBUG_DELAYED_STARTS) { StringBuilder sb = new StringBuilder(128); sb.append("Not potential delay (state=").append(proc.curProcState) @@ -394,16 +401,17 @@ public final class ActiveServices { } sb.append("): "); sb.append(r.toString()); - Slog.v(TAG, sb.toString()); + Slog.v(TAG_SERVICE, sb.toString()); } } else if (DEBUG_DELAYED_STARTS) { if (callerFg) { - Slog.v(TAG, "Not potential delay (callerFg=" + callerFg + " uid=" + Slog.v(TAG_SERVICE, "Not potential delay (callerFg=" + callerFg + " uid=" + callingUid + " pid=" + callingPid + "): " + r); } else if (r.app != null) { - Slog.v(TAG, "Not potential delay (cur app=" + r.app + "): " + r); + Slog.v(TAG_SERVICE, "Not potential delay (cur app=" + r.app + "): " + r); } else { - Slog.v(TAG, "Not potential delay (user " + r.userId + " not started): " + r); + Slog.v(TAG_SERVICE, + "Not potential delay (user " + r.userId + " not started): " + r); } } @@ -432,9 +440,9 @@ public final class ActiveServices { if (DEBUG_DELAYED_SERVICE) { RuntimeException here = new RuntimeException("here"); here.fillInStackTrace(); - Slog.v(TAG, "Starting background (first=" + first + "): " + r, here); + Slog.v(TAG_SERVICE, "Starting background (first=" + first + "): " + r, here); } else if (DEBUG_DELAYED_STARTS) { - Slog.v(TAG, "Starting background (first=" + first + "): " + r); + Slog.v(TAG_SERVICE, "Starting background (first=" + first + "): " + r); } if (first) { smap.rescheduleDelayedStarts(); @@ -451,7 +459,7 @@ public final class ActiveServices { // If service isn't actually running, but is is being held in the // delayed list, then we need to keep it started but note that it // should be stopped once no longer delayed. - if (DEBUG_DELAYED_STARTS) Slog.v(TAG, "Delaying stop of pending: " + service); + if (DEBUG_DELAYED_STARTS) Slog.v(TAG_SERVICE, "Delaying stop of pending: " + service); service.delayedStop = true; return; } @@ -469,7 +477,7 @@ public final class ActiveServices { int stopServiceLocked(IApplicationThread caller, Intent service, String resolvedType, int userId) { - if (DEBUG_SERVICE) Slog.v(TAG, "stopService: " + service + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "stopService: " + service + " type=" + resolvedType); final ProcessRecord callerApp = mAm.getRecordForAppLocked(caller); @@ -525,7 +533,7 @@ public final class ActiveServices { boolean stopServiceTokenLocked(ComponentName className, IBinder token, int startId) { - if (DEBUG_SERVICE) Slog.v(TAG, "stopServiceToken: " + className + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "stopServiceToken: " + className + " " + token + " startId=" + startId); ServiceRecord r = findServiceLocked(className, token, UserHandle.getCallingUserId()); if (r != null) { @@ -687,7 +695,7 @@ public final class ActiveServices { int bindServiceLocked(IApplicationThread caller, IBinder token, Intent service, String resolvedType, IServiceConnection connection, int flags, int userId) { - if (DEBUG_SERVICE) Slog.v(TAG, "bindService: " + service + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "bindService: " + service + " type=" + resolvedType + " conn=" + connection.asBinder() + " flags=0x" + Integer.toHexString(flags)); final ProcessRecord callerApp = mAm.getRecordForAppLocked(caller); @@ -751,7 +759,7 @@ public final class ActiveServices { try { if (unscheduleServiceRestartLocked(s, callerApp.info.uid, false)) { - if (DEBUG_SERVICE) Slog.v(TAG, "BIND SERVICE WHILE RESTART PENDING: " + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "BIND SERVICE WHILE RESTART PENDING: " + s); } @@ -819,7 +827,7 @@ public final class ActiveServices { mAm.updateOomAdjLocked(s.app); } - if (DEBUG_SERVICE) Slog.v(TAG, "Bind " + s + " with " + b + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "Bind " + s + " with " + b + ": received=" + b.intent.received + " apps=" + b.intent.apps.size() + " doRebind=" + b.intent.doRebind); @@ -857,7 +865,7 @@ public final class ActiveServices { void publishServiceLocked(ServiceRecord r, Intent intent, IBinder service) { final long origId = Binder.clearCallingIdentity(); try { - if (DEBUG_SERVICE) Slog.v(TAG, "PUBLISHING " + r + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "PUBLISHING " + r + " " + intent + ": " + service); if (r != null) { Intent.FilterComparison filter @@ -873,14 +881,14 @@ public final class ActiveServices { ConnectionRecord c = clist.get(i); if (!filter.equals(c.binding.intent.intent)) { if (DEBUG_SERVICE) Slog.v( - TAG, "Not publishing to: " + c); + TAG_SERVICE, "Not publishing to: " + c); if (DEBUG_SERVICE) Slog.v( - TAG, "Bound intent: " + c.binding.intent.intent); + TAG_SERVICE, "Bound intent: " + c.binding.intent.intent); if (DEBUG_SERVICE) Slog.v( - TAG, "Published intent: " + intent); + TAG_SERVICE, "Published intent: " + intent); continue; } - if (DEBUG_SERVICE) Slog.v(TAG, "Publishing to: " + c); + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "Publishing to: " + c); try { c.conn.connected(r.name, service); } catch (Exception e) { @@ -901,7 +909,7 @@ public final class ActiveServices { boolean unbindServiceLocked(IServiceConnection connection) { IBinder binder = connection.asBinder(); - if (DEBUG_SERVICE) Slog.v(TAG, "unbindService: conn=" + binder); + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "unbindService: conn=" + binder); ArrayList<ConnectionRecord> clist = mServiceConnections.get(binder); if (clist == null) { Slog.w(TAG, "Unbind failed: could not find connection for " @@ -945,7 +953,7 @@ public final class ActiveServices { Intent.FilterComparison filter = new Intent.FilterComparison(intent); IntentBindRecord b = r.bindings.get(filter); - if (DEBUG_SERVICE) Slog.v(TAG, "unbindFinished in " + r + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "unbindFinished in " + r + " at " + b + ": apps=" + (b != null ? b.apps.size() : 0)); @@ -1012,7 +1020,7 @@ public final class ActiveServices { String resolvedType, int callingPid, int callingUid, int userId, boolean createIfNeeded, boolean callingFromFg) { ServiceRecord r = null; - if (DEBUG_SERVICE) Slog.v(TAG, "retrieveServiceLocked: " + service + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "retrieveServiceLocked: " + service + " type=" + resolvedType + " callingUid=" + callingUid); userId = mAm.handleIncomingUser(callingPid, callingUid, userId, @@ -1036,7 +1044,7 @@ public final class ActiveServices { ServiceInfo sInfo = rInfo != null ? rInfo.serviceInfo : null; if (sInfo == null) { - Slog.w(TAG, "Unable to start service " + service + " U=" + userId + + Slog.w(TAG_SERVICE, "Unable to start service " + service + " U=" + userId + ": not found"); return null; } @@ -1110,9 +1118,9 @@ public final class ActiveServices { } private final void bumpServiceExecutingLocked(ServiceRecord r, boolean fg, String why) { - if (DEBUG_SERVICE) Slog.v(TAG, ">>> EXECUTING " + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, ">>> EXECUTING " + why + " of " + r + " in app " + r.app); - else if (DEBUG_SERVICE_EXECUTING) Slog.v(TAG, ">>> EXECUTING " + else if (DEBUG_SERVICE_EXECUTING) Slog.v(TAG_SERVICE_EXECUTING, ">>> EXECUTING " + why + " of " + r.shortName); long now = SystemClock.uptimeMillis(); if (r.executeNesting == 0) { @@ -1155,7 +1163,7 @@ public final class ActiveServices { i.hasBound = true; i.doRebind = false; } catch (RemoteException e) { - if (DEBUG_SERVICE) Slog.v(TAG, "Crashed while binding " + r); + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "Crashed while binding " + r); return false; } } @@ -1336,7 +1344,7 @@ public final class ActiveServices { return null; } - if (DEBUG_SERVICE) Slog.v(TAG, "Bringing up " + r + " " + r.intent); + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "Bringing up " + r + " " + r.intent); // We are now bringing the service up, so no longer in the // restarting state. @@ -1347,7 +1355,7 @@ public final class ActiveServices { // Make sure this service is no longer considered delayed, we are starting it now. if (r.delayed) { - if (DEBUG_DELAYED_STARTS) Slog.v(TAG, "REM FR DELAY LIST (bring up): " + r); + if (DEBUG_DELAYED_STARTS) Slog.v(TAG_SERVICE, "REM FR DELAY LIST (bring up): " + r); getServiceMap(r.userId).mDelayedStartList.remove(r); r.delayed = false; } @@ -1430,7 +1438,8 @@ public final class ActiveServices { // Oh and hey we've already been asked to stop! r.delayedStop = false; if (r.startRequested) { - if (DEBUG_DELAYED_STARTS) Slog.v(TAG, "Applying delayed stop (in bring up): " + r); + if (DEBUG_DELAYED_STARTS) Slog.v(TAG_SERVICE, + "Applying delayed stop (in bring up): " + r); stopServiceLocked(r); } } @@ -1509,7 +1518,7 @@ public final class ActiveServices { sendServiceArgsLocked(r, execInFg, true); if (r.delayed) { - if (DEBUG_DELAYED_STARTS) Slog.v(TAG, "REM FR DELAY LIST (new proc): " + r); + if (DEBUG_DELAYED_STARTS) Slog.v(TAG_SERVICE, "REM FR DELAY LIST (new proc): " + r); getServiceMap(r.userId).mDelayedStartList.remove(r); r.delayed = false; } @@ -1518,7 +1527,8 @@ public final class ActiveServices { // Oh and hey we've already been asked to stop! r.delayedStop = false; if (r.startRequested) { - if (DEBUG_DELAYED_STARTS) Slog.v(TAG, "Applying delayed stop (from start): " + r); + if (DEBUG_DELAYED_STARTS) Slog.v(TAG_SERVICE, + "Applying delayed stop (from start): " + r); stopServiceLocked(r); } } @@ -1534,7 +1544,7 @@ public final class ActiveServices { while (r.pendingStarts.size() > 0) { try { ServiceRecord.StartItem si = r.pendingStarts.remove(0); - if (DEBUG_SERVICE) Slog.v(TAG, "Sending arguments to: " + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "Sending arguments to: " + r + " " + r.intent + " args=" + si.intent); if (si.intent == null && N > 1) { // If somehow we got a dummy null intent in the middle, @@ -1566,7 +1576,7 @@ public final class ActiveServices { } catch (RemoteException e) { // Remote process gone... we'll let the normal cleanup take // care of this. - if (DEBUG_SERVICE) Slog.v(TAG, "Crashed while scheduling start: " + r); + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "Crashed while scheduling start: " + r); break; } catch (Exception e) { Slog.w(TAG, "Unexpected exception", e); @@ -1636,7 +1646,7 @@ public final class ActiveServices { if (r.app != null && r.app.thread != null) { for (int i=r.bindings.size()-1; i>=0; i--) { IntentBindRecord ibr = r.bindings.valueAt(i); - if (DEBUG_SERVICE) Slog.v(TAG, "Bringing down binding " + ibr + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "Bringing down binding " + ibr + ": hasBound=" + ibr.hasBound); if (ibr.hasBound) { try { @@ -1654,7 +1664,7 @@ public final class ActiveServices { } } - if (DEBUG_SERVICE) Slog.v(TAG, "Bringing down " + r + " " + r.intent); + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "Bringing down " + r + " " + r.intent); r.destroyTime = SystemClock.uptimeMillis(); if (LOG_SERVICE_START_STOP) { EventLogTags.writeAmDestroyService( @@ -1671,7 +1681,7 @@ public final class ActiveServices { for (int i=mPendingServices.size()-1; i>=0; i--) { if (mPendingServices.get(i) == r) { mPendingServices.remove(i); - if (DEBUG_SERVICE) Slog.v(TAG, "Removed pending: " + r); + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "Removed pending: " + r); } } @@ -1704,11 +1714,11 @@ public final class ActiveServices { } } else { if (DEBUG_SERVICE) Slog.v( - TAG, "Removed service that has no process: " + r); + TAG_SERVICE, "Removed service that has no process: " + r); } } else { if (DEBUG_SERVICE) Slog.v( - TAG, "Removed service that is not running: " + r); + TAG_SERVICE, "Removed service that is not running: " + r); } if (r.bindings.size() > 0) { @@ -1775,7 +1785,7 @@ public final class ActiveServices { } if (!c.serviceDead) { - if (DEBUG_SERVICE) Slog.v(TAG, "Disconnecting binding " + b.intent + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "Disconnecting binding " + b.intent + ": shouldUnbind=" + b.intent.hasBound); if (s.app != null && s.app.thread != null && b.intent.apps.size() == 0 && b.intent.hasBound) { @@ -1902,19 +1912,20 @@ public final class ActiveServices { private void serviceDoneExecutingLocked(ServiceRecord r, boolean inDestroying, boolean finishing) { - if (DEBUG_SERVICE) Slog.v(TAG, "<<< DONE EXECUTING " + r + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "<<< DONE EXECUTING " + r + ": nesting=" + r.executeNesting + ", inDestroying=" + inDestroying + ", app=" + r.app); - else if (DEBUG_SERVICE_EXECUTING) Slog.v(TAG, "<<< DONE EXECUTING " + r.shortName); + else if (DEBUG_SERVICE_EXECUTING) Slog.v(TAG_SERVICE_EXECUTING, + "<<< DONE EXECUTING " + r.shortName); r.executeNesting--; if (r.executeNesting <= 0) { if (r.app != null) { - if (DEBUG_SERVICE) Slog.v(TAG, + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "Nesting at 0 of " + r.shortName); r.app.execServicesFg = false; r.app.executingServices.remove(r); if (r.app.executingServices.size() == 0) { - if (DEBUG_SERVICE || DEBUG_SERVICE_EXECUTING) Slog.v(TAG, + if (DEBUG_SERVICE || DEBUG_SERVICE_EXECUTING) Slog.v(TAG_SERVICE_EXECUTING, "No more executingServices of " + r.shortName); mAm.mHandler.removeMessages(ActivityManagerService.SERVICE_TIMEOUT_MSG, r.app); } else if (r.executeFg) { @@ -1927,7 +1938,7 @@ public final class ActiveServices { } } if (inDestroying) { - if (DEBUG_SERVICE) Slog.v(TAG, + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "doneExecuting remove destroying " + r); mDestroyingServices.remove(r); r.bindings.clear(); @@ -2141,13 +2152,13 @@ public final class ActiveServices { sr.executeNesting = 0; sr.forceClearTracker(); if (mDestroyingServices.remove(sr)) { - if (DEBUG_SERVICE) Slog.v(TAG, "killServices remove destroying " + sr); + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "killServices remove destroying " + sr); } final int numClients = sr.bindings.size(); for (int bindingi=numClients-1; bindingi>=0; bindingi--) { IntentBindRecord b = sr.bindings.valueAt(bindingi); - if (DEBUG_SERVICE) Slog.v(TAG, "Killing binding " + b + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "Killing binding " + b + ": shouldUnbind=" + b.hasBound); b.binder = null; b.requested = b.received = b.hasBound = false; @@ -2281,7 +2292,7 @@ public final class ActiveServices { if (sr.app == app) { sr.forceClearTracker(); mDestroyingServices.remove(i); - if (DEBUG_SERVICE) Slog.v(TAG, "killServices remove destroying " + sr); + if (DEBUG_SERVICE) Slog.v(TAG_SERVICE, "killServices remove destroying " + sr); } } diff --git a/services/core/java/com/android/server/am/ActivityManagerDebugConfig.java b/services/core/java/com/android/server/am/ActivityManagerDebugConfig.java new file mode 100644 index 0000000..03f253b --- /dev/null +++ b/services/core/java/com/android/server/am/ActivityManagerDebugConfig.java @@ -0,0 +1,84 @@ +/* + * Copyright (C) 2014 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.am; + +/** + * Common class for the various debug {@link android.util.Log} output configuration in the activity + * manager package. + */ +class ActivityManagerDebugConfig { + + // All output logs in the activity manager package use the {@link #TAG_AM} string for tagging + // their log output. This makes it easy to identify the origin of the log message when sifting + // through a large amount of log output from multiple sources. However, it also makes trying + // to figure-out the origin of a log message while debugging the activity manager a little + // painful. By setting this constant to true, log messages from the activity manager package + // will be tagged with their class names instead fot the generic tag. + static final boolean TAG_WITH_CLASS_NAME = false; + + // While debugging it is sometimes useful to have the category name of the log prepended to the + // base log tag to make sifting through logs with the same base tag easier. By setting this + // constant to true, the category name of the log point will be prepended to the log tag. + static final boolean PREPEND_CATEGORY_NAME = false; + + // Default log tag for the activity manager package. + static final String TAG_AM = "ActivityManager"; + + // Enable all debug log categories. + static final boolean DEBUG_ALL = false; + + // Available log categories in the activity manager package. + static final boolean DEBUG_BACKUP = DEBUG_ALL || false; + static final boolean DEBUG_BROADCAST = DEBUG_ALL || false; + static final boolean DEBUG_BROADCAST_BACKGROUND = DEBUG_BROADCAST || false; + static final boolean DEBUG_BROADCAST_LIGHT = DEBUG_BROADCAST || false; + static final boolean DEBUG_CLEANUP = DEBUG_ALL || false; + static final boolean DEBUG_CONFIGURATION = DEBUG_ALL || false; + static final boolean DEBUG_FOCUS = false; + static final boolean DEBUG_IMMERSIVE = DEBUG_ALL || false; + static final boolean DEBUG_LOCKSCREEN = DEBUG_ALL || false; + static final boolean DEBUG_LRU = DEBUG_ALL || false; + static final boolean DEBUG_MU = DEBUG_ALL || false; + static final boolean DEBUG_OOM_ADJ = DEBUG_ALL || false; + static final boolean DEBUG_PAUSE = DEBUG_ALL || false; + static final boolean DEBUG_POWER = DEBUG_ALL || false; + static final boolean DEBUG_POWER_QUICK = DEBUG_POWER || false; + static final boolean DEBUG_PROCESS_OBSERVERS = DEBUG_ALL || false; + static final boolean DEBUG_PROCESSES = DEBUG_ALL || false; + static final boolean DEBUG_PROVIDER = DEBUG_ALL || false; + static final boolean DEBUG_PSS = DEBUG_ALL || false; + static final boolean DEBUG_RECENTS = DEBUG_ALL || false; + static final boolean DEBUG_RESULTS = DEBUG_ALL || false; + static final boolean DEBUG_SERVICE = DEBUG_ALL || false; + static final boolean DEBUG_SERVICE_EXECUTING = DEBUG_ALL || false; + static final boolean DEBUG_STACK = DEBUG_ALL || false; + static final boolean DEBUG_SWITCH = DEBUG_ALL || false; + static final boolean DEBUG_TASKS = DEBUG_ALL || false; + static final boolean DEBUG_THUMBNAILS = DEBUG_ALL || false; + static final boolean DEBUG_TRANSITION = DEBUG_ALL || false; + static final boolean DEBUG_URI_PERMISSION = DEBUG_ALL || false; + static final boolean DEBUG_USER_LEAVING = DEBUG_ALL || false; + static final boolean DEBUG_VISBILITY = DEBUG_ALL || false; + + static final String POSTFIX_BACKUP = (PREPEND_CATEGORY_NAME) ? "_Backup" : ""; + static final String POSTFIX_BROADCAST = (PREPEND_CATEGORY_NAME) ? "_Broadcast" : ""; + static final String POSTFIX_MU = "_MU"; + static final String POSTFIX_SERVICE = (PREPEND_CATEGORY_NAME) ? "_Service" : ""; + static final String POSTFIX_SERVICE_EXECUTING = + (PREPEND_CATEGORY_NAME) ? "_ServiceExecuting" : ""; + +} diff --git a/services/core/java/com/android/server/am/ActivityManagerService.java b/services/core/java/com/android/server/am/ActivityManagerService.java index 61ff514..1247105 100644 --- a/services/core/java/com/android/server/am/ActivityManagerService.java +++ b/services/core/java/com/android/server/am/ActivityManagerService.java @@ -30,6 +30,7 @@ import static com.android.server.Watchdog.NATIVE_STACKS_OF_INTEREST; import static org.xmlpull.v1.XmlPullParser.END_DOCUMENT; import static org.xmlpull.v1.XmlPullParser.START_TAG; import static com.android.server.am.ActivityStackSupervisor.HOME_STACK_ID; +import static com.android.server.am.ActivityManagerDebugConfig.*; import static com.android.server.am.TaskRecord.INVALID_TASK_ID; import android.Manifest; @@ -245,10 +246,11 @@ public final class ActivityManagerService extends ActivityManagerNative // File that stores last updated system version and called preboot receivers static final String CALLED_PRE_BOOTS_FILENAME = "called_pre_boots.dat"; - static final String TAG = "ActivityManager"; - static final String TAG_MU = "ActivityManagerServiceMU"; - static final boolean DEBUG = false; - static final boolean localLOGV = DEBUG; + static final String TAG = TAG_WITH_CLASS_NAME ? "ActivityManagerService" : TAG_AM; + private static final String TAG_MU = TAG + POSTFIX_MU; + + // TODO(ogunwale): Migrate all the constants below to use ActivityManagerDebugConfig class. + static final boolean localLOGV = DEBUG_ALL || false; static final boolean DEBUG_BACKUP = localLOGV || false; static final boolean DEBUG_BROADCAST = localLOGV || false; static final boolean DEBUG_BROADCAST_LIGHT = DEBUG_BROADCAST || false; diff --git a/services/core/java/com/android/server/am/ActivityStackSupervisor.java b/services/core/java/com/android/server/am/ActivityStackSupervisor.java index b3d3d6a..8b95ae8 100644 --- a/services/core/java/com/android/server/am/ActivityStackSupervisor.java +++ b/services/core/java/com/android/server/am/ActivityStackSupervisor.java @@ -20,6 +20,7 @@ import static android.Manifest.permission.START_ANY_ACTIVITY; import static android.content.Intent.FLAG_ACTIVITY_NEW_TASK; import static android.content.Intent.FLAG_ACTIVITY_TASK_ON_HOME; import static android.content.pm.PackageManager.PERMISSION_GRANTED; +import static com.android.server.am.ActivityManagerDebugConfig.*; import static com.android.server.am.ActivityManagerService.localLOGV; import static com.android.server.am.ActivityManagerService.DEBUG_CONFIGURATION; import static com.android.server.am.ActivityManagerService.DEBUG_FOCUS; @@ -116,7 +117,7 @@ import java.util.ArrayList; import java.util.List; public final class ActivityStackSupervisor implements DisplayListener { - static final boolean DEBUG = ActivityManagerService.DEBUG || false; + static final boolean DEBUG = DEBUG_ALL || false; static final boolean DEBUG_ADD_REMOVE = DEBUG || false; static final boolean DEBUG_APP = DEBUG || false; static final boolean DEBUG_CONTAINERS = DEBUG || false; diff --git a/services/core/java/com/android/server/am/BroadcastQueue.java b/services/core/java/com/android/server/am/BroadcastQueue.java index 5083b1d..7a29a88 100644 --- a/services/core/java/com/android/server/am/BroadcastQueue.java +++ b/services/core/java/com/android/server/am/BroadcastQueue.java @@ -41,6 +41,8 @@ import android.os.UserHandle; import android.util.EventLog; import android.util.Slog; +import static com.android.server.am.ActivityManagerDebugConfig.*; + /** * BROADCASTS * @@ -48,11 +50,9 @@ import android.util.Slog; * foreground priority, and one for normal (background-priority) broadcasts. */ public final class BroadcastQueue { - static final String TAG = "BroadcastQueue"; - static final String TAG_MU = ActivityManagerService.TAG_MU; - static final boolean DEBUG_BROADCAST = ActivityManagerService.DEBUG_BROADCAST; - static final boolean DEBUG_BROADCAST_LIGHT = ActivityManagerService.DEBUG_BROADCAST_LIGHT; - static final boolean DEBUG_MU = ActivityManagerService.DEBUG_MU; + private static final String TAG = TAG_WITH_CLASS_NAME ? "BroadcastQueue" : TAG_AM; + private static final String TAG_MU = TAG + POSTFIX_MU; + private static final String TAG_BROADCAST = TAG + POSTFIX_BROADCAST; static final int MAX_BROADCAST_HISTORY = ActivityManager.isLowRamDeviceStatic() ? 10 : 50; static final int MAX_BROADCAST_SUMMARY_HISTORY @@ -143,7 +143,7 @@ public final class BroadcastQueue { switch (msg.what) { case BROADCAST_INTENT_MSG: { if (DEBUG_BROADCAST) Slog.v( - TAG, "Received BROADCAST_INTENT_MSG"); + TAG_BROADCAST, "Received BROADCAST_INTENT_MSG"); processNextBroadcast(true); } break; case BROADCAST_TIMEOUT_MSG: { @@ -196,7 +196,7 @@ public final class BroadcastQueue { public final boolean replaceParallelBroadcastLocked(BroadcastRecord r) { for (int i=mParallelBroadcasts.size()-1; i>=0; i--) { if (r.intent.filterEquals(mParallelBroadcasts.get(i).intent)) { - if (DEBUG_BROADCAST) Slog.v(TAG, + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "***** DROPPING PARALLEL [" + mQueueName + "]: " + r.intent); mParallelBroadcasts.set(i, r); @@ -209,7 +209,7 @@ public final class BroadcastQueue { public final boolean replaceOrderedBroadcastLocked(BroadcastRecord r) { for (int i=mOrderedBroadcasts.size()-1; i>0; i--) { if (r.intent.filterEquals(mOrderedBroadcasts.get(i).intent)) { - if (DEBUG_BROADCAST) Slog.v(TAG, + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "***** DROPPING ORDERED [" + mQueueName + "]: " + r.intent); mOrderedBroadcasts.set(i, r); @@ -221,7 +221,7 @@ public final class BroadcastQueue { private final void processCurBroadcastLocked(BroadcastRecord r, ProcessRecord app) throws RemoteException { - if (DEBUG_BROADCAST) Slog.v(TAG, + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "Process cur broadcast " + r + " for app " + app); if (app.thread == null) { throw new RemoteException(); @@ -238,7 +238,7 @@ public final class BroadcastQueue { boolean started = false; try { - if (DEBUG_BROADCAST_LIGHT) Slog.v(TAG, + if (DEBUG_BROADCAST_LIGHT) Slog.v(TAG_BROADCAST, "Delivering to component " + r.curComponent + ": " + r); mService.ensurePackageDexOpt(r.intent.getComponent().getPackageName()); @@ -246,12 +246,12 @@ public final class BroadcastQueue { mService.compatibilityInfoForPackageLocked(r.curReceiver.applicationInfo), r.resultCode, r.resultData, r.resultExtras, r.ordered, r.userId, app.repProcState); - if (DEBUG_BROADCAST) Slog.v(TAG, + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "Process cur broadcast " + r + " DELIVERED for app " + app); started = true; } finally { if (!started) { - if (DEBUG_BROADCAST) Slog.v(TAG, + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "Process cur broadcast " + r + ": NOT STARTED!"); r.receiver = null; r.curApp = null; @@ -308,7 +308,7 @@ public final class BroadcastQueue { r = mPendingBroadcast; if (r != null && r.curApp == app) { - if (DEBUG_BROADCAST) Slog.v(TAG, + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "[" + mQueueName + "] skip & discard pending app " + r); logBroadcastReceiverDiscardLocked(r); finishReceiverLocked(r, r.resultCode, r.resultData, @@ -321,7 +321,7 @@ public final class BroadcastQueue { } public void scheduleBroadcastsLocked() { - if (DEBUG_BROADCAST) Slog.v(TAG, "Schedule broadcasts [" + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "Schedule broadcasts [" + mQueueName + "]: current=" + mBroadcastsScheduled); @@ -391,8 +391,7 @@ public final class BroadcastQueue { // on. If there are background services currently starting, then we will go into a // special state where we hold off on continuing this broadcast until they are done. if (mService.mServices.hasBackgroundServices(r.userId)) { - Slog.i(ActivityManagerService.TAG, "Delay finish: " - + r.curComponent.flattenToShortString()); + Slog.i(TAG, "Delay finish: " + r.curComponent.flattenToShortString()); r.state = BroadcastRecord.WAITING_SERVICES; return false; } @@ -412,7 +411,7 @@ public final class BroadcastQueue { if (mOrderedBroadcasts.size() > 0) { BroadcastRecord br = mOrderedBroadcasts.get(0); if (br.userId == userId && br.state == BroadcastRecord.WAITING_SERVICES) { - Slog.i(ActivityManagerService.TAG, "Resuming delayed broadcast"); + Slog.i(TAG, "Resuming delayed broadcast"); br.curComponent = null; br.state = BroadcastRecord.IDLE; processNextBroadcast(false); @@ -475,7 +474,7 @@ public final class BroadcastQueue { int mode = mService.mAppOpsService.noteOperation(r.appOp, filter.receiverList.uid, filter.packageName); if (mode != AppOpsManager.MODE_ALLOWED) { - if (DEBUG_BROADCAST) Slog.v(TAG, + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "App op " + r.appOp + " not allowed for broadcast to uid " + filter.receiverList.uid + " pkg " + filter.packageName); skip = true; @@ -513,7 +512,7 @@ public final class BroadcastQueue { } } try { - if (DEBUG_BROADCAST_LIGHT) Slog.i(TAG, "Delivering to " + filter + " : " + r); + if (DEBUG_BROADCAST_LIGHT) Slog.i(TAG_BROADCAST, "Delivering to " + filter + " : " + r); performReceiveLocked(filter.receiverList.app, filter.receiverList.receiver, new Intent(r.intent), r.resultCode, r.resultData, r.resultExtras, r.ordered, r.initialSticky, r.userId); @@ -538,7 +537,7 @@ public final class BroadcastQueue { synchronized(mService) { BroadcastRecord r; - if (DEBUG_BROADCAST) Slog.v(TAG, "processNextBroadcast [" + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "processNextBroadcast [" + mQueueName + "]: " + mParallelBroadcasts.size() + " broadcasts, " + mOrderedBroadcasts.size() + " ordered broadcasts"); @@ -555,17 +554,17 @@ public final class BroadcastQueue { r.dispatchTime = SystemClock.uptimeMillis(); r.dispatchClockTime = System.currentTimeMillis(); final int N = r.receivers.size(); - if (DEBUG_BROADCAST_LIGHT) Slog.v(TAG, "Processing parallel broadcast [" + if (DEBUG_BROADCAST_LIGHT) Slog.v(TAG_BROADCAST, "Processing parallel broadcast [" + mQueueName + "] " + r); for (int i=0; i<N; i++) { Object target = r.receivers.get(i); - if (DEBUG_BROADCAST) Slog.v(TAG, + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "Delivering non-ordered on [" + mQueueName + "] to registered " + target + ": " + r); deliverToRegisteredReceiverLocked(r, (BroadcastFilter)target, false); } addBroadcastToHistoryLocked(r); - if (DEBUG_BROADCAST_LIGHT) Slog.v(TAG, "Done with parallel broadcast [" + if (DEBUG_BROADCAST_LIGHT) Slog.v(TAG_BROADCAST, "Done with parallel broadcast [" + mQueueName + "] " + r); } @@ -576,7 +575,7 @@ public final class BroadcastQueue { // check that the process we're waiting for still exists. if (mPendingBroadcast != null) { if (DEBUG_BROADCAST_LIGHT) { - Slog.v(TAG, "processNextBroadcast [" + Slog.v(TAG_BROADCAST, "processNextBroadcast [" + mQueueName + "]: waiting for " + mPendingBroadcast.curApp); } @@ -645,7 +644,7 @@ public final class BroadcastQueue { } if (r.state != BroadcastRecord.IDLE) { - if (DEBUG_BROADCAST) Slog.d(TAG, + if (DEBUG_BROADCAST) Slog.d(TAG_BROADCAST, "processNextBroadcast(" + mQueueName + ") called when not idle (state=" + r.state + ")"); @@ -658,7 +657,7 @@ public final class BroadcastQueue { // result if requested... if (r.resultTo != null) { try { - if (DEBUG_BROADCAST) Slog.i(TAG, + if (DEBUG_BROADCAST) Slog.i(TAG_BROADCAST, "Finishing broadcast [" + mQueueName + "] " + r.intent.getAction() + " app=" + r.callerApp); performReceiveLocked(r.callerApp, r.resultTo, @@ -675,10 +674,10 @@ public final class BroadcastQueue { } } - if (DEBUG_BROADCAST) Slog.v(TAG, "Cancelling BROADCAST_TIMEOUT_MSG"); + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "Cancelling BROADCAST_TIMEOUT_MSG"); cancelBroadcastTimeoutLocked(); - if (DEBUG_BROADCAST_LIGHT) Slog.v(TAG, "Finished with ordered broadcast " + if (DEBUG_BROADCAST_LIGHT) Slog.v(TAG_BROADCAST, "Finished with ordered broadcast " + r); // ... and on to the next... @@ -699,12 +698,12 @@ public final class BroadcastQueue { if (recIdx == 0) { r.dispatchTime = r.receiverTime; r.dispatchClockTime = System.currentTimeMillis(); - if (DEBUG_BROADCAST_LIGHT) Slog.v(TAG, "Processing ordered broadcast [" + if (DEBUG_BROADCAST_LIGHT) Slog.v(TAG_BROADCAST, "Processing ordered broadcast [" + mQueueName + "] " + r); } if (! mPendingBroadcastTimeoutMessage) { long timeoutTime = r.receiverTime + mTimeoutPeriod; - if (DEBUG_BROADCAST) Slog.v(TAG, + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "Submitting BROADCAST_TIMEOUT_MSG [" + mQueueName + "] for " + r + " at " + timeoutTime); setBroadcastTimeoutLocked(timeoutTime); @@ -715,7 +714,7 @@ public final class BroadcastQueue { // Simple case: this is a registered receiver who gets // a direct call. BroadcastFilter filter = (BroadcastFilter)nextReceiver; - if (DEBUG_BROADCAST) Slog.v(TAG, + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "Delivering ordered [" + mQueueName + "] to registered " + filter + ": " + r); @@ -723,7 +722,7 @@ public final class BroadcastQueue { if (r.receiver == null || !r.ordered) { // The receiver has already finished, so schedule to // process the next one. - if (DEBUG_BROADCAST) Slog.v(TAG, "Quick finishing [" + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "Quick finishing [" + mQueueName + "]: ordered=" + r.ordered + " receiver=" + r.receiver); r.state = BroadcastRecord.IDLE; @@ -786,7 +785,7 @@ public final class BroadcastQueue { int mode = mService.mAppOpsService.noteOperation(r.appOp, info.activityInfo.applicationInfo.uid, info.activityInfo.packageName); if (mode != AppOpsManager.MODE_ALLOWED) { - if (DEBUG_BROADCAST) Slog.v(TAG, + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "App op " + r.appOp + " not allowed for broadcast to uid " + info.activityInfo.applicationInfo.uid + " pkg " + info.activityInfo.packageName); @@ -836,7 +835,7 @@ public final class BroadcastQueue { } if (!isAvailable) { if (DEBUG_BROADCAST) { - Slog.v(TAG, "Skipping delivery to " + info.activityInfo.packageName + Slog.v(TAG_BROADCAST, "Skipping delivery to " + info.activityInfo.packageName + " / " + info.activityInfo.applicationInfo.uid + " : package no longer available"); } @@ -845,7 +844,7 @@ public final class BroadcastQueue { } if (skip) { - if (DEBUG_BROADCAST) Slog.v(TAG, + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "Skipping delivery of ordered [" + mQueueName + "] " + r + " for whatever reason"); r.receiver = null; @@ -915,7 +914,7 @@ public final class BroadcastQueue { } // Not running -- get it started, to be executed when the app comes up. - if (DEBUG_BROADCAST) Slog.v(TAG, + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "Need to start app [" + mQueueName + "] " + targetProcess + " for broadcast " + r); if ((r.curApp=mService.startProcessLocked(targetProcess, @@ -990,7 +989,7 @@ public final class BroadcastQueue { // broadcast timeout message after each receiver finishes. Instead, we set up // an initial timeout then kick it down the road a little further as needed // when it expires. - if (DEBUG_BROADCAST) Slog.v(TAG, + if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST, "Premature timeout [" + mQueueName + "] @ " + now + ": resetting BROADCAST_TIMEOUT_MSG for " + timeoutTime); @@ -1005,7 +1004,7 @@ public final class BroadcastQueue { // for started services to finish as well before going on. So if we have actually // waited long enough time timeout the broadcast, let's give up on the whole thing // and just move on to the next. - Slog.i(ActivityManagerService.TAG, "Waited long enough for: " + (br.curComponent != null + Slog.i(TAG, "Waited long enough for: " + (br.curComponent != null ? br.curComponent.flattenToShortString() : "(null)")); br.curComponent = null; br.state = BroadcastRecord.IDLE; |