1 /*
2  * Copyright (C) 2020 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  *      http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 
17 package com.android.systemui.statusbar.notification.collection.notifcollection
18 
19 import android.os.RemoteException
20 import android.service.notification.NotificationListenerService
21 import android.service.notification.NotificationListenerService.RankingMap
22 import android.service.notification.StatusBarNotification
23 import com.android.systemui.log.dagger.NotificationLog
24 import com.android.systemui.log.LogBuffer
25 import com.android.systemui.log.core.LogLevel.DEBUG
26 import com.android.systemui.log.core.LogLevel.ERROR
27 import com.android.systemui.log.core.LogLevel.INFO
28 import com.android.systemui.log.core.LogLevel.WARNING
29 import com.android.systemui.log.core.LogLevel.WTF
30 import com.android.systemui.statusbar.notification.collection.NotifCollection
31 import com.android.systemui.statusbar.notification.collection.NotifCollection.CancellationReason
32 import com.android.systemui.statusbar.notification.collection.NotifCollection.FutureDismissal
33 import com.android.systemui.statusbar.notification.collection.NotificationEntry
34 import com.android.systemui.statusbar.notification.logKey
35 import javax.inject.Inject
36 
37 fun cancellationReasonDebugString(@CancellationReason reason: Int) =
38     "$reason:" + when (reason) {
39         -1 -> "REASON_NOT_CANCELED" // NotifCollection.REASON_NOT_CANCELED
40         NotifCollection.REASON_UNKNOWN -> "REASON_UNKNOWN"
41         NotificationListenerService.REASON_CLICK -> "REASON_CLICK"
42         NotificationListenerService.REASON_CANCEL -> "REASON_CANCEL"
43         NotificationListenerService.REASON_CANCEL_ALL -> "REASON_CANCEL_ALL"
44         NotificationListenerService.REASON_ERROR -> "REASON_ERROR"
45         NotificationListenerService.REASON_PACKAGE_CHANGED -> "REASON_PACKAGE_CHANGED"
46         NotificationListenerService.REASON_USER_STOPPED -> "REASON_USER_STOPPED"
47         NotificationListenerService.REASON_PACKAGE_BANNED -> "REASON_PACKAGE_BANNED"
48         NotificationListenerService.REASON_APP_CANCEL -> "REASON_APP_CANCEL"
49         NotificationListenerService.REASON_APP_CANCEL_ALL -> "REASON_APP_CANCEL_ALL"
50         NotificationListenerService.REASON_LISTENER_CANCEL -> "REASON_LISTENER_CANCEL"
51         NotificationListenerService.REASON_LISTENER_CANCEL_ALL -> "REASON_LISTENER_CANCEL_ALL"
52         NotificationListenerService.REASON_GROUP_SUMMARY_CANCELED -> "REASON_GROUP_SUMMARY_CANCELED"
53         NotificationListenerService.REASON_GROUP_OPTIMIZATION -> "REASON_GROUP_OPTIMIZATION"
54         NotificationListenerService.REASON_PACKAGE_SUSPENDED -> "REASON_PACKAGE_SUSPENDED"
55         NotificationListenerService.REASON_PROFILE_TURNED_OFF -> "REASON_PROFILE_TURNED_OFF"
56         NotificationListenerService.REASON_UNAUTOBUNDLED -> "REASON_UNAUTOBUNDLED"
57         NotificationListenerService.REASON_CHANNEL_BANNED -> "REASON_CHANNEL_BANNED"
58         NotificationListenerService.REASON_SNOOZED -> "REASON_SNOOZED"
59         NotificationListenerService.REASON_TIMEOUT -> "REASON_TIMEOUT"
60         NotificationListenerService.REASON_CHANNEL_REMOVED -> "REASON_CHANNEL_REMOVED"
61         NotificationListenerService.REASON_CLEAR_DATA -> "REASON_CLEAR_DATA"
62         NotificationListenerService.REASON_ASSISTANT_CANCEL -> "REASON_ASSISTANT_CANCEL"
63         else -> "unknown"
64     }
65 
66 class NotifCollectionLogger @Inject constructor(
67     @NotificationLog private val buffer: LogBuffer
68 ) {
69     fun logNotifPosted(entry: NotificationEntry) {
70         buffer.log(TAG, INFO, {
71             str1 = entry.logKey
72         }, {
73             "POSTED $str1"
74         })
75     }
76 
77     fun logNotifGroupPosted(groupKey: String, batchSize: Int) {
78         buffer.log(TAG, INFO, {
79             str1 = logKey(groupKey)
80             int1 = batchSize
81         }, {
82             "POSTED GROUP $str1 ($int1 events)"
83         })
84     }
85 
86     fun logNotifUpdated(entry: NotificationEntry) {
87         buffer.log(TAG, INFO, {
88             str1 = entry.logKey
89         }, {
90             "UPDATED $str1"
91         })
92     }
93 
94     fun logNotifRemoved(sbn: StatusBarNotification, @CancellationReason reason: Int) {
95         buffer.log(TAG, INFO, {
96             str1 = sbn.logKey
97             int1 = reason
98         }, {
99             "REMOVED $str1 reason=${cancellationReasonDebugString(int1)}"
100         })
101     }
102 
103     fun logNotifReleased(entry: NotificationEntry) {
104         buffer.log(TAG, INFO, {
105             str1 = entry.logKey
106         }, {
107             "RELEASED $str1"
108         })
109     }
110 
111     fun logLocallyDismissed(entry: NotificationEntry, index: Int, count: Int) {
112         buffer.log(TAG, INFO, {
113             str1 = entry.logKey
114             int1 = index
115             int2 = count
116         }, {
117             "LOCALLY DISMISSED $str1 ($int1/$int2)"
118         })
119     }
120 
121     fun logDismissNonExistentNotif(entry: NotificationEntry, index: Int, count: Int) {
122         buffer.log(TAG, INFO, {
123             str1 = entry.logKey
124             int1 = index
125             int2 = count
126         }, {
127             "DISMISS Non Existent $str1 ($int1/$int2)"
128         })
129     }
130 
131     fun logLocallyDismissedChild(
132             child: NotificationEntry,
133             parent: NotificationEntry,
134             parentIndex: Int,
135             parentCount: Int
136     ) {
137         buffer.log(TAG, DEBUG, {
138             str1 = child.logKey
139             str2 = parent.logKey
140             int1 = parentIndex
141             int2 = parentCount
142         }, {
143             "LOCALLY DISMISSED CHILD (inferred): $str1 of parent $str2 ($int1/$int2)"
144         })
145     }
146 
147     fun logDismissAll(userId: Int) {
148         buffer.log(TAG, INFO, {
149             int1 = userId
150         }, {
151             "DISMISS ALL notifications for user $int1"
152         })
153     }
154 
155     fun logLocallyDismissedAlreadyCanceledEntry(entry: NotificationEntry) {
156         buffer.log(TAG, DEBUG, {
157             str1 = entry.logKey
158         }, {
159             "LOCALLY DISMISSED Already Canceled $str1. Trying to remove."
160         })
161     }
162 
163     fun logNotifDismissedIntercepted(entry: NotificationEntry, index: Int, count: Int) {
164         buffer.log(TAG, INFO, {
165             str1 = entry.logKey
166             int1 = index
167             int2 = count
168         }, {
169             "DISMISS INTERCEPTED $str1 ($int1/$int2)"
170         })
171     }
172 
173     fun logNotifClearAllDismissalIntercepted(entry: NotificationEntry, index: Int, count: Int) {
174         buffer.log(TAG, INFO, {
175             str1 = entry.logKey
176             int1 = index
177             int2 = count
178         }, {
179             "CLEAR ALL DISMISSAL INTERCEPTED $str1 ($int1/$int2)"
180         })
181     }
182 
183     fun logNotifInternalUpdate(entry: NotificationEntry, name: String, reason: String) {
184         buffer.log(TAG, INFO, {
185             str1 = entry.logKey
186             str2 = name
187             str3 = reason
188         }, {
189             "UPDATED INTERNALLY $str1 BY $str2 BECAUSE $str3"
190         })
191     }
192 
193     fun logNotifInternalUpdateFailed(sbn: StatusBarNotification, name: String, reason: String) {
194         buffer.log(TAG, INFO, {
195             str1 = sbn.logKey
196             str2 = name
197             str3 = reason
198         }, {
199             "FAILED INTERNAL UPDATE $str1 BY $str2 BECAUSE $str3"
200         })
201     }
202 
203     fun logNoNotificationToRemoveWithKey(
204         sbn: StatusBarNotification,
205         @CancellationReason reason: Int
206     ) {
207         buffer.log(TAG, ERROR, {
208             str1 = sbn.logKey
209             int1 = reason
210         }, {
211             "No notification to remove with key $str1 reason=${cancellationReasonDebugString(int1)}"
212         })
213     }
214 
215     fun logMissingRankings(
216         newlyInconsistentEntries: List<NotificationEntry>,
217         totalInconsistent: Int,
218         rankingMap: RankingMap
219     ) {
220         buffer.log(TAG, WARNING, {
221             int1 = totalInconsistent
222             int2 = newlyInconsistentEntries.size
223             str1 = newlyInconsistentEntries.joinToString { it.logKey ?: "null" }
224         }, {
225             "Ranking update is missing ranking for $int1 entries ($int2 new): $str1"
226         })
227         buffer.log(TAG, DEBUG, {
228             str1 = rankingMap.orderedKeys.map { logKey(it) ?: "null" }.toString()
229         }, {
230             "Ranking map contents: $str1"
231         })
232     }
233 
234     fun logRecoveredRankings(newlyConsistentKeys: List<String>, totalInconsistent: Int) {
235         buffer.log(TAG, INFO, {
236             int1 = totalInconsistent
237             int1 = newlyConsistentKeys.size
238             str1 = newlyConsistentKeys.joinToString { logKey(it) ?: "null" }
239         }, {
240             "Ranking update now contains rankings for $int1 previously inconsistent entries: $str1"
241         })
242     }
243 
244     fun logMissingNotifications(
245         newlyMissingKeys: List<String>,
246         totalMissing: Int,
247     ) {
248         buffer.log(TAG, WARNING, {
249             int1 = totalMissing
250             int2 = newlyMissingKeys.size
251             str1 = newlyMissingKeys.joinToString { logKey(it) ?: "null" }
252         }, {
253             "Collection missing $int1 entries in ranking update. Just lost $int2: $str1"
254         })
255     }
256 
257     fun logFoundNotifications(
258         newlyFoundKeys: List<String>,
259         totalMissing: Int,
260     ) {
261         buffer.log(TAG, INFO, {
262             int1 = totalMissing
263             int2 = newlyFoundKeys.size
264             str1 = newlyFoundKeys.joinToString { logKey(it) ?: "null" }
265         }, {
266             "Collection missing $int1 entries in ranking update. Just found $int2: $str1"
267         })
268     }
269 
270     fun logRemoteExceptionOnNotificationClear(
271             entry: NotificationEntry,
272             index: Int,
273             count: Int,
274             e: RemoteException
275     ) {
276         buffer.log(TAG, WTF, {
277             str1 = entry.logKey
278             int1 = index
279             int2 = count
280             str2 = e.toString()
281         }, {
282             "RemoteException while attempting to clear $str1 ($int1/$int2):\n$str2"
283         })
284     }
285 
286     fun logRemoteExceptionOnClearAllNotifications(e: RemoteException) {
287         buffer.log(TAG, WTF, {
288             str1 = e.toString()
289         }, {
290             "RemoteException while attempting to clear all notifications:\n$str1"
291         })
292     }
293 
294     fun logLifetimeExtended(entry: NotificationEntry, extender: NotifLifetimeExtender) {
295         buffer.log(TAG, INFO, {
296             str1 = entry.logKey
297             str2 = extender.name
298         }, {
299             "LIFETIME EXTENDED: $str1 by $str2"
300         })
301     }
302 
303     fun logLifetimeExtensionEnded(
304         entry: NotificationEntry,
305         extender: NotifLifetimeExtender,
306         totalExtenders: Int
307     ) {
308         buffer.log(TAG, INFO, {
309             str1 = entry.logKey
310             str2 = extender.name
311             int1 = totalExtenders
312         }, {
313             "LIFETIME EXTENSION ENDED for $str1 by '$str2'; $int1 remaining extensions"
314         })
315     }
316 
317     fun logIgnoredError(message: String?) {
318         buffer.log(TAG, ERROR, {
319             str1 = message
320         }, {
321             "ERROR suppressed due to initialization forgiveness: $str1"
322         })
323     }
324 
325     fun logEntryBeingExtendedNotInCollection(
326         entry: NotificationEntry,
327         extender: NotifLifetimeExtender,
328         collectionEntryIs: String
329     ) {
330         buffer.log(TAG, WARNING, {
331             str1 = entry.logKey
332             str2 = extender.name
333             str3 = collectionEntryIs
334         }, {
335             "While ending lifetime extension by $str2 of $str1, entry in collection is $str3"
336         })
337     }
338 
339     fun logFutureDismissalReused(dismissal: FutureDismissal) {
340         buffer.log(TAG, INFO, {
341             str1 = dismissal.label
342         }, {
343             "Reusing existing registration: $str1"
344         })
345     }
346 
347     fun logFutureDismissalRegistered(dismissal: FutureDismissal) {
348         buffer.log(TAG, DEBUG, {
349             str1 = dismissal.label
350         }, {
351             "Registered: $str1"
352         })
353     }
354 
355     fun logFutureDismissalDoubleCancelledByServer(dismissal: FutureDismissal) {
356         buffer.log(TAG, WARNING, {
357             str1 = dismissal.label
358         }, {
359             "System server double cancelled: $str1"
360         })
361     }
362 
363     fun logFutureDismissalDoubleRun(dismissal: FutureDismissal) {
364         buffer.log(TAG, WARNING, {
365             str1 = dismissal.label
366         }, {
367             "Double run: $str1"
368         })
369     }
370 
371     fun logFutureDismissalAlreadyCancelledByServer(dismissal: FutureDismissal) {
372         buffer.log(TAG, DEBUG, {
373             str1 = dismissal.label
374         }, {
375             "Ignoring: entry already cancelled by server: $str1"
376         })
377     }
378 
379     fun logFutureDismissalGotSystemServerCancel(
380         dismissal: FutureDismissal,
381         @CancellationReason cancellationReason: Int
382     ) {
383         buffer.log(TAG, DEBUG, {
384             str1 = dismissal.label
385             int1 = cancellationReason
386         }, {
387             "SystemServer cancelled: $str1 reason=${cancellationReasonDebugString(int1)}"
388         })
389     }
390 
391     fun logFutureDismissalDismissing(dismissal: FutureDismissal, type: String) {
392         buffer.log(TAG, DEBUG, {
393             str1 = dismissal.label
394             str2 = type
395         }, {
396             "Dismissing $str2 for: $str1"
397         })
398     }
399 
400     fun logFutureDismissalMismatchedEntry(
401         dismissal: FutureDismissal,
402         type: String,
403         latestEntry: NotificationEntry?
404     ) {
405         buffer.log(TAG, WARNING, {
406             str1 = dismissal.label
407             str2 = type
408             str3 = latestEntry.logKey
409         }, {
410             "Mismatch: current $str2 is $str3 for: $str1"
411         })
412     }
413 
414     fun logDismissAlreadyDismissedNotif(entry: NotificationEntry, index: Int, count: Int) {
415         buffer.log(TAG, DEBUG, {
416             str1 = entry.logKey
417             int1 = index
418             int2 = count
419         }, {
420             "DISMISS Already Dismissed $str1 ($int1/$int2)"
421         })
422     }
423 
424     fun logDismissAlreadyParentDismissedNotif(
425             childEntry: NotificationEntry,
426             childIndex: Int,
427             childCount: Int
428     ) {
429         buffer.log(TAG, DEBUG, {
430             str1 = childEntry.logKey
431             int1 = childIndex
432             int2 = childCount
433             str2 = childEntry.parent?.summary?.logKey ?: "(null)"
434         }, {
435             "DISMISS Already Parent-Dismissed $str1 ($int1/$int2) with summary $str2"
436         })
437     }
438 
439     fun logLocallyDismissNonExistentNotif(entry: NotificationEntry, index: Int, count: Int) {
440         buffer.log(TAG, INFO, {
441             str1 = entry.logKey
442             int1 = index
443             int2 = count
444         }, {
445             "LOCALLY DISMISS Non Existent $str1 ($int1/$int2)"
446         })
447     }
448 
449     fun logLocallyDismissMismatchedEntry(
450             entry: NotificationEntry,
451             index: Int,
452             count: Int,
453             storedEntry: NotificationEntry
454     ) {
455         buffer.log(TAG, INFO, {
456             str1 = entry.logKey
457             int1 = index
458             int2 = count
459             str2 = Integer.toHexString(entry.hashCode())
460             str3 = Integer.toHexString(storedEntry.hashCode())
461         }, {
462             "LOCALLY DISMISS Mismatch $str1 ($int1/$int2): dismissing @$str2 but stored @$str3"
463         })
464     }
465 
466     fun logLocallyDismissAlreadyDismissedNotif(
467             entry: NotificationEntry,
468             index: Int,
469             count: Int
470     ) {
471         buffer.log(TAG, INFO, {
472             str1 = entry.logKey
473             int1 = index
474             int2 = count
475         }, {
476             "LOCALLY DISMISS Already Dismissed $str1 ($int1/$int2)"
477         })
478     }
479 
480     fun logLocallyDismissAlreadyParentDismissedNotif(
481             entry: NotificationEntry,
482             index: Int,
483             count: Int
484     ) {
485         buffer.log(TAG, INFO, {
486             str1 = entry.logKey
487             int1 = index
488             int2 = count
489         }, {
490             "LOCALLY DISMISS Already Dismissed $str1 ($int1/$int2)"
491         })
492     }
493 
494     fun logLocallyDismissAlreadyDismissedChild(
495             childEntry: NotificationEntry,
496             parentEntry: NotificationEntry,
497             parentIndex: Int,
498             parentCount: Int
499     ) {
500         buffer.log(TAG, INFO, {
501             str1 = childEntry.logKey
502             str2 = parentEntry.logKey
503             int1 = parentIndex
504             int2 = parentCount
505         }, {
506             "LOCALLY DISMISS Already Dismissed Child $str1 of parent $str2 ($int1/$int2)"
507         })
508     }
509 
510     fun logLocallyDismissAlreadyParentDismissedChild(
511             childEntry: NotificationEntry,
512             parentEntry: NotificationEntry,
513             parentIndex: Int,
514             parentCount: Int
515     ) {
516         buffer.log(TAG, INFO, {
517             str1 = childEntry.logKey
518             str2 = parentEntry.logKey
519             int1 = parentIndex
520             int2 = parentCount
521         }, {
522             "LOCALLY DISMISS Already Parent-Dismissed Child $str1 of parent $str2 ($int1/$int2)"
523         })
524     }
525 
526     fun logCancelLocalDismissalNotDismissedNotif(entry: NotificationEntry) {
527         buffer.log(TAG, INFO, {
528             str1 = entry.logKey
529         }, {
530             "CANCEL LOCAL DISMISS Not Dismissed $str1"
531         })
532     }
533 }
534 
535 private const val TAG = "NotifCollection"
536