Example implementations of new logging system (7d2e9c1c) · Commits · e / os / android_frameworks_base

packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/NotifCollection.java

+10 −7

Original line number	Diff line number	Diff line
		@@ -44,7 +44,6 @@ import android.service.notification.NotificationListenerService.Ranking;
		import android.service.notification.NotificationListenerService.RankingMap;
		import android.service.notification.StatusBarNotification;
		import android.util.ArrayMap;
		import android.util.Log;

		import com.android.internal.statusbar.IStatusBarService;
		import com.android.systemui.DumpController;
		@@ -56,6 +55,7 @@ import com.android.systemui.statusbar.notification.collection.coalescer.GroupCoa
		import com.android.systemui.statusbar.notification.collection.notifcollection.CollectionReadyForBuildListener;
		import com.android.systemui.statusbar.notification.collection.notifcollection.DismissedByUserStats;
		import com.android.systemui.statusbar.notification.collection.notifcollection.NotifCollectionListener;
		import com.android.systemui.statusbar.notification.collection.notifcollection.NotifCollectionLogger;
		import com.android.systemui.statusbar.notification.collection.notifcollection.NotifLifetimeExtender;
		import com.android.systemui.util.Assert;

		@@ -100,6 +100,7 @@ import javax.inject.Singleton;
		public class NotifCollection implements Dumpable {
		private final IStatusBarService mStatusBarService;
		private final FeatureFlags mFeatureFlags;
		private final NotifCollectionLogger mLogger;

		private final Map<String, NotificationEntry> mNotificationSet = new ArrayMap<>();
		private final Collection<NotificationEntry> mReadOnlyNotificationSet =
		@@ -116,9 +117,11 @@ public class NotifCollection implements Dumpable {
		public NotifCollection(
		IStatusBarService statusBarService,
		DumpController dumpController,
		FeatureFlags featureFlags) {
		FeatureFlags featureFlags,
		NotifCollectionLogger logger) {
		Assert.isMainThread();
		mStatusBarService = statusBarService;
		mLogger = logger;
		dumpController.registerDumpable(TAG, this);
		mFeatureFlags = featureFlags;
		}
		@@ -190,8 +193,8 @@ public class NotifCollection implements Dumpable {
		private void onNotificationGroupPosted(List<CoalescedEvent> batch) {
		Assert.isMainThread();

		Log.d(TAG, "POSTED GROUP " + batch.get(0).getSbn().getGroupKey()
		+ " (" + batch.size() + " events)");
		mLogger.logNotifGroupPosted(batch.get(0).getSbn().getGroupKey(), batch.size());

		for (CoalescedEvent event : batch) {
		postNotification(event.getSbn(), event.getRanking(), null);
		}
		@@ -204,7 +207,7 @@ public class NotifCollection implements Dumpable {
		int reason) {
		Assert.isMainThread();

		Log.d(TAG, "REMOVED " + sbn.getKey() + " reason=" + reason);
		mLogger.logNotifRemoved(sbn.getKey(), reason);
		removeNotification(sbn.getKey(), rankingMap, reason, null);
		}

		@@ -222,7 +225,7 @@ public class NotifCollection implements Dumpable {

		if (entry == null) {
		// A new notification!
		Log.d(TAG, "POSTED " + sbn.getKey());
		mLogger.logNotifPosted(sbn.getKey());

		entry = new NotificationEntry(sbn, ranking);
		mNotificationSet.put(sbn.getKey(), entry);
		@@ -234,7 +237,7 @@ public class NotifCollection implements Dumpable {

		} else {
		// Update to an existing entry
		Log.d(TAG, "UPDATED " + sbn.getKey());
		mLogger.logNotifUpdated(sbn.getKey());

		// Notification is updated so it is essentially re-added and thus alive again. Don't
		// need to keep its lifetime extended.

packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/ShadeListBuilder.java

+42 −96

Original line number	Diff line number	Diff line
		@@ -32,19 +32,20 @@ import android.annotation.Nullable;
		import android.util.ArrayMap;
		import android.util.Pair;

		import androidx.annotation.NonNull;

		import com.android.systemui.DumpController;
		import com.android.systemui.Dumpable;
		import com.android.systemui.statusbar.notification.collection.listbuilder.OnBeforeRenderListListener;
		import com.android.systemui.statusbar.notification.collection.listbuilder.OnBeforeSortListener;
		import com.android.systemui.statusbar.notification.collection.listbuilder.OnBeforeTransformGroupsListener;
		import com.android.systemui.statusbar.notification.collection.listbuilder.PipelineState;
		import com.android.systemui.statusbar.notification.collection.listbuilder.ShadeListBuilderLogger;
		import com.android.systemui.statusbar.notification.collection.listbuilder.pluggable.NotifComparator;
		import com.android.systemui.statusbar.notification.collection.listbuilder.pluggable.NotifFilter;
		import com.android.systemui.statusbar.notification.collection.listbuilder.pluggable.NotifPromoter;
		import com.android.systemui.statusbar.notification.collection.listbuilder.pluggable.NotifSection;
		import com.android.systemui.statusbar.notification.collection.notifcollection.CollectionReadyForBuildListener;
		import com.android.systemui.statusbar.notification.logging.NotifEvent;
		import com.android.systemui.statusbar.notification.logging.NotifLog;
		import com.android.systemui.util.Assert;
		import com.android.systemui.util.time.SystemClock;

		@@ -69,7 +70,7 @@ import javax.inject.Singleton;
		@Singleton
		public class ShadeListBuilder implements Dumpable {
		private final SystemClock mSystemClock;
		private final NotifLog mNotifLog;
		private final ShadeListBuilderLogger mLogger;

		private List<ListEntry> mNotifList = new ArrayList<>();
		private List<ListEntry> mNewNotifList = new ArrayList<>();
		@@ -98,11 +99,11 @@ public class ShadeListBuilder implements Dumpable {
		@Inject
		public ShadeListBuilder(
		SystemClock systemClock,
		NotifLog notifLog,
		ShadeListBuilderLogger logger,
		DumpController dumpController) {
		Assert.isMainThread();
		mSystemClock = systemClock;
		mNotifLog = notifLog;
		mLogger = logger;
		dumpController.registerDumpable(TAG, this);
		}

		@@ -205,8 +206,7 @@ public class ShadeListBuilder implements Dumpable {
		Assert.isMainThread();
		mPipelineState.requireIsBefore(STATE_BUILD_STARTED);

		mNotifLog.log(NotifEvent.ON_BUILD_LIST, "Request received from "
		+ "NotifCollection");
		mLogger.logOnBuildList();
		mAllEntries = entries;
		buildList();
		}
		@@ -215,21 +215,15 @@ public class ShadeListBuilder implements Dumpable {
		private void onPreGroupFilterInvalidated(NotifFilter filter) {
		Assert.isMainThread();

		mNotifLog.log(NotifEvent.PRE_GROUP_FILTER_INVALIDATED, String.format(
		"Filter \"%s\" invalidated; pipeline state is %d",
		filter.getName(),
		mPipelineState.getState()));
		mLogger.logPreGroupFilterInvalidated(filter.getName(), mPipelineState.getState());

		rebuildListIfBefore(STATE_PRE_GROUP_FILTERING);
		}

		private void onPromoterInvalidated(NotifPromoter filter) {
		private void onPromoterInvalidated(NotifPromoter promoter) {
		Assert.isMainThread();

		mNotifLog.log(NotifEvent.PROMOTER_INVALIDATED, String.format(
		"NotifPromoter \"%s\" invalidated; pipeline state is %d",
		filter.getName(),
		mPipelineState.getState()));
		mLogger.logPromoterInvalidated(promoter.getName(), mPipelineState.getState());

		rebuildListIfBefore(STATE_TRANSFORMING);
		}
		@@ -237,10 +231,7 @@ public class ShadeListBuilder implements Dumpable {
		private void onNotifSectionInvalidated(NotifSection section) {
		Assert.isMainThread();

		mNotifLog.log(NotifEvent.SECTION_INVALIDATED, String.format(
		"Section \"%s\" invalidated; pipeline state is %d",
		section.getName(),
		mPipelineState.getState()));
		mLogger.logNotifSectionInvalidated(section.getName(), mPipelineState.getState());

		rebuildListIfBefore(STATE_SORTING);
		}
		@@ -248,10 +239,7 @@ public class ShadeListBuilder implements Dumpable {
		private void onPreRenderFilterInvalidated(NotifFilter filter) {
		Assert.isMainThread();

		mNotifLog.log(NotifEvent.PRE_RENDER_FILTER_INVALIDATED, String.format(
		"Filter \"%s\" invalidated; pipeline state is %d",
		filter.getName(),
		mPipelineState.getState()));
		mLogger.logPreRenderFilterInvalidated(filter.getName(), mPipelineState.getState());

		rebuildListIfBefore(STATE_PRE_RENDER_FILTERING);
		}
		@@ -259,10 +247,7 @@ public class ShadeListBuilder implements Dumpable {
		private void onNotifComparatorInvalidated(NotifComparator comparator) {
		Assert.isMainThread();

		mNotifLog.log(NotifEvent.COMPARATOR_INVALIDATED, String.format(
		"Comparator \"%s\" invalidated; pipeline state is %d",
		comparator.getName(),
		mPipelineState.getState()));
		mLogger.logNotifComparatorInvalidated(comparator.getName(), mPipelineState.getState());

		rebuildListIfBefore(STATE_SORTING);
		}
		@@ -288,7 +273,7 @@ public class ShadeListBuilder implements Dumpable {
		* if we detect that behavior, we should crash instantly.
		*/
		private void buildList() {
		mNotifLog.log(NotifEvent.START_BUILD_LIST, "Run #" + mIterationCount + "...");
		mLogger.logStartBuildList(mIterationCount);

		mPipelineState.requireIsBefore(STATE_BUILD_STARTED);
		mPipelineState.setState(STATE_BUILD_STARTED);
		@@ -334,16 +319,16 @@ public class ShadeListBuilder implements Dumpable {
		freeEmptyGroups();

		// Step 6: Dispatch the new list, first to any listeners and then to the view layer
		mNotifLog.log(NotifEvent.DISPATCH_FINAL_LIST, "List finalized, is:\n"
		+ ListDumper.dumpTree(mNotifList, false, "\t\t"));
		if (mIterationCount % 10 == 0) {
		mLogger.logFinalList(mNotifList);
		}
		dispatchOnBeforeRenderList(mReadOnlyNotifList);
		if (mOnRenderListListener != null) {
		mOnRenderListListener.onRenderList(mReadOnlyNotifList);
		}

		// Step 7: We're done!
		mNotifLog.log(NotifEvent.LIST_BUILD_COMPLETE,
		"Notif list build #" + mIterationCount + " completed");
		mLogger.logEndBuildList(mIterationCount);
		mPipelineState.setState(STATE_IDLE);
		mIterationCount++;
		}
		@@ -429,11 +414,10 @@ public class ShadeListBuilder implements Dumpable {
		if (existingSummary == null) {
		group.setSummary(entry);
		} else {
		mNotifLog.log(NotifEvent.WARN, String.format(
		"Duplicate summary for group '%s': '%s' vs. '%s'",
		mLogger.logDuplicateSummary(
		group.getKey(),
		existingSummary.getKey(),
		entry.getKey()));
		entry.getKey());

		// Use whichever one was posted most recently
		if (entry.getSbn().getPostTime()
		@@ -452,8 +436,7 @@ public class ShadeListBuilder implements Dumpable {

		final String topLevelKey = entry.getKey();
		if (mGroups.containsKey(topLevelKey)) {
		mNotifLog.log(NotifEvent.WARN,
		"Duplicate non-group top-level key: " + topLevelKey);
		mLogger.logDuplicateTopLevelKey(topLevelKey);
		} else {
		entry.setParent(ROOT_ENTRY);
		out.add(entry);
		@@ -617,24 +600,22 @@ public class ShadeListBuilder implements Dumpable {
		private void logParentingChanges() {
		for (NotificationEntry entry : mAllEntries) {
		if (entry.getParent() != entry.getPreviousParent()) {
		mNotifLog.log(NotifEvent.PARENT_CHANGED, String.format(
		"%s: parent changed from %s to %s",
		mLogger.logParentChanged(
		entry.getKey(),
		entry.getPreviousParent() == null
		? "null" : entry.getPreviousParent().getKey(),
		? null : entry.getPreviousParent().getKey(),
		entry.getParent() == null
		? "null" : entry.getParent().getKey()));
		? null : entry.getParent().getKey());
		}
		}
		for (GroupEntry group : mGroups.values()) {
		if (group.getParent() != group.getPreviousParent()) {
		mNotifLog.log(NotifEvent.PARENT_CHANGED, String.format(
		"%s: parent changed from %s to %s",
		mLogger.logParentChanged(
		group.getKey(),
		group.getPreviousParent() == null
		? "null" : group.getPreviousParent().getKey(),
		? null : group.getPreviousParent().getKey(),
		group.getParent() == null
		? "null" : group.getParent().getKey()));
		? null : group.getParent().getKey());
		}
		}
		}
		@@ -684,23 +665,10 @@ public class ShadeListBuilder implements Dumpable {
		NotifFilter filter = findRejectingFilter(entry, now, filters);

		if (filter != entry.mExcludingFilter) {
		if (entry.mExcludingFilter == null) {
		mNotifLog.log(NotifEvent.FILTER_CHANGED, String.format(
		"%s: filtered out by '%s'",
		entry.getKey(),
		filter.getName()));
		} else if (filter == null) {
		mNotifLog.log(NotifEvent.FILTER_CHANGED, String.format(
		"%s: no longer filtered out (previous filter was '%s')",
		mLogger.logFilterChanged(
		entry.getKey(),
		entry.mExcludingFilter.getName()));
		} else {
		mNotifLog.log(NotifEvent.FILTER_CHANGED, String.format(
		"%s: filter changed: '%s' -> '%s'",
		entry.getKey(),
		entry.mExcludingFilter,
		filter));
		}
		entry.mExcludingFilter != null ? entry.mExcludingFilter.getName() : null,
		filter != null ? filter.getName() : null);

		// Note that groups and summaries can also be filtered out later if they're part of a
		// malformed group. We currently don't have a great way to track that beyond parenting
		@@ -728,23 +696,10 @@ public class ShadeListBuilder implements Dumpable {
		NotifPromoter promoter = findPromoter(entry);

		if (promoter != entry.mNotifPromoter) {
		if (entry.mNotifPromoter == null) {
		mNotifLog.log(NotifEvent.PROMOTER_CHANGED, String.format(
		"%s: Entry promoted to top level by '%s'",
		entry.getKey(),
		promoter.getName()));
		} else if (promoter == null) {
		mNotifLog.log(NotifEvent.PROMOTER_CHANGED, String.format(
		"%s: Entry is no longer promoted to top level (previous promoter was '%s')",
		mLogger.logPromoterChanged(
		entry.getKey(),
		entry.mNotifPromoter.getName()));
		} else {
		mNotifLog.log(NotifEvent.PROMOTER_CHANGED, String.format(
		"%s: Top-level promoter changed: '%s' -> '%s'",
		entry.getKey(),
		entry.mNotifPromoter,
		promoter));
		}
		entry.mNotifPromoter != null ? entry.mNotifPromoter.getName() : null,
		promoter != null ? promoter.getName() : null);
		entry.mNotifPromoter = promoter;
		}

		@@ -767,21 +722,12 @@ public class ShadeListBuilder implements Dumpable {
		final Integer sectionIndex = sectionWithIndex.second;

		if (section != entry.mNotifSection) {
		if (entry.mNotifSection == null) {
		mNotifLog.log(NotifEvent.SECTION_CHANGED, String.format(
		"%s: sectioned by '%s' [index=%d].",
		entry.getKey(),
		section.getName(),
		sectionIndex));
		} else {
		mNotifLog.log(NotifEvent.SECTION_CHANGED, String.format(
		"%s: section changed: '%s' [index=%d] -> '%s [index=%d]'.",
		mLogger.logSectionChanged(
		entry.getKey(),
		entry.mNotifSection,
		entry.mNotifSection != null ? entry.mNotifSection.getName() : null,
		entry.getSection(),
		section,
		sectionIndex));
		}
		section.getName(),
		sectionIndex);

		entry.mNotifSection = section;
		entry.setSection(sectionIndex);
		@@ -826,7 +772,7 @@ public class ShadeListBuilder implements Dumpable {
		}

		@Override
		public void dump(FileDescriptor fd, PrintWriter pw, String[] args) {
		public void dump(@NonNull FileDescriptor fd, PrintWriter pw, @NonNull String[] args) {
		pw.println("\t" + TAG + " shade notifications:");
		if (getShadeList().size() == 0) {
		pw.println("\t\t None");

packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/coalescer/GroupCoalescer.java

+10 −19

Original line number	Diff line number	Diff line
		@@ -16,11 +16,6 @@

		package com.android.systemui.statusbar.notification.collection.coalescer;

		import static com.android.systemui.statusbar.notification.logging.NotifEvent.BATCH_MAX_TIMEOUT;
		import static com.android.systemui.statusbar.notification.logging.NotifEvent.COALESCED_EVENT;
		import static com.android.systemui.statusbar.notification.logging.NotifEvent.EARLY_BATCH_EMIT;
		import static com.android.systemui.statusbar.notification.logging.NotifEvent.EMIT_EVENT_BATCH;

		import static java.util.Objects.requireNonNull;

		import android.annotation.MainThread;
		@@ -35,7 +30,6 @@ import com.android.systemui.Dumpable;
		import com.android.systemui.dagger.qualifiers.Main;
		import com.android.systemui.statusbar.NotificationListener;
		import com.android.systemui.statusbar.NotificationListener.NotificationHandler;
		import com.android.systemui.statusbar.notification.logging.NotifLog;
		import com.android.systemui.util.concurrency.DelayableExecutor;
		import com.android.systemui.util.time.SystemClock;

		@@ -71,7 +65,7 @@ import javax.inject.Inject;
		public class GroupCoalescer implements Dumpable {
		private final DelayableExecutor mMainExecutor;
		private final SystemClock mClock;
		private final NotifLog mLog;
		private final GroupCoalescerLogger mLogger;
		private final long mMinGroupLingerDuration;
		private final long mMaxGroupLingerDuration;

		@@ -83,8 +77,9 @@ public class GroupCoalescer implements Dumpable {
		@Inject
		public GroupCoalescer(
		@Main DelayableExecutor mainExecutor,
		SystemClock clock, NotifLog log) {
		this(mainExecutor, clock, log, MIN_GROUP_LINGER_DURATION, MAX_GROUP_LINGER_DURATION);
		SystemClock clock,
		GroupCoalescerLogger logger) {
		this(mainExecutor, clock, logger, MIN_GROUP_LINGER_DURATION, MAX_GROUP_LINGER_DURATION);
		}

		/**
		@@ -98,12 +93,12 @@ public class GroupCoalescer implements Dumpable {
		GroupCoalescer(
		@Main DelayableExecutor mainExecutor,
		SystemClock clock,
		NotifLog log,
		GroupCoalescerLogger logger,
		long minGroupLingerDuration,
		long maxGroupLingerDuration) {
		mMainExecutor = mainExecutor;
		mClock = clock;
		mLog = log;
		mLogger = logger;
		mMinGroupLingerDuration = minGroupLingerDuration;
		mMaxGroupLingerDuration = maxGroupLingerDuration;
		}
		@@ -129,7 +124,7 @@ public class GroupCoalescer implements Dumpable {
		final boolean shouldCoalesce = handleNotificationPosted(sbn, rankingMap);

		if (shouldCoalesce) {
		mLog.log(COALESCED_EVENT, String.format("Coalesced notification %s", sbn.getKey()));
		mLogger.logEventCoalesced(sbn.getKey());
		mHandler.onNotificationRankingUpdate(rankingMap);
		} else {
		mHandler.onNotificationPosted(sbn, rankingMap);
		@@ -164,15 +159,11 @@ public class GroupCoalescer implements Dumpable {
		final CoalescedEvent event = mCoalescedEvents.get(sbn.getKey());
		final EventBatch batch = mBatches.get(sbn.getGroupKey());
		if (event != null) {
		mLog.log(EARLY_BATCH_EMIT,
		String.format("Modification of %s triggered early emit of batched group %s",
		sbn.getKey(), requireNonNull(event.getBatch()).mGroupKey));
		mLogger.logEarlyEmit(sbn.getKey(), requireNonNull(event.getBatch()).mGroupKey);
		emitBatch(requireNonNull(event.getBatch()));
		} else if (batch != null
		&& mClock.uptimeMillis() - batch.mCreatedTimestamp >= mMaxGroupLingerDuration) {
		mLog.log(BATCH_MAX_TIMEOUT,
		String.format("Modification of %s triggered timeout emit of batched group %s",
		sbn.getKey(), batch.mGroupKey));
		mLogger.logMaxBatchTimeout(sbn.getKey(), batch.mGroupKey);
		emitBatch(batch);
		}
		}
		@@ -253,7 +244,7 @@ public class GroupCoalescer implements Dumpable {
		}
		events.sort(mEventComparator);

		mLog.log(EMIT_EVENT_BATCH, "Emitting event batch for group " + batch.mGroupKey);
		mLogger.logEmitBatch(batch.mGroupKey);

		mHandler.onNotificationBatchPosted(events);
		}

packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/coalescer/GroupCoalescerLogger.kt

0 → 100644

+62 −0

Original line number	Diff line number	Diff line
		/*
		* Copyright (C) 2020 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.systemui.statusbar.notification.collection.coalescer

		import com.android.systemui.log.LogBuffer
		import com.android.systemui.log.LogLevel
		import com.android.systemui.log.dagger.NotificationLog
		import javax.inject.Inject

		class GroupCoalescerLogger @Inject constructor(
		@NotificationLog private val buffer: LogBuffer
		) {
		fun logEventCoalesced(key: String) {
		buffer.log(TAG, LogLevel.INFO, {
		str1 = key
		}, {
		"COALESCED: $str1"
		})
		}

		fun logEmitBatch(groupKey: String) {
		buffer.log(TAG, LogLevel.DEBUG, {
		str1 = groupKey
		}, {
		"Emitting event batch for group $str1"
		})
		}

		fun logEarlyEmit(modifiedKey: String, groupKey: String) {
		buffer.log(TAG, LogLevel.DEBUG, {
		str1 = modifiedKey
		str2 = groupKey
		}, {
		"Modification of notif $str1 triggered early emit of batched group $str2"
		})
		}

		fun logMaxBatchTimeout(modifiedKey: String, groupKey: String) {
		buffer.log(TAG, LogLevel.INFO, {
		str1 = modifiedKey
		str2 = groupKey
		}, {
		"Modification of notif $str1 triggered TIMEOUT emit of batched group $str2"
		})
		}
		}

		private const val TAG = "GroupCoalescer"
		No newline at end of file

packages/SystemUI/src/com/android/systemui/statusbar/notification/collection/listbuilder/ShadeListBuilderLogger.kt

0 → 100644

+217 −0

File added.

Preview size limit exceeded, changes collapsed.