Merge "Move fully drawn metric log out of wm lock" (81d66e9d) · Commits · e / os / android_frameworks_base

services/core/java/com/android/server/wm/ActivityClientController.java

+2 −1

Original line number	Diff line number	Diff line
		@@ -1211,7 +1211,8 @@ class ActivityClientController extends IActivityClientController.Stub {
		synchronized (mGlobalLock) {
		final ActivityRecord r = ActivityRecord.isInRootTaskLocked(token);
		if (r != null) {
		r.reportFullyDrawnLocked(restoredFromBundle);
		mTaskSupervisor.getActivityMetricsLogger().notifyFullyDrawn(r,
		restoredFromBundle);
		}
		}
		} finally {

services/core/java/com/android/server/wm/ActivityMetricsLogger.java

+47 −44

Original line number	Diff line number	Diff line
		@@ -454,6 +454,7 @@ class ActivityMetricsLogger {
		final int windowsFullyDrawnDelayMs;
		final int activityRecordIdHashCode;
		final boolean relaunched;
		final long timestampNs;

		private TransitionInfoSnapshot(TransitionInfo info) {
		this(info, info.mLastLaunchedActivity, INVALID_DELAY);
		@@ -483,6 +484,7 @@ class ActivityMetricsLogger {
		activityRecordIdHashCode = System.identityHashCode(launchedActivity);
		this.windowsFullyDrawnDelayMs = windowsFullyDrawnDelayMs;
		relaunched = info.mRelaunched;
		timestampNs = info.mLaunchingState.mStartRealtimeNs;
		}

		@WaitResult.LaunchState int getLaunchState() {
		@@ -498,6 +500,10 @@ class ActivityMetricsLogger {
		}
		}

		boolean isIntresetedToEventLog() {
		return type == TYPE_TRANSITION_WARM_LAUNCH \|\| type == TYPE_TRANSITION_COLD_LAUNCH;
		}

		PackageOptimizationInfo getPackageOptimizationInfo(ArtManagerInternal artManagerInternal) {
		return artManagerInternal == null \|\| launchedActivityAppRecordRequiredAbi == null
		? PackageOptimizationInfo.createWithNoInfo()
		@@ -1022,16 +1028,17 @@ class ActivityMetricsLogger {
		// This will avoid any races with other operations that modify the ActivityRecord.
		final TransitionInfoSnapshot infoSnapshot = new TransitionInfoSnapshot(info);
		if (info.isInterestingToLoggerAndObserver()) {
		final long timestampNs = info.mLaunchingState.mStartRealtimeNs;
		final long uptimeNs = info.mLaunchingState.mStartUptimeNs;
		final int transitionDelay = info.mCurrentTransitionDelayMs;
		final int processState = info.mProcessState;
		final int processOomAdj = info.mProcessOomAdj;
		mLoggerHandler.post(() -> logAppTransition(
		timestampNs, uptimeNs, transitionDelay, infoSnapshot, isHibernating,
		uptimeNs, transitionDelay, infoSnapshot, isHibernating,
		processState, processOomAdj));
		}
		if (infoSnapshot.isIntresetedToEventLog()) {
		mLoggerHandler.post(() -> logAppDisplayed(infoSnapshot));
		}
		if (info.mPendingFullyDrawn != null) {
		info.mPendingFullyDrawn.run();
		}
		@@ -1040,7 +1047,7 @@ class ActivityMetricsLogger {
		}

		// This gets called on another thread without holding the activity manager lock.
		private void logAppTransition(long transitionStartTimeNs, long transitionDeviceUptimeNs,
		private void logAppTransition(long transitionDeviceUptimeNs,
		int currentTransitionDelayMs, TransitionInfoSnapshot info, boolean isHibernating,
		int processState, int processOomAdj) {
		final LogMaker builder = new LogMaker(APP_TRANSITION);
		@@ -1108,7 +1115,7 @@ class ActivityMetricsLogger {
		isIncremental,
		isLoading,
		info.launchedActivityName.hashCode(),
		TimeUnit.NANOSECONDS.toMillis(transitionStartTimeNs),
		TimeUnit.NANOSECONDS.toMillis(info.timestampNs),
		processState,
		processOomAdj);

		@@ -1132,10 +1139,6 @@ class ActivityMetricsLogger {
		}

		private void logAppDisplayed(TransitionInfoSnapshot info) {
		if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
		return;
		}

		EventLog.writeEvent(WM_ACTIVITY_LAUNCH_TIME,
		info.userId, info.activityRecordIdHashCode, info.launchedActivityShortComponentName,
		info.windowsDrawnDelayMs);
		@@ -1181,8 +1184,7 @@ class ActivityMetricsLogger {
		}

		/** @see android.app.Activity#reportFullyDrawn */
		TransitionInfoSnapshot logAppTransitionReportedDrawn(ActivityRecord r,
		boolean restoredFromBundle) {
		TransitionInfoSnapshot notifyFullyDrawn(ActivityRecord r, boolean restoredFromBundle) {
		final TransitionInfo info = mLastTransitionInfo.get(r);
		if (info == null) {
		return null;
		@@ -1191,7 +1193,7 @@ class ActivityMetricsLogger {
		// There are still undrawn activities, postpone reporting fully drawn until all of its
		// windows are drawn. So that is closer to an usable state.
		info.mPendingFullyDrawn = () -> {
		logAppTransitionReportedDrawn(r, restoredFromBundle);
		notifyFullyDrawn(r, restoredFromBundle);
		info.mPendingFullyDrawn = null;
		};
		return null;
		@@ -1204,7 +1206,9 @@ class ActivityMetricsLogger {
		currentTimestampNs - info.mLaunchingState.mStartUptimeNs);
		final TransitionInfoSnapshot infoSnapshot =
		new TransitionInfoSnapshot(info, r, (int) startupTimeMs);
		if (infoSnapshot.isIntresetedToEventLog()) {
		mLoggerHandler.post(() -> logAppFullyDrawn(infoSnapshot));
		}
		mLastTransitionInfo.remove(r);

		if (!info.isInterestingToLoggerAndObserver()) {
		@@ -1216,61 +1220,60 @@ class ActivityMetricsLogger {
		// fullfils (handling reportFullyDrawn() callbacks).
		Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER,
		"ActivityManager:ReportingFullyDrawn " + info.mLastLaunchedActivity.packageName);
		mLoggerHandler.post(() -> logAppFullyDrawnMetrics(infoSnapshot, restoredFromBundle,
		info.mProcessRunning));
		// Ends the trace started at the beginning of this function. This is located here to allow
		// the trace slice to have a noticable duration.
		Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);

		// Notify reportFullyDrawn event.
		launchObserverNotifyReportFullyDrawn(info, currentTimestampNs);

		return infoSnapshot;
		}

		private void logAppFullyDrawnMetrics(TransitionInfoSnapshot info, boolean restoredFromBundle,
		boolean processRunning) {
		final LogMaker builder = new LogMaker(APP_TRANSITION_REPORTED_DRAWN);
		builder.setPackageName(r.packageName);
		builder.addTaggedData(FIELD_CLASS_NAME, r.info.name);
		builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS, startupTimeMs);
		builder.setPackageName(info.packageName);
		builder.addTaggedData(FIELD_CLASS_NAME, info.launchedActivityName);
		builder.addTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS,
		(long) info.windowsFullyDrawnDelayMs);
		builder.setType(restoredFromBundle
		? TYPE_TRANSITION_REPORTED_DRAWN_WITH_BUNDLE
		: TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE);
		builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING,
		info.mProcessRunning ? 1 : 0);
		builder.addTaggedData(APP_TRANSITION_PROCESS_RUNNING, processRunning ? 1 : 0);
		mMetricsLogger.write(builder);
		final PackageOptimizationInfo packageOptimizationInfo =
		infoSnapshot.getPackageOptimizationInfo(getArtManagerInternal());
		info.getPackageOptimizationInfo(getArtManagerInternal());
		// Incremental info
		boolean isIncremental = false, isLoading = false;
		final String codePath = info.mLastLaunchedActivity.info.applicationInfo.getCodePath();
		final String codePath = info.applicationInfo.getCodePath();
		if (codePath != null && IncrementalManager.isIncrementalPath(codePath)) {
		isIncremental = true;
		isLoading = isIncrementalLoading(info.mLastLaunchedActivity.packageName,
		info.mLastLaunchedActivity.mUserId);
		isLoading = isIncrementalLoading(info.packageName, info.userId);
		}
		FrameworkStatsLog.write(
		FrameworkStatsLog.APP_START_FULLY_DRAWN,
		info.mLastLaunchedActivity.info.applicationInfo.uid,
		info.mLastLaunchedActivity.packageName,
		info.applicationInfo.uid,
		info.packageName,
		restoredFromBundle
		? FrameworkStatsLog.APP_START_FULLY_DRAWN__TYPE__WITH_BUNDLE
		: FrameworkStatsLog.APP_START_FULLY_DRAWN__TYPE__WITHOUT_BUNDLE,
		info.mLastLaunchedActivity.info.name,
		info.mProcessRunning,
		startupTimeMs,
		info.launchedActivityName,
		processRunning,
		info.windowsFullyDrawnDelayMs,
		packageOptimizationInfo.getCompilationReason(),
		packageOptimizationInfo.getCompilationFilter(),
		info.mSourceType,
		info.mSourceEventDelayMs,
		info.sourceType,
		info.sourceEventDelayMs,
		isIncremental,
		isLoading,
		info.mLastLaunchedActivity.info.name.hashCode(),
		TimeUnit.NANOSECONDS.toMillis(info.mLaunchingState.mStartRealtimeNs));

		// Ends the trace started at the beginning of this function. This is located here to allow
		// the trace slice to have a noticable duration.
		Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);

		// Notify reportFullyDrawn event.
		launchObserverNotifyReportFullyDrawn(info, currentTimestampNs);

		return infoSnapshot;
		info.launchedActivityName.hashCode(),
		TimeUnit.NANOSECONDS.toMillis(info.timestampNs));
		}

		private void logAppFullyDrawn(TransitionInfoSnapshot info) {
		if (info.type != TYPE_TRANSITION_WARM_LAUNCH && info.type != TYPE_TRANSITION_COLD_LAUNCH) {
		return;
		}

		StringBuilder sb = mStringBuilder;
		sb.setLength(0);
		sb.append("Fully drawn ");

services/core/java/com/android/server/wm/ActivityRecord.java

+0 −9

Original line number	Diff line number	Diff line
		@@ -6497,15 +6497,6 @@ final class ActivityRecord extends WindowToken implements WindowManagerService.A
		}
		}

		void reportFullyDrawnLocked(boolean restoredFromBundle) {
		final TransitionInfoSnapshot info = mTaskSupervisor
		.getActivityMetricsLogger().logAppTransitionReportedDrawn(this, restoredFromBundle);
		if (info != null) {
		mTaskSupervisor.reportActivityLaunched(false /* timeout */, this,
		info.windowsFullyDrawnDelayMs, info.getLaunchState());
		}
		}

		void onFirstWindowDrawn(WindowState win) {
		firstWindowDrawn = true;
		// stop tracking

services/tests/wmtests/src/com/android/server/wm/ActivityMetricsLaunchObserverTests.java

+2 −2

Original line number	Diff line number	Diff line
		@@ -324,7 +324,7 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase {

		// The activity reports fully drawn before windows drawn, then the fully drawn event will
		// be pending (see {@link WindowingModeTransitionInfo#pendingFullyDrawn}).
		mActivityMetricsLogger.logAppTransitionReportedDrawn(mTopActivity, false);
		mActivityMetricsLogger.notifyFullyDrawn(mTopActivity, false /* restoredFromBundle */);
		notifyTransitionStarting(mTopActivity);
		// The pending fully drawn event should send when the actual windows drawn event occurs.
		final ActivityMetricsLogger.TransitionInfoSnapshot info = notifyWindowsDrawn(mTopActivity);
		@@ -337,7 +337,7 @@ public class ActivityMetricsLaunchObserverTests extends WindowTestsBase {
		verifyNoMoreInteractions(mLaunchObserver);

		final ActivityMetricsLogger.TransitionInfoSnapshot fullyDrawnInfo = mActivityMetricsLogger
		.logAppTransitionReportedDrawn(mTopActivity, false /* restoredFromBundle */);
		.notifyFullyDrawn(mTopActivity, false /* restoredFromBundle */);
		assertWithMessage("Invisible event must be dropped").that(fullyDrawnInfo).isNull();
		}