Add a zen-specific event sink, include in dumpstate.

Useful for tracking zen events (since boot) that are
too old to be included in the standard log.

Change-Id: I91633d35b26091bb18523a76ebdba9d286d0cd41
diff --git a/services/core/java/com/android/server/notification/ConditionProviders.java b/services/core/java/com/android/server/notification/ConditionProviders.java
index f4248daf..a06daf6 100644
--- a/services/core/java/com/android/server/notification/ConditionProviders.java
+++ b/services/core/java/com/android/server/notification/ConditionProviders.java
@@ -273,7 +273,7 @@
         }
     }
 
-    public void setZenModeCondition(Uri conditionId) {
+    public void setZenModeCondition(Uri conditionId, String reason) {
         if (DEBUG) Slog.d(TAG, "setZenModeCondition " + conditionId);
         synchronized(mMutex) {
             ComponentName conditionComponent = null;
@@ -306,6 +306,7 @@
             if (!Objects.equals(mExitConditionId, conditionId)) {
                 mExitConditionId = conditionId;
                 mExitConditionComponent = conditionComponent;
+                ZenLog.traceExitCondition(mExitConditionId, mExitConditionComponent, reason);
                 saveZenConfigLocked();
             }
         }
@@ -314,15 +315,16 @@
     private void subscribeLocked(ConditionRecord r) {
         if (DEBUG) Slog.d(TAG, "subscribeLocked " + r);
         final IConditionProvider provider = provider(r);
-        if (provider == null) {
-            Slog.w(TAG, "subscribeLocked: no provider");
-            return;
+        RemoteException re = null;
+        if (provider != null) {
+            try {
+                provider.onSubscribe(r.id);
+            } catch (RemoteException e) {
+                Slog.w(TAG, "Error subscribing to " + r, e);
+                re = e;
+            }
         }
-        try {
-            provider.onSubscribe(r.id);
-        } catch (RemoteException e) {
-            Slog.w(TAG, "Error subscribing to " + r, e);
-        }
+        ZenLog.traceSubscribe(r != null ? r.id : null, provider, re);
     }
 
     private static <T> ArraySet<T> safeSet(T... items) {
@@ -388,15 +390,16 @@
     private void unsubscribeLocked(ConditionRecord r) {
         if (DEBUG) Slog.d(TAG, "unsubscribeLocked " + r);
         final IConditionProvider provider = provider(r);
-        if (provider == null) {
-            Slog.w(TAG, "unsubscribeLocked: no provider");
-            return;
+        RemoteException re = null;
+        if (provider != null) {
+            try {
+                provider.onUnsubscribe(r.id);
+            } catch (RemoteException e) {
+                Slog.w(TAG, "Error unsubscribing to " + r, e);
+                re = e;
+            }
         }
-        try {
-            provider.onUnsubscribe(r.id);
-        } catch (RemoteException e) {
-            Slog.w(TAG, "Error unsubscribing to " + r, e);
-        }
+        ZenLog.traceUnsubscribe(r != null ? r.id : null, provider, re);
     }
 
     private static IConditionProvider provider(ConditionRecord r) {
@@ -433,8 +436,12 @@
             return;
         }
         synchronized (mMutex) {
+            final boolean changingExit = !Objects.equals(mExitConditionId, config.exitConditionId);
             mExitConditionId = config.exitConditionId;
             mExitConditionComponent = config.exitConditionComponent;
+            if (changingExit) {
+                ZenLog.traceExitCondition(mExitConditionId, mExitConditionComponent, "config");
+            }
             if (config.conditionComponents == null || config.conditionIds == null
                     || config.conditionComponents.length != config.conditionIds.length) {
                 if (DEBUG) Slog.d(TAG, "loadZenConfig: no conditions");
@@ -498,7 +505,7 @@
             final int mode = mZenModeHelper.getZenMode();
             if (mode == Global.ZEN_MODE_OFF) {
                 // ensure any manual condition is cleared
-                setZenModeCondition(null);
+                setZenModeCondition(null, "zenOff");
             }
         }
     }
diff --git a/services/core/java/com/android/server/notification/NotificationManagerService.java b/services/core/java/com/android/server/notification/NotificationManagerService.java
index b15ac8d..aa9e151 100644
--- a/services/core/java/com/android/server/notification/NotificationManagerService.java
+++ b/services/core/java/com/android/server/notification/NotificationManagerService.java
@@ -1282,7 +1282,7 @@
             enforceSystemOrSystemUI("INotificationManager.setZenModeCondition");
             final long identity = Binder.clearCallingIdentity();
             try {
-                mConditionProviders.setZenModeCondition(conditionId);
+                mConditionProviders.setZenModeCondition(conditionId, "binderCall");
             } finally {
                 Binder.restoreCallingIdentity(identity);
             }
@@ -1409,6 +1409,9 @@
             if (filter == null || zenOnly) {
                 pw.println("\n  Zen Mode:");
                 mZenModeHelper.dump(pw, "    ");
+
+                pw.println("\n  Zen Log:");
+                ZenLog.dump(pw, "    ");
             }
 
             if (!zenOnly) {
diff --git a/services/core/java/com/android/server/notification/ZenLog.java b/services/core/java/com/android/server/notification/ZenLog.java
new file mode 100644
index 0000000..81f64b1
--- /dev/null
+++ b/services/core/java/com/android/server/notification/ZenLog.java
@@ -0,0 +1,164 @@
+/**
+ * Copyright (c) 2014, 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.server.notification;
+
+import android.content.ComponentName;
+import android.media.AudioManager;
+import android.net.Uri;
+import android.os.Build;
+import android.os.RemoteException;
+import android.provider.Settings.Global;
+import android.service.notification.IConditionProvider;
+import android.service.notification.ZenModeConfig;
+import android.util.Slog;
+
+import java.io.PrintWriter;
+import java.text.SimpleDateFormat;
+import java.util.Arrays;
+import java.util.Date;
+
+public class ZenLog {
+    private static final String TAG = "ZenLog";
+
+    private static final int SIZE = Build.IS_DEBUGGABLE ? 100 : 20;
+
+    private static final long[] TIMES = new long[SIZE];
+    private static final int[] TYPES = new int[SIZE];
+    private static final String[] MSGS = new String[SIZE];
+
+    private static final SimpleDateFormat FORMAT = new SimpleDateFormat("MM-dd HH:mm:ss.SSS");
+
+    private static final int TYPE_INTERCEPTED = 1;
+    private static final int TYPE_ALLOW_DISABLE = 2;
+    private static final int TYPE_SET_RINGER_MODE = 3;
+    private static final int TYPE_DOWNTIME = 4;
+    private static final int TYPE_ZEN_MODE = 5;
+    private static final int TYPE_EXIT_CONDITION = 6;
+    private static final int TYPE_SUBSCRIBE = 7;
+    private static final int TYPE_UNSUBSCRIBE = 8;
+    private static final int TYPE_CONFIG = 9;
+
+    private static int sNext;
+    private static int sSize;
+
+    public static void traceIntercepted(NotificationRecord record, String reason) {
+        if (record != null && record.isIntercepted()) return;  // already logged
+        append(TYPE_INTERCEPTED, record.getKey() + "," + reason);
+    }
+
+    public static void traceAllowDisable(String pkg, boolean allowDisable, String reason) {
+        append(TYPE_ALLOW_DISABLE, allowDisable + "," + pkg + "," + reason);
+    }
+
+    public static void traceSetRingerMode(int ringerMode) {
+        append(TYPE_SET_RINGER_MODE, ringerModeToString(ringerMode));
+    }
+
+    public static void traceDowntime(boolean enter, int day, int[] days) {
+        append(TYPE_DOWNTIME, enter + ",day=" + day + ",days=" + (days != null ? Arrays.asList(days)
+                : null));
+    }
+
+    public static void traceUpdateZenMode(int fromMode, int toMode) {
+        append(TYPE_ZEN_MODE, zenModeToString(fromMode) + " -> " + zenModeToString(toMode));
+    }
+
+    public static void traceExitCondition(Uri id, ComponentName component, String reason) {
+        append(TYPE_EXIT_CONDITION, id + "," + componentToString(component) + "," + reason);
+    }
+
+    public static void traceSubscribe(Uri uri, IConditionProvider provider, RemoteException e) {
+        append(TYPE_SUBSCRIBE, uri + "," + subscribeResult(provider, e));
+    }
+
+    public static void traceUnsubscribe(Uri uri, IConditionProvider provider, RemoteException e) {
+        append(TYPE_UNSUBSCRIBE, uri + "," + subscribeResult(provider, e));
+    }
+
+    public static void traceConfig(ZenModeConfig oldConfig, ZenModeConfig newConfig) {
+        append(TYPE_CONFIG, newConfig != null ? newConfig.toString() : null);
+    }
+
+    private static String subscribeResult(IConditionProvider provider, RemoteException e) {
+        return provider == null ? "no provider" : e != null ? e.getMessage() : "ok";
+    }
+
+    private static String typeToString(int type) {
+        switch (type) {
+            case TYPE_INTERCEPTED: return "intercepted";
+            case TYPE_ALLOW_DISABLE: return "allow_disable";
+            case TYPE_SET_RINGER_MODE: return "set_ringer_mode";
+            case TYPE_DOWNTIME: return "downtime";
+            case TYPE_ZEN_MODE: return "zen_mode";
+            case TYPE_EXIT_CONDITION: return "exit_condition";
+            case TYPE_SUBSCRIBE: return "subscribe";
+            case TYPE_UNSUBSCRIBE: return "unsubscribe";
+            case TYPE_CONFIG: return "config";
+            default: return "unknown";
+        }
+    }
+
+    private static String ringerModeToString(int ringerMode) {
+        switch (ringerMode) {
+            case AudioManager.RINGER_MODE_SILENT: return "silent";
+            case AudioManager.RINGER_MODE_VIBRATE: return "vibrate";
+            case AudioManager.RINGER_MODE_NORMAL: return "normal";
+            default: return "unknown";
+        }
+    }
+
+    private static String zenModeToString(int zenMode) {
+        switch (zenMode) {
+            case Global.ZEN_MODE_OFF: return "off";
+            case Global.ZEN_MODE_IMPORTANT_INTERRUPTIONS: return "important_interruptions";
+            case Global.ZEN_MODE_NO_INTERRUPTIONS: return "no_interruptions";
+            default: return "unknown";
+        }
+    }
+
+    private static String componentToString(ComponentName component) {
+        return component != null ? component.toShortString() : null;
+    }
+
+    private static void append(int type, String msg) {
+        synchronized(MSGS) {
+            TIMES[sNext] = System.currentTimeMillis();
+            TYPES[sNext] = type;
+            MSGS[sNext] = msg;
+            sNext = (sNext + 1) % SIZE;
+            if (sSize < SIZE) {
+                sSize++;
+            }
+        }
+        Slog.d(TAG, typeToString(type) + ": " + msg);
+    }
+
+    public static void dump(PrintWriter pw, String prefix) {
+        synchronized(MSGS) {
+            final int start = (sNext - sSize + SIZE) % SIZE;
+            for (int i = 0; i < sSize; i++) {
+                final int j = (start + i) % SIZE;
+                pw.print(prefix);
+                pw.print(FORMAT.format(new Date(TIMES[j])));
+                pw.print(' ');
+                pw.print(typeToString(TYPES[j]));
+                pw.print(": ");
+                pw.println(MSGS[j]);
+            }
+        }
+    }
+}
diff --git a/services/core/java/com/android/server/notification/ZenModeHelper.java b/services/core/java/com/android/server/notification/ZenModeHelper.java
index f74e371..118b9fc 100644
--- a/services/core/java/com/android/server/notification/ZenModeHelper.java
+++ b/services/core/java/com/android/server/notification/ZenModeHelper.java
@@ -139,18 +139,32 @@
                 return false;
             }
             if (isAlarm(record)) {
-                return mZenMode == Global.ZEN_MODE_NO_INTERRUPTIONS;
+                if (mZenMode == Global.ZEN_MODE_NO_INTERRUPTIONS) {
+                    ZenLog.traceIntercepted(record, "alarm");
+                    return true;
+                }
+                return false;
             }
             // audience has veto power over all following rules
             if (!audienceMatches(record)) {
+                ZenLog.traceIntercepted(record, "!audienceMatches");
                 return true;
             }
             if (isCall(record)) {
-                return !mConfig.allowCalls;
+                if (!mConfig.allowCalls) {
+                    ZenLog.traceIntercepted(record, "!allowCalls");
+                    return true;
+                }
+                return false;
             }
             if (isMessage(record)) {
-                return !mConfig.allowMessages;
+                if (!mConfig.allowMessages) {
+                    ZenLog.traceIntercepted(record, "!allowMessages");
+                    return true;
+                }
+                return false;
             }
+            ZenLog.traceIntercepted(record, "!allowed");
             return true;
         }
         return false;
@@ -171,6 +185,7 @@
             Slog.d(TAG, String.format("updateZenMode: %s -> %s",
                     Global.zenModeToString(mZenMode),
                     Global.zenModeToString(mode)));
+            ZenLog.traceUpdateZenMode(mZenMode, mode);
         }
         mZenMode = mode;
         final boolean zen = mZenMode != Global.ZEN_MODE_OFF;
@@ -202,30 +217,41 @@
         // force ringer mode into compliance
         if (mAudioManager != null) {
             int ringerMode = mAudioManager.getRingerMode();
+            int forcedRingerMode = -1;
             if (mZenMode == Global.ZEN_MODE_NO_INTERRUPTIONS) {
                 if (ringerMode != AudioManager.RINGER_MODE_SILENT) {
                     mPreviousRingerMode = ringerMode;
                     Slog.d(TAG, "Silencing ringer");
-                    mAudioManager.setRingerMode(AudioManager.RINGER_MODE_SILENT);
+                    forcedRingerMode = AudioManager.RINGER_MODE_SILENT;
                 }
             } else {
                 if (ringerMode == AudioManager.RINGER_MODE_SILENT) {
                     Slog.d(TAG, "Unsilencing ringer");
-                    mAudioManager.setRingerMode(mPreviousRingerMode != -1 ? mPreviousRingerMode
-                            : AudioManager.RINGER_MODE_NORMAL);
+                    forcedRingerMode = mPreviousRingerMode != -1 ? mPreviousRingerMode
+                            : AudioManager.RINGER_MODE_NORMAL;
                     mPreviousRingerMode = -1;
                 }
             }
+            if (forcedRingerMode != -1) {
+                mAudioManager.setRingerMode(forcedRingerMode);
+                ZenLog.traceSetRingerMode(forcedRingerMode);
+            }
         }
         dispatchOnZenModeChanged();
     }
 
     public boolean allowDisable(int what, IBinder token, String pkg) {
         // TODO(cwren): delete this API before the next release. Bug:15344099
+        boolean allowDisable = true;
+        String reason = null;
         if (isDefaultPhoneApp(pkg)) {
-            return mZenMode == Global.ZEN_MODE_OFF || mConfig.allowCalls;
+            allowDisable = mZenMode == Global.ZEN_MODE_OFF || mConfig.allowCalls;
+            reason = mZenMode == Global.ZEN_MODE_OFF ? "zenOff" : "allowCalls";
         }
-        return true;
+        if (!SYSTEM_PACKAGES.contains(pkg)) {
+            ZenLog.traceAllowDisable(pkg, allowDisable, reason);
+        }
+        return allowDisable;
     }
 
     public void dump(PrintWriter pw, String prefix) {
@@ -255,8 +281,8 @@
     public boolean setConfig(ZenModeConfig config) {
         if (config == null || !config.isValid()) return false;
         if (config.equals(mConfig)) return true;
+        ZenLog.traceConfig(mConfig, config);
         mConfig = config;
-        Slog.d(TAG, "mConfig=" + mConfig);
         dispatchOnConfigChanged();
         final String val = Integer.toString(mConfig.hashCode());
         Global.putString(mContext.getContentResolver(), Global.ZEN_MODE_CONFIG_ETAG, val);
@@ -398,20 +424,18 @@
                     intent.getAction(), ts(schTime), ts(now), now - schTime));
 
             final int[] days = ZenModeConfig.tryParseDays(mConfig.sleepMode);
+            boolean enter = false;
+            final int day = getDayOfWeek(schTime);
             if (days != null) {
-                final int day = getDayOfWeek(schTime);
                 for (int i = 0; i < days.length; i++) {
                     if (days[i] == day) {
-                        Slog.d(TAG, "Enter downtime, day=" + day + " days=" + Arrays.asList(days));
+                        enter = true;
                         ZenModeHelper.this.setZenMode(zenModeValue);
                         break;
-                    } else {
-                        Slog.d(TAG, "Skip downtime, day=" + day + " days=" + Arrays.asList(days));
                     }
                 }
-            } else {
-                Slog.d(TAG, "Skip downtime, no days configured");
             }
+            ZenLog.traceDowntime(enter, day, days);
             updateAlarms();
         }