Fix system audio mode failure in boot up
This bug happens because <Set System Audio Mode> is arrived
before <Give System Audio Mode Status>'s send result callback
is called in service thread. We do set internal state
on callback resut.
This change sets state when we send command.
Along with this, add more debug log to help future debugging.
Bug: 17309726
Change-Id: I0e41f684372a4c8891a90f724944227fc689e053
diff --git a/services/core/java/com/android/server/hdmi/HdmiCecController.java b/services/core/java/com/android/server/hdmi/HdmiCecController.java
index 827b3ed..3aed6f0 100644
--- a/services/core/java/com/android/server/hdmi/HdmiCecController.java
+++ b/services/core/java/com/android/server/hdmi/HdmiCecController.java
@@ -446,7 +446,7 @@
allocated.add(address);
}
}
- mIoThreadLogger.debug("DevicePollingResult:" + allocated);
+ mIoThreadLogger.debug("[P]:Allocated Address=" + allocated);
if (callback != null) {
runOnServiceThread(new Runnable() {
@Override
@@ -548,7 +548,7 @@
runOnIoThread(new Runnable() {
@Override
public void run() {
- mIoThreadLogger.debug("SendCommand:" + cecMessage);
+ mIoThreadLogger.debug("[S]:" + cecMessage);
byte[] body = buildBody(cecMessage.getOpcode(), cecMessage.getParams());
int i = 0;
int errorCode = Constants.SEND_RESULT_SUCCESS;
@@ -583,7 +583,7 @@
private void handleIncomingCecCommand(int srcAddress, int dstAddress, byte[] body) {
assertRunOnServiceThread();
HdmiCecMessage command = HdmiCecMessageBuilder.of(srcAddress, dstAddress, body);
- mServiceThreadLogger.debug("ReceiveCommand:" + command);
+ mServiceThreadLogger.debug("[R]:" + command);
onReceiveCommand(command);
}
diff --git a/services/core/java/com/android/server/hdmi/HdmiCecFeatureAction.java b/services/core/java/com/android/server/hdmi/HdmiCecFeatureAction.java
index 26d2cde..85f5be2 100644
--- a/services/core/java/com/android/server/hdmi/HdmiCecFeatureAction.java
+++ b/services/core/java/com/android/server/hdmi/HdmiCecFeatureAction.java
@@ -43,6 +43,9 @@
*/
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;
diff --git a/services/core/java/com/android/server/hdmi/HdmiLogger.java b/services/core/java/com/android/server/hdmi/HdmiLogger.java
index ee9379d..c7add75 100644
--- a/services/core/java/com/android/server/hdmi/HdmiLogger.java
+++ b/services/core/java/com/android/server/hdmi/HdmiLogger.java
@@ -42,7 +42,7 @@
private final String mTag;
HdmiLogger(String tag) {
- mTag = tag;
+ mTag = "HDMI:" + tag;
}
void warning(String logMessage) {
diff --git a/services/core/java/com/android/server/hdmi/SystemAudioAction.java b/services/core/java/com/android/server/hdmi/SystemAudioAction.java
index ac2c7b9..d15ffb0 100644
--- a/services/core/java/com/android/server/hdmi/SystemAudioAction.java
+++ b/services/core/java/com/android/server/hdmi/SystemAudioAction.java
@@ -73,9 +73,9 @@
// Seq #27
protected void sendSystemAudioModeRequest() {
- mState = STATE_CHECK_ROUTING_IN_PRGRESS;
List<RoutingControlAction> routingActions = getActions(RoutingControlAction.class);
if (!routingActions.isEmpty()) {
+ mState = STATE_CHECK_ROUTING_IN_PRGRESS;
// Should have only one Routing Control Action
RoutingControlAction routingAction = routingActions.get(0);
routingAction.addOnFinishedCallback(this, new Runnable() {
@@ -97,20 +97,21 @@
sendCommand(command, new HdmiControlService.SendMessageCallback() {
@Override
public void onSendCompleted(int error) {
- if (error == Constants.SEND_RESULT_SUCCESS) {
- mState = STATE_WAIT_FOR_SET_SYSTEM_AUDIO_MODE;
- addTimer(mState, mTargetAudioStatus ? ON_TIMEOUT_MS : OFF_TIMEOUT_MS);
- } else {
+ if (error != Constants.SEND_RESULT_SUCCESS) {
+ DLOGGER.debug("Failed to send <System Audio Mode Request>:" + error);
setSystemAudioMode(false);
finishWithCallback(HdmiControlManager.RESULT_COMMUNICATION_FAILED);
}
}
});
+ mState = STATE_WAIT_FOR_SET_SYSTEM_AUDIO_MODE;
+ addTimer(mState, mTargetAudioStatus ? ON_TIMEOUT_MS : OFF_TIMEOUT_MS);
}
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>.");
setSystemAudioMode(false);
finishWithCallback(HdmiControlManager.RESULT_TIMEOUT);
return;
@@ -129,6 +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.");
setSystemAudioMode(false);
finishWithCallback(HdmiControlManager.RESULT_EXCEPTION);
return true;
@@ -143,6 +145,7 @@
startAudioStatusAction();
return true;
} else {
+ DLOGGER.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.