From 44caf0ed75697e8b33346bece6e1b022403abe99 Mon Sep 17 00:00:00 2001 From: Jean-Michel Trivi Date: Fri, 21 Aug 2020 15:44:55 -0700 Subject: [PATCH] AudioService: check calls to AudioSystem.initStreamVolume AudioSystem.initStreamVolume initializes the min and max stream volume indices. The return value was never checked to ensure success of the call. An unchecked failure could leave min/max values at -1 in native AudioPolicyManager, which could lead to no valid volume to be set, and thus no audio would be heard as a result. The fix consists in ensuring we retry initializing the stream volumes whenever an error is detected when calling the initialization method, or after checking whether the min/max values are valid after initialization. Bug: 161950968 Test: adb shell dumpsys audio, check lifecycle section Change-Id: I3714c0db2a9657a88488635f7d6c78e682f326aa Merged-In: I3714c0db2a9657a88488635f7d6c78e682f326aa --- .../server/audio/AudioEventLogger.java | 31 ++++- .../android/server/audio/AudioService.java | 109 ++++++++++++++++-- 2 files changed, 129 insertions(+), 11 deletions(-) diff --git a/services/core/java/com/android/server/audio/AudioEventLogger.java b/services/core/java/com/android/server/audio/AudioEventLogger.java index 9ebd75bd0f648..af0e978726e3a 100644 --- a/services/core/java/com/android/server/audio/AudioEventLogger.java +++ b/services/core/java/com/android/server/audio/AudioEventLogger.java @@ -60,7 +60,36 @@ public class AudioEventLogger { * @return the same instance of the event */ public Event printLog(String tag) { - Log.i(tag, eventToString()); + return printLog(ALOGI, tag); + } + + public static final int ALOGI = 0; + public static final int ALOGE = 1; + public static final int ALOGW = 2; + public static final int ALOGV = 3; + + /** + * Same as {@link #printLog(String)} with a log type + * @param type one of {@link #ALOGI}, {@link #ALOGE}, {@link #ALOGV} + * @param tag + * @return + */ + public Event printLog(int type, String tag) { + switch (type) { + case ALOGI: + Log.i(tag, eventToString()); + break; + case ALOGE: + Log.e(tag, eventToString()); + break; + case ALOGW: + Log.w(tag, eventToString()); + break; + case ALOGV: + default: + Log.v(tag, eventToString()); + break; + } return this; } diff --git a/services/core/java/com/android/server/audio/AudioService.java b/services/core/java/com/android/server/audio/AudioService.java index fe619690ae345..75c27603d7859 100755 --- a/services/core/java/com/android/server/audio/AudioService.java +++ b/services/core/java/com/android/server/audio/AudioService.java @@ -26,6 +26,10 @@ import static android.provider.Settings.Secure.VOLUME_HUSH_MUTE; import static android.provider.Settings.Secure.VOLUME_HUSH_OFF; import static android.provider.Settings.Secure.VOLUME_HUSH_VIBRATE; +import static com.android.server.audio.AudioEventLogger.Event.ALOGE; +import static com.android.server.audio.AudioEventLogger.Event.ALOGI; +import static com.android.server.audio.AudioEventLogger.Event.ALOGW; + import android.Manifest; import android.annotation.IntDef; import android.annotation.NonNull; @@ -284,6 +288,7 @@ public class AudioService extends IAudioService.Stub private static final int MSG_PLAYBACK_CONFIG_CHANGE = 29; private static final int MSG_BROADCAST_MICROPHONE_MUTE = 30; private static final int MSG_CHECK_MODE_FOR_UID = 31; + private static final int MSG_REINIT_VOLUMES = 32; // start of messages handled under wakelock // these messages can only be queued, i.e. sent with queueMsgUnderWakeLock(), // and not with sendMsg(..., ..., SENDMSG_QUEUE, ...) @@ -673,6 +678,7 @@ public class AudioService extends IAudioService.Stub public AudioService(Context context, AudioSystemAdapter audioSystem, SystemServerAdapter systemServer) { + sLifecycleLogger.log(new AudioEventLogger.StringEvent("AudioService()")); mContext = context; mContentResolver = context.getContentResolver(); mAppOps = (AppOpsManager)context.getSystemService(Context.APP_OPS_SERVICE); @@ -892,6 +898,9 @@ public class AudioService extends IAudioService.Stub mPrescaleAbsoluteVolume[i] = preScale[i]; } } + + // check on volume initialization + checkVolumeRangeInitialization("AudioService()"); } public void systemReady() { @@ -1019,11 +1028,15 @@ public class AudioService extends IAudioService.Stub if (!mSystemReady || (AudioSystem.checkAudioFlinger() != AudioSystem.AUDIO_STATUS_OK)) { Log.e(TAG, "Audioserver died."); + sLifecycleLogger.log(new AudioEventLogger.StringEvent( + "onAudioServerDied() audioserver died")); sendMsg(mAudioHandler, MSG_AUDIO_SERVER_DIED, SENDMSG_NOOP, 0, 0, null, 500); return; } - Log.e(TAG, "Audioserver started."); + Log.i(TAG, "Audioserver started."); + sLifecycleLogger.log(new AudioEventLogger.StringEvent( + "onAudioServerDied() audioserver started")); updateAudioHalPids(); @@ -1058,14 +1071,7 @@ public class AudioService extends IAudioService.Stub mDeviceBroker.setForceUse_Async(AudioSystem.FOR_SYSTEM, forSys, "onAudioServerDied"); // Restore stream volumes - int numStreamTypes = AudioSystem.getNumStreamTypes(); - for (int streamType = numStreamTypes - 1; streamType >= 0; streamType--) { - VolumeStreamState streamState = mStreamStates[streamType]; - AudioSystem.initStreamVolume( - streamType, streamState.mIndexMin / 10, streamState.mIndexMax / 10); - - streamState.applyAllVolumes(); - } + onReinitVolumes("after audioserver restart"); // Restore audio volume groups restoreVolumeGroups(); @@ -1163,6 +1169,72 @@ public class AudioService extends IAudioService.Stub setMicMuteFromSwitchInput(); } + private void onReinitVolumes(@NonNull String caller) { + final int numStreamTypes = AudioSystem.getNumStreamTypes(); + // keep track of any error during stream volume initialization + int status = AudioSystem.AUDIO_STATUS_OK; + for (int streamType = numStreamTypes - 1; streamType >= 0; streamType--) { + VolumeStreamState streamState = mStreamStates[streamType]; + final int res = AudioSystem.initStreamVolume( + streamType, streamState.mIndexMin / 10, streamState.mIndexMax / 10); + if (res != AudioSystem.AUDIO_STATUS_OK) { + status = res; + Log.e(TAG, "Failed to initStreamVolume (" + res + ") for stream " + streamType); + // stream volume initialization failed, no need to try the others, it will be + // attempted again when MSG_REINIT_VOLUMES is handled + break; + } + streamState.applyAllVolumes(); + } + + // did it work? check based on status + if (status != AudioSystem.AUDIO_STATUS_OK) { + sLifecycleLogger.log(new AudioEventLogger.StringEvent( + caller + ": initStreamVolume failed with " + status + " will retry") + .printLog(ALOGE, TAG)); + sendMsg(mAudioHandler, MSG_REINIT_VOLUMES, SENDMSG_NOOP, 0, 0, + caller /*obj*/, 2 * INDICATE_SYSTEM_READY_RETRY_DELAY_MS); + return; + } + + // did it work? check based on min/max values of some basic streams + if (!checkVolumeRangeInitialization(caller)) { + return; + } + + // success + sLifecycleLogger.log(new AudioEventLogger.StringEvent( + caller + ": initStreamVolume succeeded").printLog(ALOGI, TAG)); + } + + /** + * Check volume ranges were properly initialized + * @return true if volume ranges were successfully initialized + */ + private boolean checkVolumeRangeInitialization(String caller) { + boolean success = true; + final int[] basicStreams = { AudioSystem.STREAM_ALARM, AudioSystem.STREAM_RING, + AudioSystem.STREAM_MUSIC, AudioSystem.STREAM_VOICE_CALL, + AudioSystem.STREAM_ACCESSIBILITY }; + for (int streamType : basicStreams) { + final AudioAttributes aa = new AudioAttributes.Builder() + .setInternalLegacyStreamType(streamType).build(); + if (AudioSystem.getMaxVolumeIndexForAttributes(aa) < 0 + || AudioSystem.getMinVolumeIndexForAttributes(aa) < 0) { + success = false; + break; + } + } + if (!success) { + sLifecycleLogger.log(new AudioEventLogger.StringEvent( + caller + ": initStreamVolume succeeded but invalid mix/max levels, will retry") + .printLog(ALOGW, TAG)); + sendMsg(mAudioHandler, MSG_REINIT_VOLUMES, SENDMSG_NOOP, 0, 0, + caller /*obj*/, 2 * INDICATE_SYSTEM_READY_RETRY_DELAY_MS); + } + return success; + } + private void onDispatchAudioServerStateChange(boolean state) { synchronized (mAudioServerStateListeners) { for (AsdProxy asdp : mAudioServerStateListeners.values()) { @@ -5579,7 +5651,15 @@ public class AudioService extends IAudioService.Stub mIndexMin = MIN_STREAM_VOLUME[streamType] * 10; mIndexMinNoPerm = mIndexMin; // may be overwritten later in updateNoPermMinIndex() mIndexMax = MAX_STREAM_VOLUME[streamType] * 10; - AudioSystem.initStreamVolume(streamType, mIndexMin / 10, mIndexMax / 10); + final int status = AudioSystem.initStreamVolume( + streamType, mIndexMin / 10, mIndexMax / 10); + if (status != AudioSystem.AUDIO_STATUS_OK) { + sLifecycleLogger.log(new AudioEventLogger.StringEvent( + "VSS() stream:" + streamType + " initStreamVolume=" + status) + .printLog(ALOGE, TAG)); + sendMsg(mAudioHandler, MSG_REINIT_VOLUMES, SENDMSG_NOOP, 0, 0, + "VSS()" /*obj*/, 2 * INDICATE_SYSTEM_READY_RETRY_DELAY_MS); + } readSettings(); mVolumeChanged = new Intent(AudioManager.VOLUME_CHANGED_ACTION); @@ -6433,6 +6513,10 @@ public class AudioService extends IAudioService.Stub mModeLogger.log(new PhoneStateEvent(h.getPackage(), h.getPid())); } break; + + case MSG_REINIT_VOLUMES: + onReinitVolumes((String) msg.obj); + break; } } } @@ -7363,12 +7447,16 @@ public class AudioService extends IAudioService.Stub //========================================================================================== // AudioService logging and dumpsys //========================================================================================== + static final int LOG_NB_EVENTS_LIFECYCLE = 20; static final int LOG_NB_EVENTS_PHONE_STATE = 20; static final int LOG_NB_EVENTS_DEVICE_CONNECTION = 30; static final int LOG_NB_EVENTS_FORCE_USE = 20; static final int LOG_NB_EVENTS_VOLUME = 40; static final int LOG_NB_EVENTS_DYN_POLICY = 10; + static final AudioEventLogger sLifecycleLogger = new AudioEventLogger(LOG_NB_EVENTS_LIFECYCLE, + "audio services lifecycle"); + final private AudioEventLogger mModeLogger = new AudioEventLogger(LOG_NB_EVENTS_PHONE_STATE, "phone state (logged after successful call to AudioSystem.setPhoneState(int, int))"); @@ -7445,6 +7533,7 @@ public class AudioService extends IAudioService.Stub protected void dump(FileDescriptor fd, PrintWriter pw, String[] args) { if (!DumpUtils.checkDumpPermission(mContext, TAG, pw)) return; + sLifecycleLogger.dump(pw); if (mAudioHandler != null) { pw.println("\nMessage handler (watch for unhandled messages):"); mAudioHandler.dump(new PrintWriterPrinter(pw), " ");