AudioService: log stream mute events

Mute events are logged separately from volume events as
those happen more often and would cause older mute events
to roll off the logging window
Log an error when trying to unmute a stream that should
stay muted due to the set of muted streams by ringer and
zen mode.

Also invert muting and updating mask of muted streams
so the state always precedes the update of the stream,
in order to identify incorrect mute state changes.

Bug: 278661956
Test: adb shell dumpsys audio | grep -A 30 "mute commands"
Change-Id: I6091b0e2a449aea4e21167678304811ca8a4ef53
This commit is contained in:
Jean-Michel Trivi
2023-05-05 18:49:57 -07:00
parent 8cd878fbcf
commit a7f114849b
2 changed files with 115 additions and 20 deletions

View File

@@ -624,7 +624,7 @@ public class AudioService extends IAudioService.Stub
private int mZenModeAffectedStreams = 0;
// Streams currently muted by ringer mode and dnd
private int mRingerAndZenModeMutedStreams;
protected static volatile int sRingerAndZenModeMutedStreams;
/** Streams that can be muted. Do not resolve to aliases when checking.
* @see System#MUTE_STREAMS_AFFECTED */
@@ -1320,7 +1320,9 @@ public class AudioService extends IAudioService.Stub
// Call setRingerModeInt() to apply correct mute
// state on streams affected by ringer mode.
mRingerAndZenModeMutedStreams = 0;
sRingerAndZenModeMutedStreams = 0;
sMuteLogger.enqueue(new AudioServiceEvents.RingerZenMutedStreamsEvent(
sRingerAndZenModeMutedStreams, "onInitStreamsAndVolumes"));
setRingerModeInt(getRingerModeInternal(), false);
final float[] preScale = new float[3];
@@ -2132,7 +2134,7 @@ public class AudioService extends IAudioService.Stub
// Unmute streams if required and device is full volume
if (isStreamMute(streamType) && mFullVolumeDevices.contains(device)) {
mStreamStates[streamType].mute(false);
mStreamStates[streamType].mute(false, "updateVolumeStates(" + caller);
}
}
}
@@ -3681,7 +3683,7 @@ public class AudioService extends IAudioService.Stub
if (!(mCameraSoundForced
&& (vss.getStreamType()
== AudioSystem.STREAM_SYSTEM_ENFORCED))) {
boolean changed = vss.mute(state, /* apply= */ false);
boolean changed = vss.mute(state, /* apply= */ false, "muteAliasStreams");
if (changed) {
streamsToMute.add(stream);
}
@@ -3708,7 +3710,8 @@ public class AudioService extends IAudioService.Stub
boolean wasMuted;
synchronized (VolumeStreamState.class) {
final VolumeStreamState streamState = mStreamStates[stream];
wasMuted = streamState.mute(false); // if unmuting causes a change, it was muted
// if unmuting causes a change, it was muted
wasMuted = streamState.mute(false, "onUnmuteStream");
final int device = getDeviceForStream(stream);
final int index = streamState.getIndex(device);
@@ -3801,13 +3804,13 @@ public class AudioService extends IAudioService.Stub
/*package*/ void onSetStreamVolume(int streamType, int index, int flags, int device,
String caller, boolean hasModifyAudioSettings, boolean canChangeMute) {
final int stream = mStreamVolumeAlias[streamType];
setStreamVolumeInt(stream, index, device, false, caller, hasModifyAudioSettings);
// setting volume on ui sounds stream type also controls silent mode
if (((flags & AudioManager.FLAG_ALLOW_RINGER_MODES) != 0) ||
(stream == getUiSoundsStreamType())) {
setRingerMode(getNewRingerMode(stream, index, flags),
TAG + ".onSetStreamVolume", false /*external*/);
}
setStreamVolumeInt(stream, index, device, false, caller, hasModifyAudioSettings);
// setting non-zero volume for a muted stream unmutes the stream and vice versa
// except for BT SCO stream where only explicit mute is allowed to comply to BT requirements
if ((streamType != AudioSystem.STREAM_BLUETOOTH_SCO) && canChangeMute) {
@@ -5498,12 +5501,16 @@ public class AudioService extends IAudioService.Stub
PERSIST_DELAY);
}
}
mStreamStates[streamType].mute(false);
mRingerAndZenModeMutedStreams &= ~(1 << streamType);
sRingerAndZenModeMutedStreams &= ~(1 << streamType);
sMuteLogger.enqueue(new AudioServiceEvents.RingerZenMutedStreamsEvent(
sRingerAndZenModeMutedStreams, "muteRingerModeStreams"));
mStreamStates[streamType].mute(false, "muteRingerModeStreams");
} else {
// mute
mStreamStates[streamType].mute(true);
mRingerAndZenModeMutedStreams |= (1 << streamType);
sRingerAndZenModeMutedStreams |= (1 << streamType);
sMuteLogger.enqueue(new AudioServiceEvents.RingerZenMutedStreamsEvent(
sRingerAndZenModeMutedStreams, "muteRingerModeStreams"));
mStreamStates[streamType].mute(true, "muteRingerModeStreams");
}
}
}
@@ -6702,7 +6709,7 @@ public class AudioService extends IAudioService.Stub
}
private boolean isStreamMutedByRingerOrZenMode(int streamType) {
return (mRingerAndZenModeMutedStreams & (1 << streamType)) != 0;
return (sRingerAndZenModeMutedStreams & (1 << streamType)) != 0;
}
/**
@@ -7613,7 +7620,7 @@ public class AudioService extends IAudioService.Stub
Log.i(TAG, String.format("onAccessoryPlugMediaUnmute unmuting device=%d [%s]",
newDevice, AudioSystem.getOutputDeviceName(newDevice)));
}
mStreamStates[AudioSystem.STREAM_MUSIC].mute(false);
mStreamStates[AudioSystem.STREAM_MUSIC].mute(false, "onAccessoryPlugMediaUnmute");
}
}
@@ -7989,7 +7996,8 @@ public class AudioService extends IAudioService.Stub
true /*hasModifyAudioSettings*/);
}
if ((isMuted() != streamMuted) && isVssMuteBijective(stream)) {
mStreamStates[stream].mute(isMuted());
mStreamStates[stream].mute(isMuted(),
"VGS.applyAllVolumes#1");
}
}
}
@@ -8030,7 +8038,7 @@ public class AudioService extends IAudioService.Stub
true /*hasModifyAudioSettings*/);
}
if ((isMuted() != streamMuted) && isVssMuteBijective(stream)) {
mStreamStates[stream].mute(isMuted());
mStreamStates[stream].mute(isMuted(), "VGS.applyAllVolumes#2");
}
}
}
@@ -8718,10 +8726,10 @@ public class AudioService extends IAudioService.Stub
* @param state the new mute state
* @return true if the mute state was changed
*/
public boolean mute(boolean state) {
public boolean mute(boolean state, String source) {
boolean changed = false;
synchronized (VolumeStreamState.class) {
changed = mute(state, true);
changed = mute(state, true, source);
}
if (changed) {
broadcastMuteSetting(mStreamType, state);
@@ -8770,10 +8778,21 @@ public class AudioService extends IAudioService.Stub
* It prevents unnecessary calls to {@see AudioSystem#setStreamVolume}
* @return true if the mute state was changed
*/
public boolean mute(boolean state, boolean apply) {
public boolean mute(boolean state, boolean apply, String src) {
synchronized (VolumeStreamState.class) {
boolean changed = state != mIsMuted;
if (changed) {
sMuteLogger.enqueue(
new AudioServiceEvents.StreamMuteEvent(mStreamType, state, src));
// check to see if unmuting should not have happened due to ringer muted streams
if (!state && isStreamMutedByRingerOrZenMode(mStreamType)) {
Log.e(TAG, "Unmuting stream " + mStreamType
+ " despite ringer-zen muted stream 0x"
+ Integer.toHexString(AudioService.sRingerAndZenModeMutedStreams),
new Exception()); // this will put a stack trace in the logs
sMuteLogger.enqueue(new AudioServiceEvents.StreamUnmuteErrorEvent(
mStreamType, AudioService.sRingerAndZenModeMutedStreams));
}
mIsMuted = state;
if (apply) {
doMute();
@@ -9378,9 +9397,9 @@ public class AudioService extends IAudioService.Stub
public void onChange(boolean selfChange) {
super.onChange(selfChange);
// FIXME This synchronized is not necessary if mSettingsLock only protects mRingerMode.
// However there appear to be some missing locks around mRingerAndZenModeMutedStreams
// However there appear to be some missing locks around sRingerAndZenModeMutedStreams
// and mRingerModeAffectedStreams, so will leave this synchronized for now.
// mRingerAndZenModeMutedStreams and mMuteAffectedStreams are safe (only accessed once).
// sRingerAndZenModeMutedStreams and mMuteAffectedStreams are safe (only accessed once).
synchronized (mSettingsLock) {
if (updateRingerAndZenModeAffectedStreams()) {
/*
@@ -10873,6 +10892,9 @@ public class AudioService extends IAudioService.Stub
sLifecycleLogger = new EventLogger(LOG_NB_EVENTS_LIFECYCLE,
"audio services lifecycle");
static final EventLogger sMuteLogger = new EventLogger(30,
"mute commands");
final private EventLogger
mModeLogger = new EventLogger(LOG_NB_EVENTS_PHONE_STATE,
"phone state (logged after successful call to AudioSystem.setPhoneState(int, int))");
@@ -10913,7 +10935,7 @@ public class AudioService extends IAudioService.Stub
pw.println("- mode (external) = " + RINGER_MODE_NAMES[mRingerModeExternal]);
pw.println("- zen mode:" + Settings.Global.zenModeToString(mNm.getZenMode()));
dumpRingerModeStreams(pw, "affected", mRingerModeAffectedStreams);
dumpRingerModeStreams(pw, "muted", mRingerAndZenModeMutedStreams);
dumpRingerModeStreams(pw, "muted", sRingerAndZenModeMutedStreams);
pw.print("- delegate = "); pw.println(mRingerModeDelegate);
}
@@ -11039,6 +11061,8 @@ public class AudioService extends IAudioService.Stub
pw.println("\n");
sVolumeLogger.dump(pw);
pw.println("\n");
sMuteLogger.dump(pw);
pw.println("\n");
dumpSupportedSystemUsage(pw);
pw.println("\n");

View File

@@ -563,4 +563,75 @@ public class AudioServiceEvents {
return new StringBuilder("FIXME invalid event type:").append(mEventType).toString();
}
}
/**
* Class to log stream type mute/unmute events
*/
static final class StreamMuteEvent extends EventLogger.Event {
final int mStreamType;
final boolean mMuted;
final String mSource;
StreamMuteEvent(int streamType, boolean muted, String source) {
mStreamType = streamType;
mMuted = muted;
mSource = source;
}
@Override
public String eventToString() {
final String streamName =
(mStreamType <= AudioSystem.getNumStreamTypes() && mStreamType >= 0)
? AudioSystem.STREAM_NAMES[mStreamType]
: ("stream " + mStreamType);
return new StringBuilder(streamName)
.append(mMuted ? " muting by " : " unmuting by ")
.append(mSource)
.toString();
}
}
/**
* Class to log unmute errors that contradict the ringer/zen mode muted streams
*/
static final class StreamUnmuteErrorEvent extends EventLogger.Event {
final int mStreamType;
final int mRingerZenMutedStreams;
StreamUnmuteErrorEvent(int streamType, int ringerZenMutedStreams) {
mStreamType = streamType;
mRingerZenMutedStreams = ringerZenMutedStreams;
}
@Override
public String eventToString() {
final String streamName =
(mStreamType <= AudioSystem.getNumStreamTypes() && mStreamType >= 0)
? AudioSystem.STREAM_NAMES[mStreamType]
: ("stream " + mStreamType);
return new StringBuilder("Error trying to unmute ")
.append(streamName)
.append(" despite muted streams 0x")
.append(Integer.toHexString(mRingerZenMutedStreams))
.toString();
}
}
static final class RingerZenMutedStreamsEvent extends EventLogger.Event {
final int mRingerZenMutedStreams;
final String mSource;
RingerZenMutedStreamsEvent(int ringerZenMutedStreams, String source) {
mRingerZenMutedStreams = ringerZenMutedStreams;
mSource = source;
}
@Override
public String eventToString() {
return new StringBuilder("RingerZenMutedStreams 0x")
.append(Integer.toHexString(mRingerZenMutedStreams))
.append(" from ").append(mSource)
.toString();
}
}
}