Merge "Add more debug message to HdmiControlService" into lmp-dev
diff --git a/services/core/java/com/android/server/hdmi/HdmiCecController.java b/services/core/java/com/android/server/hdmi/HdmiCecController.java
index cf06ca8..827b3ed 100644
--- a/services/core/java/com/android/server/hdmi/HdmiCecController.java
+++ b/services/core/java/com/android/server/hdmi/HdmiCecController.java
@@ -99,6 +99,11 @@
     // Stores the local CEC devices in the system. Device type is used for key.
     private final SparseArray<HdmiCecLocalDevice> mLocalDevices = new SparseArray<>();
 
+    @IoThreadOnly
+    private final HdmiLogger mIoThreadLogger = new HdmiLogger(TAG);
+    @ServiceThreadOnly
+    private final HdmiLogger mServiceThreadLogger = new HdmiLogger(TAG);
+
     // Private constructor.  Use HdmiCecController.create().
     private HdmiCecController(HdmiControlService service) {
         mService = service;
@@ -202,6 +207,9 @@
         }
 
         final int assignedAddress = logicalAddress;
+        mIoThreadLogger.debug(
+                String.format("New logical address for device [%d]: [preferred:%d, assigned:%d]",
+                        deviceType, preferredAddress, assignedAddress));
         if (callback != null) {
             runOnServiceThread(new Runnable() {
                 @Override
@@ -438,6 +446,7 @@
                         allocated.add(address);
                     }
                 }
+                mIoThreadLogger.debug("DevicePollingResult:" + allocated);
                 if (callback != null) {
                     runOnServiceThread(new Runnable() {
                         @Override
@@ -539,6 +548,7 @@
         runOnIoThread(new Runnable() {
             @Override
             public void run() {
+                mIoThreadLogger.debug("SendCommand:" + cecMessage);
                 byte[] body = buildBody(cecMessage.getOpcode(), cecMessage.getParams());
                 int i = 0;
                 int errorCode = Constants.SEND_RESULT_SUCCESS;
@@ -572,7 +582,9 @@
     @ServiceThreadOnly
     private void handleIncomingCecCommand(int srcAddress, int dstAddress, byte[] body) {
         assertRunOnServiceThread();
-        onReceiveCommand(HdmiCecMessageBuilder.of(srcAddress, dstAddress, body));
+        HdmiCecMessage command = HdmiCecMessageBuilder.of(srcAddress, dstAddress, body);
+        mServiceThreadLogger.debug("ReceiveCommand:" + command);
+        onReceiveCommand(command);
     }
 
     /**
@@ -581,6 +593,8 @@
     @ServiceThreadOnly
     private void handleHotplug(int port, boolean connected) {
         assertRunOnServiceThread();
+        mServiceThreadLogger.debug(
+                "Hotplug event:[port:" + port + " , connected:" + connected + "]");
         mService.onHotplug(port, connected);
     }
 
diff --git a/services/core/java/com/android/server/hdmi/HdmiCecMessage.java b/services/core/java/com/android/server/hdmi/HdmiCecMessage.java
index 433e93f..23fb099 100644
--- a/services/core/java/com/android/server/hdmi/HdmiCecMessage.java
+++ b/services/core/java/com/android/server/hdmi/HdmiCecMessage.java
@@ -103,26 +103,146 @@
         switch (opcode) {
             case Constants.MESSAGE_FEATURE_ABORT:
                 return "Feature Abort";
+            case Constants.MESSAGE_IMAGE_VIEW_ON:
+                return "Image View On";
+            case Constants.MESSAGE_TUNER_STEP_INCREMENT:
+                return "Tuner Step Increment";
+            case Constants.MESSAGE_TUNER_STEP_DECREMENT:
+                return "Tuner Step Decrement";
+            case Constants.MESSAGE_TUNER_DEVICE_STATUS:
+                return "Tuner Device Staus";
+            case Constants.MESSAGE_GIVE_TUNER_DEVICE_STATUS:
+                return "Give Tuner Device Status";
+            case Constants.MESSAGE_RECORD_ON:
+                return "Record On";
+            case Constants.MESSAGE_RECORD_STATUS:
+                return "Record Status";
+            case Constants.MESSAGE_RECORD_OFF:
+                return "Record Off";
+            case Constants.MESSAGE_TEXT_VIEW_ON:
+                return "Text View On";
+            case Constants.MESSAGE_RECORD_TV_SCREEN:
+                return "Record Tv Screen";
+            case Constants.MESSAGE_GIVE_DECK_STATUS:
+                return "Give Deck Status";
+            case Constants.MESSAGE_DECK_STATUS:
+                return "Deck Status";
+            case Constants.MESSAGE_SET_MENU_LANGUAGE:
+                return "Set Menu Language";
+            case Constants.MESSAGE_CLEAR_ANALOG_TIMER:
+                return "Clear Analog Timer";
+            case Constants.MESSAGE_SET_ANALOG_TIMER:
+                return "Set Analog Timer";
+            case Constants.MESSAGE_TIMER_STATUS:
+                return "Timer Status";
+            case Constants.MESSAGE_STANDBY:
+                return "Standby";
+            case Constants.MESSAGE_PLAY:
+                return "Play";
+            case Constants.MESSAGE_DECK_CONTROL:
+                return "Deck Control";
+            case Constants.MESSAGE_TIMER_CLEARED_STATUS:
+                return "Timer Cleared Status";
+            case Constants.MESSAGE_USER_CONTROL_PRESSED:
+                return "User Control Pressed";
+            case Constants.MESSAGE_USER_CONTROL_RELEASED:
+                return "User Control Release";
+            case Constants.MESSAGE_GIVE_OSD_NAME:
+                return "Give Osd Name";
+            case Constants.MESSAGE_SET_OSD_NAME:
+                return "Set Osd Name";
+            case Constants.MESSAGE_SET_OSD_STRING:
+                return "Set Osd String";
+            case Constants.MESSAGE_SET_TIMER_PROGRAM_TITLE:
+                return "Set Timer Program Title";
+            case Constants.MESSAGE_SYSTEM_AUDIO_MODE_REQUEST:
+                return "System Audio Mode Request";
+            case Constants.MESSAGE_GIVE_AUDIO_STATUS:
+                return "Give Audio Status";
+            case Constants.MESSAGE_SET_SYSTEM_AUDIO_MODE:
+                return "System Audio Mode";
+            case Constants.MESSAGE_REPORT_AUDIO_STATUS:
+                return "Report Audio Status";
+            case Constants.MESSAGE_GIVE_SYSTEM_AUDIO_MODE_STATUS:
+                return "Give System Audio Mode Status";
+            case Constants.MESSAGE_SYSTEM_AUDIO_MODE_STATUS:
+                return "System Audio Mode Status";
+            case Constants.MESSAGE_ROUTING_CHANGE:
+                return "Routing Change";
+            case Constants.MESSAGE_ROUTING_INFORMATION:
+                return "Routing Information";
+            case Constants.MESSAGE_ACTIVE_SOURCE:
+                return "Active Source";
+            case Constants.MESSAGE_GIVE_PHYSICAL_ADDRESS:
+                return "Give Physical Address";
+            case Constants.MESSAGE_REPORT_PHYSICAL_ADDRESS:
+                return "Report Physical Address";
+            case Constants.MESSAGE_REQUEST_ACTIVE_SOURCE:
+                return "Request Active Source";
+            case Constants.MESSAGE_SET_STREAM_PATH:
+                return "Set Stream Path";
+            case Constants.MESSAGE_DEVICE_VENDOR_ID:
+                return "Device Vendor Id";
+            case Constants.MESSAGE_VENDOR_COMMAND:
+                return "Vendor Commandn";
+            case Constants.MESSAGE_VENDOR_REMOTE_BUTTON_DOWN:
+                return "Vendor Remote Button Down";
+            case Constants.MESSAGE_VENDOR_REMOTE_BUTTON_UP:
+                return "Vendor Remote Button Up";
+            case Constants.MESSAGE_GIVE_DEVICE_VENDOR_ID:
+                return "Give Device Vendor Id";
+            case Constants.MESSAGE_MENU_REQUEST:
+                return "Menu REquest";
+            case Constants.MESSAGE_MENU_STATUS:
+                return "Menu Status";
+            case Constants.MESSAGE_GIVE_DEVICE_POWER_STATUS:
+                return "Give Device Power Status";
+            case Constants.MESSAGE_REPORT_POWER_STATUS:
+                return "Report Power Status";
+            case Constants.MESSAGE_GET_MENU_LANGUAGE:
+                return "Get Menu Language";
+            case Constants.MESSAGE_SELECT_ANALOG_SERVICE:
+                return "Select Analog Service";
+            case Constants.MESSAGE_SELECT_DIGITAL_SERVICE:
+                return "Select Digital Service";
+            case Constants.MESSAGE_SET_DIGITAL_TIMER:
+                return "Set Digital Timer";
+            case Constants.MESSAGE_CLEAR_DIGITAL_TIMER:
+                return "Clear Digital Timer";
+            case Constants.MESSAGE_SET_AUDIO_RATE:
+                return "Set Audio Rate";
+            case Constants.MESSAGE_INACTIVE_SOURCE:
+                return "InActive Source";
             case Constants.MESSAGE_CEC_VERSION:
-                return "CEC Version";
-            case Constants.MESSAGE_REQUEST_ARC_INITIATION:
-                return "Request ARC Initiation";
-            case Constants.MESSAGE_REQUEST_ARC_TERMINATION:
-                return "Request ARC Termination";
+                return "Cec Version";
+            case Constants.MESSAGE_GET_CEC_VERSION:
+                return "Get Cec Version";
+            case Constants.MESSAGE_VENDOR_COMMAND_WITH_ID:
+                return "Vendor Command With Id";
+            case Constants.MESSAGE_CLEAR_EXTERNAL_TIMER:
+                return "Clear External Timer";
+            case Constants.MESSAGE_SET_EXTERNAL_TIMER:
+                return "Set External Timer";
+            case Constants.MESSAGE_REPORT_SHORT_AUDIO_DESCRIPTOR:
+                return "Repot Short Audio Descriptor";
+            case Constants.MESSAGE_REQUEST_SHORT_AUDIO_DESCRIPTOR:
+                return "Request Short Audio Descriptor";
+            case Constants.MESSAGE_INITIATE_ARC:
+                return "Initiate ARC";
             case Constants.MESSAGE_REPORT_ARC_INITIATED:
                 return "Report ARC Initiated";
             case Constants.MESSAGE_REPORT_ARC_TERMINATED:
                 return "Report ARC Terminated";
-            case Constants.MESSAGE_TEXT_VIEW_ON:
-                return "Text View On";
-            case Constants.MESSAGE_ACTIVE_SOURCE:
-                return "Active Source";
-            case Constants.MESSAGE_GIVE_DEVICE_POWER_STATUS:
-                return "Give Device Power Status";
-            case Constants.MESSAGE_VENDOR_COMMAND:
-                return "Vendor Command";
-            case Constants.MESSAGE_VENDOR_COMMAND_WITH_ID:
-                return "Vendor Command With ID";
+            case Constants.MESSAGE_REQUEST_ARC_INITIATION:
+                return "Request ARC Initiation";
+            case Constants.MESSAGE_REQUEST_ARC_TERMINATION:
+                return "Request ARC Termination";
+            case Constants.MESSAGE_TERMINATE_ARC:
+                return "Terminate ARC";
+            case Constants.MESSAGE_CDC_MESSAGE:
+                return "Cdc Message";
+            case Constants.MESSAGE_ABORT:
+                return "Abort";
             default:
                 return String.format("Opcode: %02X", opcode);
         }
diff --git a/services/core/java/com/android/server/hdmi/HdmiLogger.java b/services/core/java/com/android/server/hdmi/HdmiLogger.java
index cb72bc1..ee9379d 100644
--- a/services/core/java/com/android/server/hdmi/HdmiLogger.java
+++ b/services/core/java/com/android/server/hdmi/HdmiLogger.java
@@ -31,13 +31,14 @@
     // Logging duration for same error message.
     private static final long ERROR_LOG_DURATTION_MILLIS = 20 * 1000;  // 20s
 
+    private static final boolean DEBUG = false;
+
     // 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) {
@@ -45,41 +46,54 @@
     }
 
     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);
+        String log = updateLog(mWarningTimingCache, logMessage);
+        if (!log.isEmpty()) {
+            Slog.w(mTag, log);
         }
     }
 
     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);
+        String log = updateLog(mErrorTimingCache, logMessage);
+        if (!log.isEmpty()) {
+            Slog.e(mTag, log);
         }
     }
 
-    private String buildMessage(String message, @Nullable Pair<Long, Integer> timing) {
-        return new StringBuilder()
-            .append("[").append(timing == null ? 1 : timing.second).append("]:")
-            .append(message).toString();
+    void debug(String logMessage) {
+        if (!DEBUG) {
+            return;
+        }
+        Slog.d(mTag, logMessage);
     }
 
-    private void increaseLogCount(HashMap<String, Pair<Long, Integer>> cache, String message) {
+    private static String updateLog(HashMap<String, Pair<Long, Integer>> cache, String logMessage) {
+        long curTime = SystemClock.uptimeMillis();
+        Pair<Long, Integer> timing = cache.get(logMessage);
+        if (shouldLogNow(timing, curTime)) {
+            String log = buildMessage(logMessage, timing);
+            cache.put(logMessage, new Pair<>(curTime, 1));
+            return log;
+        } else {
+            increaseLogCount(cache, logMessage);
+        }
+        return "";
+    }
+
+    private static String buildMessage(String message, @Nullable Pair<Long, Integer> timing) {
+        return new StringBuilder()
+                .append("[").append(timing == null ? 1 : timing.second).append("]:")
+                .append(message).toString();
+    }
+
+    private static 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(@Nullable Pair<Long, Integer> timing, long curTime) {
+    private static boolean shouldLogNow(@Nullable Pair<Long, Integer> timing, long curTime) {
         return timing == null || curTime - timing.first > ERROR_LOG_DURATTION_MILLIS;
     }
 }
diff --git a/services/core/java/com/android/server/hdmi/SetArcTransmissionStateAction.java b/services/core/java/com/android/server/hdmi/SetArcTransmissionStateAction.java
index c1c6b91..30519f3 100644
--- a/services/core/java/com/android/server/hdmi/SetArcTransmissionStateAction.java
+++ b/services/core/java/com/android/server/hdmi/SetArcTransmissionStateAction.java
@@ -92,7 +92,7 @@
 
     private void setArcStatus(boolean enabled) {
         boolean wasEnabled = tv().setArcStatus(enabled);
-        Slog.i(TAG, "Change arc status [old:" + wasEnabled + " ,new:" + enabled);
+        Slog.i(TAG, "Change arc status [old:" + wasEnabled + ", new:" + enabled + "]");
 
         // If enabled before and set to "disabled" and send <Report Arc Terminated> to
         // av reciever.