Add spam-safe logger.

This change introduces a new helper class, HdmiLogger,
which prevents spammy log for same error message.

Bug: 17179667
Change-Id: Ia55808408e0a92b0370cd627361f80754b2f1018

3 files changed, 94 insertions, 8 deletions

diff --git a/services/core/java/com/android/server/hdmi/HdmiCecMessageValidator.java b/services/core/java/com/android/server/hdmi/HdmiCecMessageValidator.java
index 4c88ce0..8b345cf 100644
--- a/services/core/java/com/android/server/hdmi/HdmiCecMessageValidator.java
+++ b/services/core/java/com/android/server/hdmi/HdmiCecMessageValidator.java
@@ -17,7 +17,6 @@
 package com.android.server.hdmi;
 
 import android.hardware.hdmi.HdmiDeviceInfo;
-import android.util.Slog;
 import android.util.SparseArray;
 
 /**
@@ -52,6 +51,7 @@ public final class HdmiCecMessageValidator {
     }
 
     final SparseArray<ValidationInfo> mValidationInfo = new SparseArray<>();
+    private final HdmiLogger mSpamSafeLogger = new HdmiLogger(TAG);
 
     public HdmiCecMessageValidator(HdmiControlService service) {
         mService = service;
@@ -183,32 +183,32 @@ public final class HdmiCecMessageValidator {
         int opcode = message.getOpcode();
         ValidationInfo info = mValidationInfo.get(opcode);
         if (info == null) {
-            Slog.w(TAG, "No validation information for the message: " + message);
+            mSpamSafeLogger.warning("No validation information for the message: " + message);
             return true;
         }
 
         // Check the source field.
         if (message.getSource() == Constants.ADDR_UNREGISTERED &&
                 (info.addressType & SRC_UNREGISTERED) == 0) {
-            Slog.w(TAG, "Unexpected source: " + message);
+            mSpamSafeLogger.warning("Unexpected source: " + message);
             return false;
         }
         // Check the destination field.
         if (message.getDestination() == Constants.ADDR_BROADCAST) {
             if ((info.addressType & DEST_BROADCAST) == 0) {
-                Slog.w(TAG, "Unexpected broadcast message: " + message);
+                mSpamSafeLogger.warning("Unexpected broadcast message: " + message);
                 return false;
             }
         } else {  // Direct addressing.
             if ((info.addressType & DEST_DIRECT) == 0) {
-                Slog.w(TAG, "Unexpected direct message: " + message);
+                mSpamSafeLogger.warning("Unexpected direct message: " + message);
                 return false;
             }
         }
 
         // Check the parameter type.
         if (!info.parameterValidator.isValid(message.getParams())) {
-            Slog.w(TAG, "Unexpected parameters: " + message);
+            mSpamSafeLogger.warning("Unexpected parameters: " + message);
             return false;
         }
         return true;
diff --git a/services/core/java/com/android/server/hdmi/HdmiControlService.java b/services/core/java/com/android/server/hdmi/HdmiControlService.java
index fc8d7c3..3dabc11 100644
--- a/services/core/java/com/android/server/hdmi/HdmiControlService.java
+++ b/services/core/java/com/android/server/hdmi/HdmiControlService.java
@@ -160,6 +160,8 @@ public final class HdmiControlService extends SystemService {
     // Type of logical devices hosted in the system. Stored in the unmodifiable list.
     private final List<Integer> mLocalDevices;
 
+    private final HdmiLogger mSpamSafeLogger = new HdmiLogger(TAG);
+
     // List of records for hotplug event listener to handle the the caller killed in action.
     @GuardedBy("mLock")
     private final ArrayList<HotplugEventListenerRecord> mHotplugEventListenerRecords =
@@ -634,7 +636,7 @@ public final class HdmiControlService extends SystemService {
         if (mMessageValidator.isValid(command)) {
             mCecController.sendCommand(command, callback);
         } else {
-            Slog.e(TAG, "Invalid message type:" + command);
+            mSpamSafeLogger.error("Invalid message type:" + command);
             if (callback != null) {
                 callback.onSendCompleted(Constants.SEND_RESULT_FAILURE);
             }
@@ -695,7 +697,7 @@ public final class HdmiControlService extends SystemService {
         }
 
         if (message.getDestination() != Constants.ADDR_BROADCAST) {
-            Slog.w(TAG, "Unhandled cec command:" + message);
+            mSpamSafeLogger.warning("Unhandled cec command:" + message);
         }
         return false;
     }
diff --git a/services/core/java/com/android/server/hdmi/HdmiLogger.java b/services/core/java/com/android/server/hdmi/HdmiLogger.java
new file mode 100644
index 0000000..36159cb
--- /dev/null
+++ b/services/core/java/com/android/server/hdmi/HdmiLogger.java
@@ -0,0 +1,84 @@
+/*
+ * 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.hdmi;
+
+import android.os.SystemClock;
+import android.util.Pair;
+import android.util.Slog;
+
+import java.util.HashMap;
+
+/**
+ * A logger that prevents spammy log. For the same log message, it logs once every 20seconds.
+ * This class is not thread-safe.
+ */
+final class HdmiLogger {
+    // Logging duration for same error message.
+    private static final long ERROR_LOG_DURATTION_MILLIS = 20 * 1000;  // 20s
+
+    // Key (String): log message.
+    // Value (Pair(Long, Integer)): a pair of last log time millis and the number of logMessage.
+    // Cache for warning.
+    private final HashMap<String, Pair<Long, Integer>> mWarningTimingCache = new HashMap<>();
+    // Cache for error.
+    private final HashMap<String, Pair<Long, Integer>> mErrorTimingCache = new HashMap<>();
+
+    private final String mTag;
+
+    HdmiLogger(String tag) {
+        mTag = tag;
+    }
+
+    void warning(String logMessage) {
+        long curTime = SystemClock.uptimeMillis();
+        Pair<Long, Integer> timing = mWarningTimingCache.get(logMessage);
+        if (shouldLogNow(timing, curTime)) {
+            Slog.w(mTag, buildMessage(logMessage, timing));
+            mWarningTimingCache.put(logMessage, new Pair<>(curTime, 1));
+        } else {
+            increaseLogCount(mWarningTimingCache, logMessage);
+        }
+    }
+
+    void error(String logMessage) {
+        long curTime = SystemClock.uptimeMillis();
+        Pair<Long, Integer> timing = mErrorTimingCache.get(logMessage);
+        if (shouldLogNow(timing, curTime)) {
+            Slog.e(mTag, buildMessage(logMessage, timing));
+            mErrorTimingCache.put(logMessage, new Pair<>(curTime, 1));
+        } else {
+            increaseLogCount(mErrorTimingCache, logMessage);
+        }
+    }
+
+    private String buildMessage(String message, Pair<Long, Integer> timing) {
+        return new StringBuilder()
+            .append("[").append(timing.second).append("]:").append(message)
+            .toString();
+    }
+
+    private void increaseLogCount(HashMap<String, Pair<Long, Integer>> cache, String message) {
+        Pair<Long, Integer> timing = cache.get(message);
+        if (timing != null) {
+            cache.put(message, new Pair<>(timing.first, timing.second + 1));
+        }
+    }
+
+    private boolean shouldLogNow(Pair<Long, Integer> timing, long curTime) {
+        return timing == null || curTime - timing.first > ERROR_LOG_DURATTION_MILLIS;
+    }
+}