From 133c8e8f5d377aaf2718359b9a32b09367ba256a Mon Sep 17 00:00:00 2001 From: Hui Yu Date: Tue, 15 Jun 2021 13:33:01 -0700 Subject: [PATCH] Log FGS ENTER event synchronously. To make sure the ENTER event has correct timestamp and other fields from ServiceRecord. Add field mFgsNotificationWasDeferred to save mFgsNotificationDeferred value when mFgsNotificationDeferred is set true, should look at EXIT event for fgs_notification_deferred instead of ENTER event. Bug: 191054441 Test: build and run, monitor westworld event logs. Test: atest CtsAppTestCases:android.app.cts.NotificationManagerTest Test: atest CtsAppTestCases:android.app.cts.ServiceTest Test: atest CtsStatsdAtomHostTestCases:android.cts.statsdatom.statsd.UidAtomTests#testForegroundServiceState Change-Id: I07ace3810b6bbed4860065e7e06453441794f80c --- .../com/android/server/am/ActiveServices.java | 28 ++++++------------- .../com/android/server/am/ServiceRecord.java | 5 ++-- 2 files changed, 11 insertions(+), 22 deletions(-) diff --git a/services/core/java/com/android/server/am/ActiveServices.java b/services/core/java/com/android/server/am/ActiveServices.java index 9f831d2168c12..2eafc616245a9 100644 --- a/services/core/java/com/android/server/am/ActiveServices.java +++ b/services/core/java/com/android/server/am/ActiveServices.java @@ -1876,7 +1876,6 @@ public final class ActiveServices { active.mNumActive++; } r.isForeground = true; - r.mLogEntering = true; // The logging of FOREGROUND_SERVICE_STATE_CHANGED__STATE__ENTER event could // be deferred, make a copy of mAllowStartForeground and // mAllowWhileInUsePermissionInFgs. @@ -1902,6 +1901,9 @@ public final class ActiveServices { AppOpsManager.ATTRIBUTION_CHAIN_ID_NONE); registerAppOpCallbackLocked(r); mAm.updateForegroundServiceUsageStats(r.name, r.userId, true); + logFGSStateChangeLocked(r, + FrameworkStatsLog.FOREGROUND_SERVICE_STATE_CHANGED__STATE__ENTER, + 0); } // Even if the service is already a FGS, we need to update the notification, // so we need to call it again. @@ -1957,6 +1959,7 @@ public final class ActiveServices { FrameworkStatsLog.FOREGROUND_SERVICE_STATE_CHANGED__STATE__EXIT, r.mFgsExitTime > r.mFgsEnterTime ? (int)(r.mFgsExitTime - r.mFgsEnterTime) : 0); + r.mFgsNotificationWasDeferred = false; resetFgsRestrictionLocked(r); mAm.updateForegroundServiceUsageStats(r.name, r.userId, false); if (r.app != null) { @@ -2161,6 +2164,7 @@ public final class ActiveServices { } r.fgDisplayTime = when; r.mFgsNotificationDeferred = true; + r.mFgsNotificationWasDeferred = true; r.mFgsNotificationShown = false; mPendingFgsNotifications.add(r); if (DEBUG_FOREGROUND_SERVICE) { @@ -2204,11 +2208,6 @@ public final class ActiveServices { Slog.d(TAG_SERVICE, " - service no longer running/fg, ignoring"); } } - // Regardless of whether we needed to post the notification or the - // service is no longer running, we may not have logged its FGS - // transition yet depending on the timing and API sequence that led - // to this point - so make sure to do so. - maybeLogFGSStateEnteredLocked(r); } } if (DEBUG_FOREGROUND_SERVICE) { @@ -2251,16 +2250,6 @@ public final class ActiveServices { } } - private void maybeLogFGSStateEnteredLocked(ServiceRecord r) { - if (r.mLogEntering) { - logFGSStateChangeLocked(r, - FrameworkStatsLog - .FOREGROUND_SERVICE_STATE_CHANGED__STATE__ENTER, - 0); - r.mLogEntering = false; - } - } - /** * Callback from NotificationManagerService whenever it posts a notification * associated with a foreground service. This is the unified handling point @@ -2279,9 +2268,7 @@ public final class ActiveServices { && id == sr.foregroundId && sr.appInfo.packageName.equals(pkg)) { // Found it. If 'shown' is false, it means that the notification - // subsystem will not be displaying it yet, so all we do is log - // the "fgs entered" transition noting deferral, then we're done. - maybeLogFGSStateEnteredLocked(sr); + // subsystem will not be displaying it yet. if (shown) { if (DEBUG_FOREGROUND_SERVICE) { Slog.d(TAG_SERVICE, "Notification shown; canceling deferral of " @@ -4239,6 +4226,7 @@ public final class ActiveServices { r.isForeground = false; r.foregroundId = 0; r.foregroundNoti = null; + r.mFgsNotificationWasDeferred = false; resetFgsRestrictionLocked(r); // Clear start entries. @@ -6262,7 +6250,7 @@ public final class ActiveServices { ? r.mRecentCallerApplicationInfo.targetSdkVersion : 0, r.mInfoTempFgsAllowListReason != null ? r.mInfoTempFgsAllowListReason.mCallingUid : INVALID_UID, - r.mFgsNotificationDeferred, + r.mFgsNotificationWasDeferred, r.mFgsNotificationShown, durationMs, r.mStartForegroundCount, diff --git a/services/core/java/com/android/server/am/ServiceRecord.java b/services/core/java/com/android/server/am/ServiceRecord.java index 3ba07af710c24..141f081ab9a7a 100644 --- a/services/core/java/com/android/server/am/ServiceRecord.java +++ b/services/core/java/com/android/server/am/ServiceRecord.java @@ -109,7 +109,6 @@ final class ServiceRecord extends Binder implements ComponentName.WithComponentN boolean fgWaiting; // is a timeout for going foreground already scheduled? boolean isNotAppComponentUsage; // is service binding not considered component/package usage? boolean isForeground; // is service currently in foreground mode? - boolean mLogEntering; // need to report fgs transition once deferral policy is known int foregroundId; // Notification ID of last foreground req. Notification foregroundNoti; // Notification record of foreground state. long fgDisplayTime; // time at which the FGS notification should become visible @@ -167,8 +166,10 @@ final class ServiceRecord extends Binder implements ComponentName.WithComponentN long mFgsEnterTime = 0; // The uptime when the service exits FGS state. long mFgsExitTime = 0; - // FGS notification was deferred. + // FGS notification is deferred. boolean mFgsNotificationDeferred; + // FGS notification was deferred. + boolean mFgsNotificationWasDeferred; // FGS notification was shown before the FGS finishes, or it wasn't deferred in the first place. boolean mFgsNotificationShown;