NotificationUsageStats.java revision 333a61c3a5a83fe9c50ebeb5c947317f61385b7b
1/* 2 * Copyright (C) 2014 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 17package com.android.server.notification; 18 19import android.content.ContentValues; 20import android.content.Context; 21import android.database.Cursor; 22import android.database.sqlite.SQLiteDatabase; 23import android.database.sqlite.SQLiteOpenHelper; 24import android.os.Handler; 25import android.os.HandlerThread; 26import android.os.Message; 27import android.os.SystemClock; 28import android.service.notification.StatusBarNotification; 29import android.util.Log; 30 31import java.io.PrintWriter; 32import java.util.HashMap; 33import java.util.Map; 34 35/** 36 * Keeps track of notification activity, display, and user interaction. 37 * 38 * <p>This class receives signals from NoMan and keeps running stats of 39 * notification usage. Some metrics are updated as events occur. Others, namely 40 * those involving durations, are updated as the notification is canceled.</p> 41 * 42 * <p>This class is thread-safe.</p> 43 * 44 * {@hide} 45 */ 46public class NotificationUsageStats { 47 private static final boolean ENABLE_SQLITE_LOG = false; 48 49 // Guarded by synchronized(this). 50 private final Map<String, AggregatedStats> mStats = new HashMap<String, AggregatedStats>(); 51 private final SQLiteLog mSQLiteLog; 52 53 public NotificationUsageStats(Context context) { 54 mSQLiteLog = ENABLE_SQLITE_LOG ? new SQLiteLog(context) : null; 55 } 56 57 /** 58 * Called when a notification has been posted. 59 */ 60 public synchronized void registerPostedByApp(NotificationRecord notification) { 61 notification.stats = new SingleNotificationStats(); 62 notification.stats.posttimeElapsedMs = SystemClock.elapsedRealtime(); 63 for (AggregatedStats stats : getAggregatedStatsLocked(notification)) { 64 stats.numPostedByApp++; 65 } 66 if (ENABLE_SQLITE_LOG) { 67 mSQLiteLog.logPosted(notification); 68 } 69 } 70 71 /** 72 * Called when a notification has been updated. 73 */ 74 public void registerUpdatedByApp(NotificationRecord notification, NotificationRecord old) { 75 notification.stats = old.stats; 76 for (AggregatedStats stats : getAggregatedStatsLocked(notification)) { 77 stats.numUpdatedByApp++; 78 } 79 } 80 81 /** 82 * Called when the originating app removed the notification programmatically. 83 */ 84 public synchronized void registerRemovedByApp(NotificationRecord notification) { 85 notification.stats.onRemoved(); 86 for (AggregatedStats stats : getAggregatedStatsLocked(notification)) { 87 stats.numRemovedByApp++; 88 stats.collect(notification.stats); 89 } 90 if (ENABLE_SQLITE_LOG) { 91 mSQLiteLog.logRemoved(notification); 92 } 93 } 94 95 /** 96 * Called when the user dismissed the notification via the UI. 97 */ 98 public synchronized void registerDismissedByUser(NotificationRecord notification) { 99 notification.stats.onDismiss(); 100 for (AggregatedStats stats : getAggregatedStatsLocked(notification)) { 101 stats.numDismissedByUser++; 102 stats.collect(notification.stats); 103 } 104 if (ENABLE_SQLITE_LOG) { 105 mSQLiteLog.logDismissed(notification); 106 } 107 } 108 109 /** 110 * Called when the user clicked the notification in the UI. 111 */ 112 public synchronized void registerClickedByUser(NotificationRecord notification) { 113 notification.stats.onClick(); 114 for (AggregatedStats stats : getAggregatedStatsLocked(notification)) { 115 stats.numClickedByUser++; 116 } 117 if (ENABLE_SQLITE_LOG) { 118 mSQLiteLog.logClicked(notification); 119 } 120 } 121 122 /** 123 * Called when the notification is canceled because the user clicked it. 124 * 125 * <p>Called after {@link #registerClickedByUser(NotificationRecord)}.</p> 126 */ 127 public synchronized void registerCancelDueToClick(NotificationRecord notification) { 128 notification.stats.onCancel(); 129 for (AggregatedStats stats : getAggregatedStatsLocked(notification)) { 130 stats.collect(notification.stats); 131 } 132 } 133 134 /** 135 * Called when the notification is canceled due to unknown reasons. 136 * 137 * <p>Called for notifications of apps being uninstalled, for example.</p> 138 */ 139 public synchronized void registerCancelUnknown(NotificationRecord notification) { 140 notification.stats.onCancel(); 141 for (AggregatedStats stats : getAggregatedStatsLocked(notification)) { 142 stats.collect(notification.stats); 143 } 144 } 145 146 // Locked by this. 147 private AggregatedStats[] getAggregatedStatsLocked(NotificationRecord record) { 148 StatusBarNotification n = record.sbn; 149 150 String user = String.valueOf(n.getUserId()); 151 String userPackage = user + ":" + n.getPackageName(); 152 153 // TODO: Use pool of arrays. 154 return new AggregatedStats[] { 155 getOrCreateAggregatedStatsLocked(user), 156 getOrCreateAggregatedStatsLocked(userPackage), 157 getOrCreateAggregatedStatsLocked(n.getKey()), 158 }; 159 } 160 161 // Locked by this. 162 private AggregatedStats getOrCreateAggregatedStatsLocked(String key) { 163 AggregatedStats result = mStats.get(key); 164 if (result == null) { 165 result = new AggregatedStats(key); 166 mStats.put(key, result); 167 } 168 return result; 169 } 170 171 public synchronized void dump(PrintWriter pw, String indent) { 172 for (AggregatedStats as : mStats.values()) { 173 as.dump(pw, indent); 174 } 175 if (ENABLE_SQLITE_LOG) { 176 mSQLiteLog.dump(pw, indent); 177 } 178 } 179 180 /** 181 * Aggregated notification stats. 182 */ 183 private static class AggregatedStats { 184 public final String key; 185 186 // ---- Updated as the respective events occur. 187 public int numPostedByApp; 188 public int numUpdatedByApp; 189 public int numRemovedByApp; 190 public int numClickedByUser; 191 public int numDismissedByUser; 192 193 // ---- Updated when a notification is canceled. 194 public final Aggregate posttimeMs = new Aggregate(); 195 public final Aggregate posttimeToDismissMs = new Aggregate(); 196 public final Aggregate posttimeToFirstClickMs = new Aggregate(); 197 public final Aggregate airtimeCount = new Aggregate(); 198 public final Aggregate airtimeMs = new Aggregate(); 199 public final Aggregate posttimeToFirstAirtimeMs = new Aggregate(); 200 201 public AggregatedStats(String key) { 202 this.key = key; 203 } 204 205 public void collect(SingleNotificationStats singleNotificationStats) { 206 posttimeMs.addSample( 207 SystemClock.elapsedRealtime() - singleNotificationStats.posttimeElapsedMs); 208 if (singleNotificationStats.posttimeToDismissMs >= 0) { 209 posttimeToDismissMs.addSample(singleNotificationStats.posttimeToDismissMs); 210 } 211 if (singleNotificationStats.posttimeToFirstClickMs >= 0) { 212 posttimeToFirstClickMs.addSample(singleNotificationStats.posttimeToFirstClickMs); 213 } 214 airtimeCount.addSample(singleNotificationStats.airtimeCount); 215 if (singleNotificationStats.airtimeMs >= 0) { 216 airtimeMs.addSample(singleNotificationStats.airtimeMs); 217 } 218 if (singleNotificationStats.posttimeToFirstAirtimeMs >= 0) { 219 posttimeToFirstAirtimeMs.addSample( 220 singleNotificationStats.posttimeToFirstAirtimeMs); 221 } 222 } 223 224 public void dump(PrintWriter pw, String indent) { 225 pw.println(toStringWithIndent(indent)); 226 } 227 228 @Override 229 public String toString() { 230 return toStringWithIndent(""); 231 } 232 233 private String toStringWithIndent(String indent) { 234 return indent + "AggregatedStats{\n" + 235 indent + " key='" + key + "',\n" + 236 indent + " numPostedByApp=" + numPostedByApp + ",\n" + 237 indent + " numUpdatedByApp=" + numUpdatedByApp + ",\n" + 238 indent + " numRemovedByApp=" + numRemovedByApp + ",\n" + 239 indent + " numClickedByUser=" + numClickedByUser + ",\n" + 240 indent + " numDismissedByUser=" + numDismissedByUser + ",\n" + 241 indent + " posttimeMs=" + posttimeMs + ",\n" + 242 indent + " posttimeToDismissMs=" + posttimeToDismissMs + ",\n" + 243 indent + " posttimeToFirstClickMs=" + posttimeToFirstClickMs + ",\n" + 244 indent + " airtimeCount=" + airtimeCount + ",\n" + 245 indent + " airtimeMs=" + airtimeMs + ",\n" + 246 indent + " posttimeToFirstAirtimeMs=" + posttimeToFirstAirtimeMs + ",\n" + 247 indent + "}"; 248 } 249 } 250 251 /** 252 * Tracks usage of an individual notification that is currently active. 253 */ 254 public static class SingleNotificationStats { 255 /** SystemClock.elapsedRealtime() when the notification was posted. */ 256 public long posttimeElapsedMs = -1; 257 /** Elapsed time since the notification was posted until it was first clicked, or -1. */ 258 public long posttimeToFirstClickMs = -1; 259 /** Elpased time since the notification was posted until it was dismissed by the user. */ 260 public long posttimeToDismissMs = -1; 261 /** Number of times the notification has been made visible. */ 262 public long airtimeCount = 0; 263 /** Time in ms between the notification was posted and first shown; -1 if never shown. */ 264 public long posttimeToFirstAirtimeMs = -1; 265 /** 266 * If currently visible, SystemClock.elapsedRealtime() when the notification was made 267 * visible; -1 otherwise. 268 */ 269 public long currentAirtimeStartElapsedMs = -1; 270 /** Accumulated visible time. */ 271 public long airtimeMs = 0; 272 273 public long getCurrentPosttimeMs() { 274 if (posttimeElapsedMs < 0) { 275 return 0; 276 } 277 return SystemClock.elapsedRealtime() - posttimeElapsedMs; 278 } 279 280 public long getCurrentAirtimeMs() { 281 long result = airtimeMs; 282 // Add incomplete airtime if currently shown. 283 if (currentAirtimeStartElapsedMs >= 0) { 284 result+= (SystemClock.elapsedRealtime() - currentAirtimeStartElapsedMs); 285 } 286 return result; 287 } 288 289 /** 290 * Called when the user clicked the notification. 291 */ 292 public void onClick() { 293 if (posttimeToFirstClickMs < 0) { 294 posttimeToFirstClickMs = SystemClock.elapsedRealtime() - posttimeElapsedMs; 295 } 296 } 297 298 /** 299 * Called when the user removed the notification. 300 */ 301 public void onDismiss() { 302 if (posttimeToDismissMs < 0) { 303 posttimeToDismissMs = SystemClock.elapsedRealtime() - posttimeElapsedMs; 304 } 305 finish(); 306 } 307 308 public void onCancel() { 309 finish(); 310 } 311 312 public void onRemoved() { 313 finish(); 314 } 315 316 public void onVisibilityChanged(boolean visible) { 317 long elapsedNowMs = SystemClock.elapsedRealtime(); 318 if (visible) { 319 if (currentAirtimeStartElapsedMs < 0) { 320 airtimeCount++; 321 currentAirtimeStartElapsedMs = elapsedNowMs; 322 } 323 if (posttimeToFirstAirtimeMs < 0) { 324 posttimeToFirstAirtimeMs = elapsedNowMs - posttimeElapsedMs; 325 } 326 } else { 327 if (currentAirtimeStartElapsedMs >= 0) { 328 airtimeMs += (elapsedNowMs - currentAirtimeStartElapsedMs); 329 currentAirtimeStartElapsedMs = -1; 330 } 331 } 332 } 333 334 /** The notification is leaving the system. Finalize. */ 335 public void finish() { 336 onVisibilityChanged(false); 337 } 338 339 @Override 340 public String toString() { 341 return "SingleNotificationStats{" + 342 "posttimeElapsedMs=" + posttimeElapsedMs + 343 ", posttimeToFirstClickMs=" + posttimeToFirstClickMs + 344 ", posttimeToDismissMs=" + posttimeToDismissMs + 345 ", airtimeCount=" + airtimeCount + 346 ", airtimeMs=" + airtimeMs + 347 ", currentAirtimeStartElapsedMs=" + currentAirtimeStartElapsedMs + 348 '}'; 349 } 350 } 351 352 /** 353 * Aggregates long samples to sum and averages. 354 */ 355 public static class Aggregate { 356 long numSamples; 357 double avg; 358 double sum2; 359 double var; 360 361 public void addSample(long sample) { 362 // Welford's "Method for Calculating Corrected Sums of Squares" 363 // http://www.jstor.org/stable/1266577?seq=2 364 numSamples++; 365 final double n = numSamples; 366 final double delta = sample - avg; 367 avg += (1.0 / n) * delta; 368 sum2 += ((n - 1) / n) * delta * delta; 369 final double divisor = numSamples == 1 ? 1.0 : n - 1.0; 370 var = sum2 / divisor; 371 } 372 373 @Override 374 public String toString() { 375 return "Aggregate{" + 376 "numSamples=" + numSamples + 377 ", avg=" + avg + 378 ", var=" + var + 379 '}'; 380 } 381 } 382 383 private static class SQLiteLog { 384 private static final String TAG = "NotificationSQLiteLog"; 385 386 // Message types passed to the background handler. 387 private static final int MSG_POST = 1; 388 private static final int MSG_CLICK = 2; 389 private static final int MSG_REMOVE = 3; 390 private static final int MSG_DISMISS = 4; 391 392 private static final String DB_NAME = "notification_log.db"; 393 private static final int DB_VERSION = 2; 394 395 /** Age in ms after which events are pruned from the DB. */ 396 private static final long HORIZON_MS = 7 * 24 * 60 * 60 * 1000L; // 1 week 397 /** Delay between pruning the DB. Used to throttle pruning. */ 398 private static final long PRUNE_MIN_DELAY_MS = 6 * 60 * 60 * 1000L; // 6 hours 399 /** Mininum number of writes between pruning the DB. Used to throttle pruning. */ 400 private static final long PRUNE_MIN_WRITES = 1024; 401 402 // Table 'log' 403 private static final String TAB_LOG = "log"; 404 private static final String COL_EVENT_USER_ID = "event_user_id"; 405 private static final String COL_EVENT_TYPE = "event_type"; 406 private static final String COL_EVENT_TIME = "event_time_ms"; 407 private static final String COL_KEY = "key"; 408 private static final String COL_PKG = "pkg"; 409 private static final String COL_NOTIFICATION_ID = "nid"; 410 private static final String COL_TAG = "tag"; 411 private static final String COL_WHEN_MS = "when_ms"; 412 private static final String COL_DEFAULTS = "defaults"; 413 private static final String COL_FLAGS = "flags"; 414 private static final String COL_PRIORITY = "priority"; 415 private static final String COL_CATEGORY = "category"; 416 private static final String COL_ACTION_COUNT = "action_count"; 417 private static final String COL_POSTTIME_MS = "posttime_ms"; 418 private static final String COL_AIRTIME_MS = "airtime_ms"; 419 420 private static final int EVENT_TYPE_POST = 1; 421 private static final int EVENT_TYPE_CLICK = 2; 422 private static final int EVENT_TYPE_REMOVE = 3; 423 private static final int EVENT_TYPE_DISMISS = 4; 424 425 private static long sLastPruneMs; 426 private static long sNumWrites; 427 428 private final SQLiteOpenHelper mHelper; 429 private final Handler mWriteHandler; 430 431 private static final long DAY_MS = 24 * 60 * 60 * 1000; 432 433 public SQLiteLog(Context context) { 434 HandlerThread backgroundThread = new HandlerThread("notification-sqlite-log", 435 android.os.Process.THREAD_PRIORITY_BACKGROUND); 436 backgroundThread.start(); 437 mWriteHandler = new Handler(backgroundThread.getLooper()) { 438 @Override 439 public void handleMessage(Message msg) { 440 NotificationRecord r = (NotificationRecord) msg.obj; 441 long nowMs = System.currentTimeMillis(); 442 switch (msg.what) { 443 case MSG_POST: 444 writeEvent(r.sbn.getPostTime(), EVENT_TYPE_POST, r); 445 break; 446 case MSG_CLICK: 447 writeEvent(nowMs, EVENT_TYPE_CLICK, r); 448 break; 449 case MSG_REMOVE: 450 writeEvent(nowMs, EVENT_TYPE_REMOVE, r); 451 break; 452 case MSG_DISMISS: 453 writeEvent(nowMs, EVENT_TYPE_DISMISS, r); 454 break; 455 default: 456 Log.wtf(TAG, "Unknown message type: " + msg.what); 457 break; 458 } 459 } 460 }; 461 mHelper = new SQLiteOpenHelper(context, DB_NAME, null, DB_VERSION) { 462 @Override 463 public void onCreate(SQLiteDatabase db) { 464 db.execSQL("CREATE TABLE " + TAB_LOG + " (" + 465 "_id INTEGER PRIMARY KEY AUTOINCREMENT," + 466 COL_EVENT_USER_ID + " INT," + 467 COL_EVENT_TYPE + " INT," + 468 COL_EVENT_TIME + " INT," + 469 COL_KEY + " TEXT," + 470 COL_PKG + " TEXT," + 471 COL_NOTIFICATION_ID + " INT," + 472 COL_TAG + " TEXT," + 473 COL_WHEN_MS + " INT," + 474 COL_DEFAULTS + " INT," + 475 COL_FLAGS + " INT," + 476 COL_PRIORITY + " INT," + 477 COL_CATEGORY + " TEXT," + 478 COL_ACTION_COUNT + " INT," + 479 COL_POSTTIME_MS + " INT," + 480 COL_AIRTIME_MS + " INT" + 481 ")"); 482 } 483 484 @Override 485 public void onUpgrade(SQLiteDatabase db, int oldVersion, int newVersion) { 486 switch (oldVersion) { 487 case 1: 488 // Add COL_POSTTIME_MS, COL_AIRTIME_MS columns, 489 db.execSQL("ALTER TABLE " + TAB_LOG + " ADD COLUMN " + 490 COL_POSTTIME_MS + " INT"); 491 db.execSQL("ALTER TABLE " + TAB_LOG + " ADD COLUMN " + 492 COL_AIRTIME_MS + " INT"); 493 } 494 } 495 }; 496 } 497 498 public void logPosted(NotificationRecord notification) { 499 mWriteHandler.sendMessage(mWriteHandler.obtainMessage(MSG_POST, notification)); 500 } 501 502 public void logClicked(NotificationRecord notification) { 503 mWriteHandler.sendMessage(mWriteHandler.obtainMessage(MSG_CLICK, notification)); 504 } 505 506 public void logRemoved(NotificationRecord notification) { 507 mWriteHandler.sendMessage(mWriteHandler.obtainMessage(MSG_REMOVE, notification)); 508 } 509 510 public void logDismissed(NotificationRecord notification) { 511 mWriteHandler.sendMessage(mWriteHandler.obtainMessage(MSG_DISMISS, notification)); 512 } 513 514 public void printPostFrequencies(PrintWriter pw, String indent) { 515 SQLiteDatabase db = mHelper.getReadableDatabase(); 516 long nowMs = System.currentTimeMillis(); 517 String q = "SELECT " + 518 COL_EVENT_USER_ID + ", " + 519 COL_PKG + ", " + 520 // Bucket by day by looking at 'floor((nowMs - eventTimeMs) / dayMs)' 521 "CAST(((" + nowMs + " - " + COL_EVENT_TIME + ") / " + DAY_MS + ") AS int) " + 522 "AS day, " + 523 "COUNT(*) AS cnt " + 524 "FROM " + TAB_LOG + " " + 525 "WHERE " + 526 COL_EVENT_TYPE + "=" + EVENT_TYPE_POST + " " + 527 "GROUP BY " + COL_EVENT_USER_ID + ", day, " + COL_PKG; 528 Cursor cursor = db.rawQuery(q, null); 529 try { 530 for (cursor.moveToFirst(); !cursor.isAfterLast(); cursor.moveToNext()) { 531 int userId = cursor.getInt(0); 532 String pkg = cursor.getString(1); 533 int day = cursor.getInt(2); 534 int count = cursor.getInt(3); 535 pw.println(indent + "post_frequency{user_id=" + userId + ",pkg=" + pkg + 536 ",day=" + day + ",count=" + count + "}"); 537 } 538 } finally { 539 cursor.close(); 540 } 541 } 542 543 private void writeEvent(long eventTimeMs, int eventType, NotificationRecord r) { 544 ContentValues cv = new ContentValues(); 545 cv.put(COL_EVENT_USER_ID, r.sbn.getUser().getIdentifier()); 546 cv.put(COL_EVENT_TIME, eventTimeMs); 547 cv.put(COL_EVENT_TYPE, eventType); 548 putNotificationIdentifiers(r, cv); 549 if (eventType == EVENT_TYPE_POST) { 550 putNotificationDetails(r, cv); 551 } else { 552 putPosttimeAirtime(r, cv); 553 } 554 SQLiteDatabase db = mHelper.getWritableDatabase(); 555 if (db.insert(TAB_LOG, null, cv) < 0) { 556 Log.wtf(TAG, "Error while trying to insert values: " + cv); 557 } 558 sNumWrites++; 559 pruneIfNecessary(db); 560 } 561 562 private void pruneIfNecessary(SQLiteDatabase db) { 563 // Prune if we haven't in a while. 564 long nowMs = System.currentTimeMillis(); 565 if (sNumWrites > PRUNE_MIN_WRITES || 566 nowMs - sLastPruneMs > PRUNE_MIN_DELAY_MS) { 567 sNumWrites = 0; 568 sLastPruneMs = nowMs; 569 long horizonStartMs = nowMs - HORIZON_MS; 570 int deletedRows = db.delete(TAB_LOG, COL_EVENT_TIME + " < ?", 571 new String[] { String.valueOf(horizonStartMs) }); 572 Log.d(TAG, "Pruned event entries: " + deletedRows); 573 } 574 } 575 576 private static void putNotificationIdentifiers(NotificationRecord r, ContentValues outCv) { 577 outCv.put(COL_KEY, r.sbn.getKey()); 578 outCv.put(COL_PKG, r.sbn.getPackageName()); 579 } 580 581 private static void putNotificationDetails(NotificationRecord r, ContentValues outCv) { 582 outCv.put(COL_NOTIFICATION_ID, r.sbn.getId()); 583 if (r.sbn.getTag() != null) { 584 outCv.put(COL_TAG, r.sbn.getTag()); 585 } 586 outCv.put(COL_WHEN_MS, r.sbn.getPostTime()); 587 outCv.put(COL_FLAGS, r.getNotification().flags); 588 outCv.put(COL_PRIORITY, r.getNotification().priority); 589 if (r.getNotification().category != null) { 590 outCv.put(COL_CATEGORY, r.getNotification().category); 591 } 592 outCv.put(COL_ACTION_COUNT, r.getNotification().actions != null ? 593 r.getNotification().actions.length : 0); 594 } 595 596 private static void putPosttimeAirtime(NotificationRecord r, ContentValues outCv) { 597 outCv.put(COL_POSTTIME_MS, r.stats.getCurrentPosttimeMs()); 598 outCv.put(COL_AIRTIME_MS, r.stats.getCurrentAirtimeMs()); 599 } 600 601 public void dump(PrintWriter pw, String indent) { 602 printPostFrequencies(pw, indent); 603 } 604 } 605} 606