CEC: Revamp volume control action.

Here is a list of changes
1. Change volume control into event base not level base
2. Hide volume ui if volume change is triggered by CEC
3. Report volume change triggered by CEC in OSD message
4. Revamp HdmiLogger so that normal class uses static method only.
5. Apply format message to HdmiLogger's helper methods.

Bug: 17367215

Change-Id: I9f3cd41f7c66f76919059b463df956ed5176b054
diff --git a/core/java/android/hardware/hdmi/HdmiControlManager.java b/core/java/android/hardware/hdmi/HdmiControlManager.java
index 4b5ced9..30f3576 100644
--- a/core/java/android/hardware/hdmi/HdmiControlManager.java
+++ b/core/java/android/hardware/hdmi/HdmiControlManager.java
@@ -55,10 +55,29 @@
     public static final int OSD_MESSAGE_ARC_CONNECTED_INVALID_PORT = 1;
 
     /**
+     * Message used by TV to receive volume status from Audio Receiver. It should check volume value
+     * that is retrieved from extra value with the key {@link #EXTRA_MESSAGE_EXTRAM_PARAM1}. If the
+     * value is in range of [0,100], it is current volume of Audio Receiver. And there is another
+     * value, {@link #AVR_VOLUME_MUTED}, which is used to inform volume mute.
+     */
+    public static final int OSD_MESSAGE_AVR_VOLUME_CHANGED = 2;
+
+    /**
      * Used as an extra field in the intent {@link #ACTION_OSD_MESSAGE}. Contains the ID of
      * the message to display on screen.
      */
     public static final String EXTRA_MESSAGE_ID = "android.hardware.hdmi.extra.MESSAGE_ID";
+    /**
+     * Used as an extra field in the intent {@link #ACTION_OSD_MESSAGE}. Contains the extra value
+     * of the message.
+     */
+    public static final String EXTRA_MESSAGE_EXTRAM_PARAM1 =
+            "android.hardware.hdmi.extra.MESSAGE_EXTRA_PARAM1";
+
+    /**
+     * Volume value for mute state.
+     */
+    public static final int AVR_VOLUME_MUTED = 101;
 
     public static final int POWER_STATUS_UNKNOWN = -1;
     public static final int POWER_STATUS_ON = 0;
diff --git a/services/core/java/com/android/server/hdmi/HdmiCecController.java b/services/core/java/com/android/server/hdmi/HdmiCecController.java
index bb22b4d..c5a6dbd 100644
--- a/services/core/java/com/android/server/hdmi/HdmiCecController.java
+++ b/services/core/java/com/android/server/hdmi/HdmiCecController.java
@@ -31,8 +31,6 @@
 
 import libcore.util.EmptyArray;
 
-import java.io.FileDescriptor;
-import java.io.PrintWriter;
 import java.util.ArrayList;
 import java.util.List;
 
@@ -102,11 +100,6 @@
     // 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;
@@ -210,9 +203,8 @@
         }
 
         final int assignedAddress = logicalAddress;
-        mIoThreadLogger.debug(
-                String.format("New logical address for device [%d]: [preferred:%d, assigned:%d]",
-                        deviceType, preferredAddress, assignedAddress));
+        HdmiLogger.debug("New logical address for device [%d]: [preferred:%d, assigned:%d]",
+                        deviceType, preferredAddress, assignedAddress);
         if (callback != null) {
             runOnServiceThread(new Runnable() {
                 @Override
@@ -449,7 +441,7 @@
                         allocated.add(address);
                     }
                 }
-                mIoThreadLogger.debug("[P]:Allocated Address=" + allocated);
+                HdmiLogger.debug("[P]:Allocated Address=" + allocated);
                 if (callback != null) {
                     runOnServiceThread(new Runnable() {
                         @Override
@@ -551,7 +543,7 @@
         runOnIoThread(new Runnable() {
             @Override
             public void run() {
-                mIoThreadLogger.debug("[S]:" + cecMessage);
+                HdmiLogger.debug("[S]:" + cecMessage);
                 byte[] body = buildBody(cecMessage.getOpcode(), cecMessage.getParams());
                 int i = 0;
                 int errorCode = Constants.SEND_RESULT_SUCCESS;
@@ -586,7 +578,7 @@
     private void handleIncomingCecCommand(int srcAddress, int dstAddress, byte[] body) {
         assertRunOnServiceThread();
         HdmiCecMessage command = HdmiCecMessageBuilder.of(srcAddress, dstAddress, body);
-        mServiceThreadLogger.debug("[R]:" + command);
+        HdmiLogger.debug("[R]:" + command);
         onReceiveCommand(command);
     }
 
@@ -596,8 +588,7 @@
     @ServiceThreadOnly
     private void handleHotplug(int port, boolean connected) {
         assertRunOnServiceThread();
-        mServiceThreadLogger.debug(
-                "Hotplug event:[port:" + port + " , connected:" + connected + "]");
+        HdmiLogger.debug("Hotplug event:[port:%d, connected:%b]", port, connected);
         mService.onHotplug(port, connected);
     }
 
diff --git a/services/core/java/com/android/server/hdmi/HdmiCecFeatureAction.java b/services/core/java/com/android/server/hdmi/HdmiCecFeatureAction.java
index 85f5be2..b2300a6 100644
--- a/services/core/java/com/android/server/hdmi/HdmiCecFeatureAction.java
+++ b/services/core/java/com/android/server/hdmi/HdmiCecFeatureAction.java
@@ -43,9 +43,6 @@
  */
 abstract class HdmiCecFeatureAction {
     private static final String TAG = "HdmiCecFeatureAction";
-    // As all actions run in the same thread (service thread), it's fine to have single logger.
-    // TODO: create global logger for each threads and use them.
-    protected static final HdmiLogger DLOGGER = new HdmiLogger(TAG);
 
     // Timer handler message used for timeout event
     protected static final int MSG_TIMEOUT = 100;
@@ -264,10 +261,7 @@
     }
 
     protected final void sendUserControlPressedAndReleased(int targetAddress, int uiCommand) {
-        sendCommand(HdmiCecMessageBuilder.buildUserControlPressed(
-                getSourceAddress(), targetAddress, uiCommand));
-        sendCommand(HdmiCecMessageBuilder.buildUserControlReleased(
-                getSourceAddress(), targetAddress));
+        mSource.sendUserControlPressedAndReleased(targetAddress, uiCommand);
     }
 
     protected final void addOnFinishedCallback(HdmiCecFeatureAction action, Runnable runnable) {
diff --git a/services/core/java/com/android/server/hdmi/HdmiCecLocalDevice.java b/services/core/java/com/android/server/hdmi/HdmiCecLocalDevice.java
index bc6a299..04e38dc 100644
--- a/services/core/java/com/android/server/hdmi/HdmiCecLocalDevice.java
+++ b/services/core/java/com/android/server/hdmi/HdmiCecLocalDevice.java
@@ -810,6 +810,13 @@
         Slog.w(TAG, "sendKeyEvent not implemented");
     }
 
+    void sendUserControlPressedAndReleased(int targetAddress, int cecKeycode) {
+        mService.sendCecCommand(HdmiCecMessageBuilder.buildUserControlPressed(
+                mAddress, targetAddress, cecKeycode));
+        mService.sendCecCommand(HdmiCecMessageBuilder.buildUserControlReleased(
+                mAddress, targetAddress));
+    }
+
     /**
      * Dump internal status of HdmiCecLocalDevice object.
      */
diff --git a/services/core/java/com/android/server/hdmi/HdmiCecLocalDeviceTv.java b/services/core/java/com/android/server/hdmi/HdmiCecLocalDeviceTv.java
index 7ae2198..5994c76 100644
--- a/services/core/java/com/android/server/hdmi/HdmiCecLocalDeviceTv.java
+++ b/services/core/java/com/android/server/hdmi/HdmiCecLocalDeviceTv.java
@@ -120,8 +120,6 @@
     // other CEC devices since they might not have logical address.
     private final ArraySet<Integer> mCecSwitches = new ArraySet<Integer>();
 
-    private final HdmiLogger mSafeLogger = new HdmiLogger(TAG);
-
     HdmiCecLocalDeviceTv(HdmiControlService service) {
         super(service, HdmiDeviceInfo.DEVICE_TV);
         mPrevPortId = Constants.INVALID_PORT_ID;
@@ -700,8 +698,7 @@
 
     // # Seq 25
     void setSystemAudioMode(boolean on, boolean updateSetting) {
-        mSafeLogger.debug(String.format("System Audio Mode change[old:%b new:%b]",
-                mSystemAudioActivated, on));
+        HdmiLogger.debug("System Audio Mode change[old:%b new:%b]", mSystemAudioActivated, on);
 
         if (updateSetting) {
             mService.writeBooleanSetting(Global.HDMI_SYSTEM_AUDIO_ENABLED, on);
@@ -832,6 +829,8 @@
                     AudioManager.STREAM_MUSIC);
             mService.setAudioStatus(mute,
                     VolumeControlAction.scaleToCustomVolume(volume, maxVolume));
+            displayOsd(HdmiControlManager.OSD_MESSAGE_AVR_VOLUME_CHANGED,
+                    mute ? HdmiControlManager.AVR_VOLUME_MUTED : volume);
         }
     }
 
@@ -855,12 +854,13 @@
             }
         }
 
-        // Remove existing volume action.
-        removeAction(VolumeControlAction.class);
-
-        HdmiDeviceInfo avr = getAvrDeviceInfo();
-        addAndStartAction(VolumeControlAction.ofVolumeChange(this, avr.getLogicalAddress(),
-                cecVolume, delta > 0));
+        List<VolumeControlAction> actions = getActions(VolumeControlAction.class);
+        if (actions.isEmpty()) {
+            addAndStartAction(new VolumeControlAction(this,
+                    getAvrDeviceInfo().getLogicalAddress(), delta > 0));
+        } else {
+            actions.get(0).handleVolumeChange(delta > 0);
+        }
     }
 
     @ServiceThreadOnly
@@ -872,8 +872,9 @@
 
         // Remove existing volume action.
         removeAction(VolumeControlAction.class);
-        HdmiDeviceInfo avr = getAvrDeviceInfo();
-        addAndStartAction(VolumeControlAction.ofMute(this, avr.getLogicalAddress(), mute));
+        sendUserControlPressedAndReleased(getAvrDeviceInfo().getLogicalAddress(),
+                mute ? HdmiCecKeycode.CEC_KEYCODE_MUTE_FUNCTION :
+                        HdmiCecKeycode.CEC_KEYCODE_RESTORE_VOLUME_FUNCTION);
     }
 
     @Override
@@ -935,7 +936,7 @@
     protected boolean handleSetSystemAudioMode(HdmiCecMessage message) {
         assertRunOnServiceThread();
         if (!isMessageForSystemAudio(message)) {
-            mSafeLogger.warning("Invalid <Set System Audio Mode> message:" + message);
+            HdmiLogger.warning("Invalid <Set System Audio Mode> message:" + message);
             return false;
         }
         SystemAudioActionFromAvr action = new SystemAudioActionFromAvr(this,
@@ -949,7 +950,7 @@
     protected boolean handleSystemAudioModeStatus(HdmiCecMessage message) {
         assertRunOnServiceThread();
         if (!isMessageForSystemAudio(message)) {
-            mSafeLogger.warning("Invalid <System Audio Mode Status> message:" + message);
+            HdmiLogger.warning("Invalid <System Audio Mode Status> message:" + message);
             return false;
         }
         setSystemAudioMode(HdmiUtils.parseCommandParamSystemAudioStatus(message), true);
@@ -1445,6 +1446,12 @@
         mService.displayOsd(messageId);
     }
 
+    @ServiceThreadOnly
+    void displayOsd(int messageId, int extra) {
+        assertRunOnServiceThread();
+        mService.displayOsd(messageId, extra);
+    }
+
     // Seq #54 and #55
     @ServiceThreadOnly
     void startOneTouchRecord(int recorderAddress, byte[] recordSource) {
diff --git a/services/core/java/com/android/server/hdmi/HdmiCecMessageValidator.java b/services/core/java/com/android/server/hdmi/HdmiCecMessageValidator.java
index 8b345cf..0b3d9fb 100644
--- a/services/core/java/com/android/server/hdmi/HdmiCecMessageValidator.java
+++ b/services/core/java/com/android/server/hdmi/HdmiCecMessageValidator.java
@@ -51,7 +51,6 @@
     }
 
     final SparseArray<ValidationInfo> mValidationInfo = new SparseArray<>();
-    private final HdmiLogger mSpamSafeLogger = new HdmiLogger(TAG);
 
     public HdmiCecMessageValidator(HdmiControlService service) {
         mService = service;
@@ -183,32 +182,32 @@
         int opcode = message.getOpcode();
         ValidationInfo info = mValidationInfo.get(opcode);
         if (info == null) {
-            mSpamSafeLogger.warning("No validation information for the message: " + message);
+            HdmiLogger.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) {
-            mSpamSafeLogger.warning("Unexpected source: " + message);
+            HdmiLogger.warning("Unexpected source: " + message);
             return false;
         }
         // Check the destination field.
         if (message.getDestination() == Constants.ADDR_BROADCAST) {
             if ((info.addressType & DEST_BROADCAST) == 0) {
-                mSpamSafeLogger.warning("Unexpected broadcast message: " + message);
+                HdmiLogger.warning("Unexpected broadcast message: " + message);
                 return false;
             }
         } else {  // Direct addressing.
             if ((info.addressType & DEST_DIRECT) == 0) {
-                mSpamSafeLogger.warning("Unexpected direct message: " + message);
+                HdmiLogger.warning("Unexpected direct message: " + message);
                 return false;
             }
         }
 
         // Check the parameter type.
         if (!info.parameterValidator.isValid(message.getParams())) {
-            mSpamSafeLogger.warning("Unexpected parameters: " + message);
+            HdmiLogger.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 9314cf8..38c6fb3 100644
--- a/services/core/java/com/android/server/hdmi/HdmiControlService.java
+++ b/services/core/java/com/android/server/hdmi/HdmiControlService.java
@@ -166,8 +166,6 @@
     // 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 =
@@ -656,7 +654,7 @@
         if (mMessageValidator.isValid(command)) {
             mCecController.sendCommand(command, callback);
         } else {
-            mSpamSafeLogger.error("Invalid message type:" + command);
+            HdmiLogger.error("Invalid message type:" + command);
             if (callback != null) {
                 callback.onSendCompleted(Constants.SEND_RESULT_FAILURE);
             }
@@ -705,7 +703,7 @@
         }
 
         if (message.getDestination() != Constants.ADDR_BROADCAST) {
-            mSpamSafeLogger.warning("Unhandled cec command:" + message);
+            HdmiLogger.warning("Unhandled cec command:" + message);
         }
         return false;
     }
@@ -794,7 +792,6 @@
             // FLAG_HDMI_SYSTEM_AUDIO_VOLUME prevents audio manager from announcing
             // volume change notification back to hdmi control service.
             audioManager.setStreamVolume(AudioManager.STREAM_MUSIC, volume,
-                    AudioManager.FLAG_SHOW_UI |
                     AudioManager.FLAG_HDMI_SYSTEM_AUDIO_VOLUME);
         }
     }
@@ -2033,4 +2030,14 @@
         getContext().sendBroadcastAsUser(intent, UserHandle.ALL,
                 HdmiControlService.PERMISSION);
     }
+
+    @ServiceThreadOnly
+    void displayOsd(int messageId, int extra) {
+        assertRunOnServiceThread();
+        Intent intent = new Intent(HdmiControlManager.ACTION_OSD_MESSAGE);
+        intent.putExtra(HdmiControlManager.EXTRA_MESSAGE_ID, messageId);
+        intent.putExtra(HdmiControlManager.EXTRA_MESSAGE_EXTRAM_PARAM1, extra);
+        getContext().sendBroadcastAsUser(intent, UserHandle.ALL,
+                HdmiControlService.PERMISSION);
+    }
 }
diff --git a/services/core/java/com/android/server/hdmi/HdmiLogger.java b/services/core/java/com/android/server/hdmi/HdmiLogger.java
index c7add75..2562ffc 100644
--- a/services/core/java/com/android/server/hdmi/HdmiLogger.java
+++ b/services/core/java/com/android/server/hdmi/HdmiLogger.java
@@ -26,44 +26,83 @@
 /**
  * A logger that prevents spammy log. For the same log message, it logs once every 20seconds.
  * This class is not thread-safe.
+ * <p>
+ * For convenience, use single character prefix for all messages.
+ * Here are common acronyms
+ * <ul>
+ *   <li>[T]: Timout
+ *   <li>[R]: Received message
+ *   <li>[S]: Sent message
+ *   <li>[P]: Device polling result
+ * </ul>
  */
 final class HdmiLogger {
+    private static final String TAG = "HDMI";
     // Logging duration for same error message.
     private static final long ERROR_LOG_DURATTION_MILLIS = 20 * 1000;  // 20s
 
     private static final boolean DEBUG = false;
 
+    private static final ThreadLocal<HdmiLogger> sLogger = new ThreadLocal<>();
+
     // 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 = "HDMI:" + tag;
+    private HdmiLogger() {
     }
 
-    void warning(String logMessage) {
+    static final void warning(String logMessage, Object... objs) {
+        getLogger().warningInternal(toLogString(logMessage, objs));
+    }
+
+    private void warningInternal(String logMessage) {
         String log = updateLog(mWarningTimingCache, logMessage);
         if (!log.isEmpty()) {
-            Slog.w(mTag, log);
+            Slog.w(TAG, log);
         }
     }
 
-    void error(String logMessage) {
+    static final void error(String logMessage, Object... objs) {
+        getLogger().errorInternal(toLogString(logMessage, objs));
+    }
+
+    private void errorInternal(String logMessage) {
         String log = updateLog(mErrorTimingCache, logMessage);
         if (!log.isEmpty()) {
-            Slog.e(mTag, log);
+            Slog.e(TAG, log);
         }
     }
 
-    void debug(String logMessage) {
+    static final void debug(String logMessage, Object... objs) {
+        getLogger().debugInternal(toLogString(logMessage, objs));
+    }
+
+    private void debugInternal(String logMessage) {
         if (!DEBUG) {
             return;
         }
-        Slog.d(mTag, logMessage);
+        Slog.d(TAG, logMessage);
+    }
+
+    private static final String toLogString(String logMessage, Object[] objs) {
+        if (objs.length > 0) {
+            return String.format(logMessage, objs);
+        } else {
+            return logMessage;
+        }
+    }
+
+    private static HdmiLogger getLogger() {
+        HdmiLogger logger = sLogger.get();
+        if (logger == null) {
+            logger = new HdmiLogger();
+            sLogger.set(logger);
+        }
+        return logger;
     }
 
     private static String updateLog(HashMap<String, Pair<Long, Integer>> cache, String logMessage) {
diff --git a/services/core/java/com/android/server/hdmi/RequestArcAction.java b/services/core/java/com/android/server/hdmi/RequestArcAction.java
index 17c2d6c..3fb450f 100644
--- a/services/core/java/com/android/server/hdmi/RequestArcAction.java
+++ b/services/core/java/com/android/server/hdmi/RequestArcAction.java
@@ -85,6 +85,7 @@
         if (mState != state || state != STATE_WATING_FOR_REQUEST_ARC_REQUEST_RESPONSE) {
             return;
         }
+        HdmiLogger.debug("[T]RequestArcAction.");
         disableArcTransmission();
         finish();
     }
diff --git a/services/core/java/com/android/server/hdmi/RequestArcInitiationAction.java b/services/core/java/com/android/server/hdmi/RequestArcInitiationAction.java
index f25363d..d9e1f24 100644
--- a/services/core/java/com/android/server/hdmi/RequestArcInitiationAction.java
+++ b/services/core/java/com/android/server/hdmi/RequestArcInitiationAction.java
@@ -35,15 +35,15 @@
 
     @Override
     boolean start() {
+        mState = STATE_WATING_FOR_REQUEST_ARC_REQUEST_RESPONSE;
+        addTimer(mState, HdmiConfig.TIMEOUT_MS);
+
         HdmiCecMessage command = HdmiCecMessageBuilder.buildRequestArcInitiation(
                 getSourceAddress(), mAvrAddress);
         sendCommand(command, new HdmiControlService.SendMessageCallback() {
             @Override
             public void onSendCompleted(int error) {
-                if (error == Constants.SEND_RESULT_SUCCESS) {
-                    mState = STATE_WATING_FOR_REQUEST_ARC_REQUEST_RESPONSE;
-                    addTimer(mState, HdmiConfig.TIMEOUT_MS);
-                } else {
+                if (error != Constants.SEND_RESULT_SUCCESS) {
                     // If failed to send <Request ARC Initiation>, start "Disabled"
                     // ARC transmission action.
                     disableArcTransmission();
diff --git a/services/core/java/com/android/server/hdmi/RequestArcTerminationAction.java b/services/core/java/com/android/server/hdmi/RequestArcTerminationAction.java
index 1491c72..f5a0115 100644
--- a/services/core/java/com/android/server/hdmi/RequestArcTerminationAction.java
+++ b/services/core/java/com/android/server/hdmi/RequestArcTerminationAction.java
@@ -35,15 +35,15 @@
 
     @Override
     boolean start() {
+        mState = STATE_WATING_FOR_REQUEST_ARC_REQUEST_RESPONSE;
+        addTimer(mState, HdmiConfig.TIMEOUT_MS);
+
         HdmiCecMessage command =
                 HdmiCecMessageBuilder.buildRequestArcTermination(getSourceAddress(), mAvrAddress);
         sendCommand(command, new HdmiControlService.SendMessageCallback() {
             @Override
             public void onSendCompleted(int error) {
-                if (error == Constants.SEND_RESULT_SUCCESS) {
-                    mState = STATE_WATING_FOR_REQUEST_ARC_REQUEST_RESPONSE;
-                    addTimer(mState, HdmiConfig.TIMEOUT_MS);
-                } else {
+                if (error != Constants.SEND_RESULT_SUCCESS) {
                     // If failed to send <Request ARC Termination>, start "Disabled" ARC
                     // transmission action.
                     disableArcTransmission();
diff --git a/services/core/java/com/android/server/hdmi/SetArcTransmissionStateAction.java b/services/core/java/com/android/server/hdmi/SetArcTransmissionStateAction.java
index 30519f3..bffa854 100644
--- a/services/core/java/com/android/server/hdmi/SetArcTransmissionStateAction.java
+++ b/services/core/java/com/android/server/hdmi/SetArcTransmissionStateAction.java
@@ -53,6 +53,18 @@
     @Override
     boolean start() {
         if (mEnabled) {
+            // Enable ARC status immediately after sending <Report Arc Initiated>.
+            // If AVR responds with <Feature Abort>, disable ARC status again.
+            // This is different from spec that says that turns ARC status to
+            // "Enabled" if <Report ARC Initiated> is acknowledged and no
+            // <Feature Abort> is received.
+            // But implemented this way to save the time having to wait for
+            // <Feature Abort>.
+            setArcStatus(true);
+            // If succeeds to send <Report ARC Initiated>, wait general timeout
+            // to check whether there is no <Feature Abort> for <Report ARC Initiated>.
+            mState = STATE_WAITING_TIMEOUT;
+            addTimer(mState, HdmiConfig.TIMEOUT_MS);
             sendReportArcInitiated();
         } else {
             setArcStatus(false);
@@ -67,23 +79,11 @@
         sendCommand(command, new HdmiControlService.SendMessageCallback() {
             @Override
             public void onSendCompleted(int error) {
-                if (error == Constants.SEND_RESULT_SUCCESS) {
-                    // Enable ARC status immediately after sending <Report Arc Initiated>.
-                    // If AVR responds with <Feature Abort>, disable ARC status again.
-                    // This is different from spec that says that turns ARC status to
-                    // "Enabled" if <Report ARC Initiated> is acknowledged and no
-                    // <Feature Abort> is received.
-                    // But implemented this way to save the time having to wait for
-                    // <Feature Abort>.
-                    setArcStatus(true);
-                    // If succeeds to send <Report ARC Initiated>, wait general timeout
-                    // to check whether there is no <Feature Abort> for <Report ARC Initiated>.
-                    mState = STATE_WAITING_TIMEOUT;
-                    addTimer(mState, HdmiConfig.TIMEOUT_MS);
-                } else {
+                if (error != Constants.SEND_RESULT_SUCCESS) {
                     // If fails to send <Report ARC Initiated>, disable ARC and
                     // send <Report ARC Terminated> directly.
                     setArcStatus(false);
+                    HdmiLogger.debug("Failed to send <Report Arc Initiated>.");
                     finish();
                 }
             }
@@ -112,6 +112,7 @@
         if (opcode == Constants.MESSAGE_FEATURE_ABORT) {
             int originalOpcode = cmd.getParams()[0] & 0xFF;
             if (originalOpcode == Constants.MESSAGE_REPORT_ARC_INITIATED) {
+                HdmiLogger.debug("Feature aborted for <Report Arc Initiated>");
                 setArcStatus(false);
                 finish();
                 return true;
diff --git a/services/core/java/com/android/server/hdmi/SystemAudioAction.java b/services/core/java/com/android/server/hdmi/SystemAudioAction.java
index d15ffb0..0871194 100644
--- a/services/core/java/com/android/server/hdmi/SystemAudioAction.java
+++ b/services/core/java/com/android/server/hdmi/SystemAudioAction.java
@@ -98,7 +98,7 @@
             @Override
             public void onSendCompleted(int error) {
                 if (error != Constants.SEND_RESULT_SUCCESS) {
-                    DLOGGER.debug("Failed to send <System Audio Mode Request>:" + error);
+                    HdmiLogger.debug("Failed to send <System Audio Mode Request>:" + error);
                     setSystemAudioMode(false);
                     finishWithCallback(HdmiControlManager.RESULT_COMMUNICATION_FAILED);
                 }
@@ -111,7 +111,7 @@
     private void handleSendSystemAudioModeRequestTimeout() {
         if (!mTargetAudioStatus  // Don't retry for Off case.
                 || mSendRetryCount++ >= MAX_SEND_RETRY_COUNT) {
-            DLOGGER.debug("[T]:wait for <Set System Audio Mode>.");
+            HdmiLogger.debug("[T]:wait for <Set System Audio Mode>.");
             setSystemAudioMode(false);
             finishWithCallback(HdmiControlManager.RESULT_TIMEOUT);
             return;
@@ -130,7 +130,7 @@
                 if (cmd.getOpcode() == Constants.MESSAGE_FEATURE_ABORT
                         && (cmd.getParams()[0] & 0xFF)
                                 == Constants.MESSAGE_SYSTEM_AUDIO_MODE_REQUEST) {
-                    DLOGGER.debug("Failed to start system audio mode request.");
+                    HdmiLogger.debug("Failed to start system audio mode request.");
                     setSystemAudioMode(false);
                     finishWithCallback(HdmiControlManager.RESULT_EXCEPTION);
                     return true;
@@ -145,7 +145,7 @@
                     startAudioStatusAction();
                     return true;
                 } else {
-                    DLOGGER.debug("Unexpected system audio mode request:" + receivedStatus);
+                    HdmiLogger.debug("Unexpected system audio mode request:" + receivedStatus);
                     // Unexpected response, consider the request is newly initiated by AVR.
                     // To return 'false' will initiate new SystemAudioActionFromAvr by the control
                     // service.
diff --git a/services/core/java/com/android/server/hdmi/VolumeControlAction.java b/services/core/java/com/android/server/hdmi/VolumeControlAction.java
index ddc267a..4338fc7 100644
--- a/services/core/java/com/android/server/hdmi/VolumeControlAction.java
+++ b/services/core/java/com/android/server/hdmi/VolumeControlAction.java
@@ -17,66 +17,35 @@
 package com.android.server.hdmi;
 
 import static com.android.server.hdmi.Constants.IRT_MS;
+import static com.android.server.hdmi.Constants.MESSAGE_FEATURE_ABORT;
+import static com.android.server.hdmi.Constants.MESSAGE_REPORT_AUDIO_STATUS;
+import static com.android.server.hdmi.Constants.MESSAGE_USER_CONTROL_PRESSED;
 
-import com.android.internal.util.Preconditions;
+import android.media.AudioManager;
 
 /**
  * Feature action that transmits volume change to Audio Receiver.
  * <p>
- * This action is created when a user pressed volume up/down. However, Since Android only provides a
- * listener for delta of some volume change, we will set a target volume, and check reported volume
- * from Audio Receiver(AVR). If TV receives no &lt;Report Audio Status&gt; from AVR, this action
- * will be finished in {@link #IRT_MS} * {@link #VOLUME_CHANGE_TIMEOUT_MAX_COUNT} (ms).
+ * This action is created when a user pressed volume up/down. However, Android only provides a
+ * listener for delta of some volume change instead of individual key event. Also it's hard to know
+ * Audio Receiver's number of volume steps for a single volume control key. Because of this, it
+ * sends key-down event until IRT timeout happens, and it will send key-up event if no additional
+ * volume change happens; otherwise, it will send again key-down as press and hold feature does.
  */
 final class VolumeControlAction extends HdmiCecFeatureAction {
     private static final String TAG = "VolumeControlAction";
 
-    private static final int VOLUME_MUTE = 101;
-    private static final int VOLUME_RESTORE = 102;
+    // State that wait for next volume press.
+    private static final int STATE_WAIT_FOR_NEXT_VOLUME_PRESS = 1;
     private static final int MAX_VOLUME = 100;
-    private static final int MIN_VOLUME = 0;
 
-    // State where to wait for <Report Audio Status>
-    private static final int STATE_WAIT_FOR_REPORT_VOLUME_STATUS = 1;
-
-    // Maximum count of time out used to finish volume action.
-    private static final int VOLUME_CHANGE_TIMEOUT_MAX_COUNT = 2;
+    private static final int UNKNOWN_AVR_VOLUME = -1;
 
     private final int mAvrAddress;
-    private final int mTargetVolume;
-    private final boolean mIsVolumeUp;
-    private int mTimeoutCount;
-
-    /**
-     * Create a {@link VolumeControlAction} for mute/restore change
-     *
-     * @param source source device sending volume change
-     * @param avrAddress address of audio receiver
-     * @param mute whether to mute sound or not. {@code true} for mute on; {@code false} for mute
-     *            off, i.e restore volume
-     * @return newly created {@link VolumeControlAction}
-     */
-    public static VolumeControlAction ofMute(HdmiCecLocalDevice source, int avrAddress,
-            boolean mute) {
-        return new VolumeControlAction(source, avrAddress, mute ? VOLUME_MUTE : VOLUME_RESTORE,
-                false);
-    }
-
-    /**
-     * Create a {@link VolumeControlAction} for volume up/down change
-     *
-     * @param source source device sending volume change
-     * @param avrAddress address of audio receiver
-     * @param targetVolume target volume to be set to AVR. It should be in range of [0-100]
-     * @param isVolumeUp whether to volume up or not. {@code true} for volume up; {@code false} for
-     *            volume down
-     * @return newly created {@link VolumeControlAction}
-     */
-    public static VolumeControlAction ofVolumeChange(HdmiCecLocalDevice source, int avrAddress,
-            int targetVolume, boolean isVolumeUp) {
-        Preconditions.checkArgumentInRange(targetVolume, MIN_VOLUME, MAX_VOLUME, "volume");
-        return new VolumeControlAction(source, avrAddress, targetVolume, isVolumeUp);
-    }
+    private boolean mIsVolumeUp;
+    private long mLastKeyUpdateTime;
+    private int mLastAvrVolume;
+    private boolean mSentKeyPressed;
 
     /**
      * Scale a custom volume value to cec volume scale.
@@ -94,123 +63,141 @@
      *
      * @param cecVolume volume value in cec volume scale. It should be in a range of [0-100]
      * @param scale scale of custom volume (max volume)
-     * @return a volume value scaled to custom volume range
+     * @return a volume scaled to custom volume range
      */
     public static int scaleToCustomVolume(int cecVolume, int scale) {
         return (cecVolume * scale) / MAX_VOLUME;
     }
 
-    private VolumeControlAction(HdmiCecLocalDevice source, int avrAddress, int targetVolume,
-            boolean isVolumeUp) {
+    VolumeControlAction(HdmiCecLocalDevice source, int avrAddress, boolean isVolumeUp) {
         super(source);
-
         mAvrAddress = avrAddress;
-        mTargetVolume = targetVolume;
         mIsVolumeUp = isVolumeUp;
+        mLastAvrVolume = UNKNOWN_AVR_VOLUME;
+        mSentKeyPressed = false;
+
+        updateLastKeyUpdateTime();
+    }
+
+    private void updateLastKeyUpdateTime() {
+        mLastKeyUpdateTime = System.currentTimeMillis();
     }
 
     @Override
     boolean start() {
-        if (isForMute()) {
-            sendMuteChange(mTargetVolume == VOLUME_MUTE);
-            finish();
-            return true;
-        }
-
-        startVolumeChange();
+        mState = STATE_WAIT_FOR_NEXT_VOLUME_PRESS;
+        sendVolumeKeyPressed();
+        resetTimer();
         return true;
     }
 
-
-    private boolean isForMute() {
-        return mTargetVolume == VOLUME_MUTE || mTargetVolume == VOLUME_RESTORE;
-    }
-
-    private void startVolumeChange() {
-        mTimeoutCount = 0;
-        sendVolumeChange(mIsVolumeUp);
-        mState = STATE_WAIT_FOR_REPORT_VOLUME_STATUS;
-        addTimer(mState, IRT_MS);
-    }
-
-    private void sendVolumeChange(boolean up) {
+    private void sendVolumeKeyPressed() {
         sendCommand(HdmiCecMessageBuilder.buildUserControlPressed(getSourceAddress(), mAvrAddress,
-                up ? HdmiCecKeycode.CEC_KEYCODE_VOLUME_UP
+                mIsVolumeUp ? HdmiCecKeycode.CEC_KEYCODE_VOLUME_UP
                         : HdmiCecKeycode.CEC_KEYCODE_VOLUME_DOWN));
+        mSentKeyPressed = true;
     }
 
-    private void sendMuteChange(boolean mute) {
-        sendUserControlPressedAndReleased(mAvrAddress,
-                mute ? HdmiCecKeycode.CEC_KEYCODE_MUTE_FUNCTION :
-                        HdmiCecKeycode.CEC_KEYCODE_RESTORE_VOLUME_FUNCTION);
+    private void resetTimer() {
+        mActionTimer.clearTimerMessage();
+        addTimer(STATE_WAIT_FOR_NEXT_VOLUME_PRESS, IRT_MS);
+    }
+
+    void handleVolumeChange(boolean isVolumeUp) {
+        if (mIsVolumeUp != isVolumeUp) {
+            HdmiLogger.debug("Volume Key Status Changed[old:%b new:%b]", mIsVolumeUp, isVolumeUp);
+            sendVolumeKeyReleased();
+            mIsVolumeUp = isVolumeUp;
+        }
+        updateLastKeyUpdateTime();
+    }
+
+    private void sendVolumeKeyReleased() {
+        sendCommand(HdmiCecMessageBuilder.buildUserControlReleased(
+                getSourceAddress(), mAvrAddress));
+        mSentKeyPressed = false;
     }
 
     @Override
     boolean processCommand(HdmiCecMessage cmd) {
-        if (mState != STATE_WAIT_FOR_REPORT_VOLUME_STATUS) {
+        if (mState != STATE_WAIT_FOR_NEXT_VOLUME_PRESS || cmd.getSource() != mAvrAddress) {
             return false;
         }
 
         switch (cmd.getOpcode()) {
-            case Constants.MESSAGE_REPORT_AUDIO_STATUS:
-                handleReportAudioStatus(cmd);
-                return true;
-            case Constants.MESSAGE_FEATURE_ABORT:
-                int originalOpcode = cmd.getParams()[0] & 0xFF;
-                if (originalOpcode == Constants.MESSAGE_USER_CONTROL_PRESSED
-                        || originalOpcode == Constants.MESSAGE_USER_CONTROL_RELEASED) {
-                    // TODO: handle feature abort.
-                    finish();
-                    return true;
-                }
-            default:  // fall through
+            case MESSAGE_REPORT_AUDIO_STATUS:
+                return handleReportAudioStatus(cmd);
+            case MESSAGE_FEATURE_ABORT:
+                return handleFeatureAbort(cmd);
+            default:
                 return false;
         }
     }
 
-    private void handleReportAudioStatus(HdmiCecMessage cmd) {
-        byte[] params = cmd.getParams();
+    private boolean handleReportAudioStatus(HdmiCecMessage cmd) {
+        byte params[] = cmd.getParams();
+        boolean mute = (params[0] & 0x80) == 0x80;
         int volume = params[0] & 0x7F;
-        // Update volume with new value.
-        // Note that it will affect system volume change.
-        tv().setAudioStatus(false, volume);
-        if (mIsVolumeUp) {
-            if (mTargetVolume <= volume) {
-                finishWithVolumeChangeRelease();
-                return;
-            }
-        } else {
-            if (mTargetVolume >= volume) {
-                finishWithVolumeChangeRelease();
-                return;
-            }
+        mLastAvrVolume = volume;
+        if (shouldUpdateAudioVolume(mute)) {
+            HdmiLogger.debug("Force volume change[mute:%b, volume=%d]", mute, volume);
+            tv().setAudioStatus(mute, volume);
         }
-
-        // Clear action status and send another volume change command.
-        clear();
-        startVolumeChange();
+        return true;
     }
 
-    private void finishWithVolumeChangeRelease() {
-        sendCommand(HdmiCecMessageBuilder.buildUserControlReleased(
-                getSourceAddress(), mAvrAddress));
-        finish();
+    private boolean shouldUpdateAudioVolume(boolean mute) {
+        // Do nothing if in mute.
+        if (mute) {
+            return true;
+        }
+
+        // Update audio status if current volume position is edge of volume bar,
+        // i.e max or min volume.
+        AudioManager audioManager = tv().getService().getAudioManager();
+        int currentVolume = audioManager.getStreamVolume(AudioManager.STREAM_MUSIC);
+        if (mIsVolumeUp) {
+            int maxVolume = audioManager.getStreamMaxVolume(AudioManager.STREAM_MUSIC);
+            return currentVolume == maxVolume;
+        } else {
+            return currentVolume == 0;
+        }
+    }
+
+    private boolean handleFeatureAbort(HdmiCecMessage cmd) {
+        int originalOpcode = cmd.getParams()[0] & 0xFF;
+        // Since it sends <User Control Released> only when it finishes this action,
+        // it takes care of <User Control Pressed> only here.
+        if (originalOpcode == MESSAGE_USER_CONTROL_PRESSED) {
+            finish();
+            return true;
+        }
+        return false;
+    }
+
+    @Override
+    protected void clear() {
+        super.clear();
+        if (mSentKeyPressed) {
+            sendVolumeKeyReleased();
+        }
+        if (mLastAvrVolume != UNKNOWN_AVR_VOLUME) {
+            tv().setAudioStatus(false, mLastAvrVolume);
+            mLastAvrVolume = UNKNOWN_AVR_VOLUME;
+        }
     }
 
     @Override
     void handleTimerEvent(int state) {
-        if (mState != STATE_WAIT_FOR_REPORT_VOLUME_STATUS) {
+        if (state != STATE_WAIT_FOR_NEXT_VOLUME_PRESS) {
             return;
         }
 
-        // If no report volume action after IRT * VOLUME_CHANGE_TIMEOUT_MAX_COUNT just stop volume
-        // action.
-        if (++mTimeoutCount == VOLUME_CHANGE_TIMEOUT_MAX_COUNT) {
-            finishWithVolumeChangeRelease();
-            return;
+        if (System.currentTimeMillis() - mLastKeyUpdateTime >= IRT_MS) {
+            finish();
+        } else {
+            sendVolumeKeyPressed();
+            resetTimer();
         }
-
-        sendVolumeChange(mIsVolumeUp);
-        addTimer(mState, IRT_MS);
     }
 }