AudioService: add Spatial Audio logs

Bug: 227774516
Test: adb shell dumpsys audio
Change-Id: I2b01a0c6c8f7d488c5402d1bdc3f5776105ba8d2
This commit is contained in:
Jean-Michel Trivi
2022-03-28 16:07:17 -07:00
parent 9bc3b0986f
commit f82dfce816
3 changed files with 137 additions and 60 deletions

View File

@@ -16,9 +16,12 @@
package com.android.server.audio;
import android.annotation.IntDef;
import android.util.Log;
import java.io.PrintWriter;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.LinkedList;
@@ -63,6 +66,16 @@ public class AudioEventLogger {
return printLog(ALOGI, tag);
}
/** @hide */
@IntDef(flag = false, value = {
ALOGI,
ALOGE,
ALOGW,
ALOGV }
)
@Retention(RetentionPolicy.SOURCE)
public @interface LogType {}
public static final int ALOGI = 0;
public static final int ALOGE = 1;
public static final int ALOGW = 2;
@@ -74,7 +87,7 @@ public class AudioEventLogger {
* @param tag
* @return
*/
public Event printLog(int type, String tag) {
public Event printLog(@LogType int type, String tag) {
switch (type) {
case ALOGI:
Log.i(tag, eventToString());
@@ -135,6 +148,27 @@ public class AudioEventLogger {
mEvents.add(evt);
}
/**
* Add a string-based event to the log, and print it to logcat as info.
* @param msg the message for the logs
* @param tag the logcat tag to use
*/
public synchronized void loglogi(String msg, String tag) {
final Event event = new StringEvent(msg);
log(event.printLog(tag));
}
/**
* Same as {@link #loglogi(String, String)} but specifying the logcat type
* @param msg the message for the logs
* @param logType the type of logcat entry
* @param tag the logcat tag to use
*/
public synchronized void loglog(String msg, @Event.LogType int logType, String tag) {
final Event event = new StringEvent(msg);
log(event.printLog(logType, tag));
}
public synchronized void dump(PrintWriter pw) {
pw.println("Audio event log: " + mTitle);
for (Event evt : mEvents) {

View File

@@ -9716,6 +9716,7 @@ public class AudioService extends IAudioService.Stub
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 int LOG_NB_EVENTS_SPATIAL = 30;
static final AudioEventLogger sLifecycleLogger = new AudioEventLogger(LOG_NB_EVENTS_LIFECYCLE,
"audio services lifecycle");
@@ -9736,6 +9737,9 @@ public class AudioService extends IAudioService.Stub
static final AudioEventLogger sVolumeLogger = new AudioEventLogger(LOG_NB_EVENTS_VOLUME,
"volume changes (logged when command received by AudioService)");
static final AudioEventLogger sSpatialLogger = new AudioEventLogger(LOG_NB_EVENTS_SPATIAL,
"spatial audio");
final private AudioEventLogger mDynPolicyLogger = new AudioEventLogger(LOG_NB_EVENTS_DYN_POLICY,
"dynamic policy events (logged when command received by AudioService)");
@@ -9877,6 +9881,7 @@ public class AudioService extends IAudioService.Stub
pw.println("mHasSpatializerEffect:" + mHasSpatializerEffect + " (effect present)");
pw.println("isSpatializerEnabled:" + isSpatializerEnabled() + " (routing dependent)");
mSpatializerHelper.dump(pw);
sSpatialLogger.dump(pw);
mAudioSystem.dump(pw);
}

View File

@@ -177,20 +177,20 @@ public class SpatializerHelper {
}
synchronized void init(boolean effectExpected) {
Log.i(TAG, "Initializing");
loglogi("init effectExpected=" + effectExpected);
if (!effectExpected) {
Log.i(TAG, "Setting state to STATE_NOT_SUPPORTED due to effect not expected");
loglogi("init(): setting state to STATE_NOT_SUPPORTED due to effect not expected");
mState = STATE_NOT_SUPPORTED;
return;
}
if (mState != STATE_UNINITIALIZED) {
throw new IllegalStateException(("init() called in state:" + mState));
throw new IllegalStateException(logloge("init() called in state " + mState));
}
// is there a spatializer?
mSpatCallback = new SpatializerCallback();
final ISpatializer spat = AudioSystem.getSpatializer(mSpatCallback);
if (spat == null) {
Log.i(TAG, "init(): No Spatializer found");
loglogi("init(): No Spatializer found");
mState = STATE_NOT_SUPPORTED;
return;
}
@@ -201,14 +201,14 @@ public class SpatializerHelper {
|| levels.length == 0
|| (levels.length == 1
&& levels[0] == Spatializer.SPATIALIZER_IMMERSIVE_LEVEL_NONE)) {
Log.e(TAG, "Spatializer is useless");
logloge("init(): found Spatializer is useless");
mState = STATE_NOT_SUPPORTED;
return;
}
for (byte level : levels) {
logd("found support for level: " + level);
loglogi("init(): found support for level: " + level);
if (level == Spatializer.SPATIALIZER_IMMERSIVE_LEVEL_MULTICHANNEL) {
logd("Setting capable level to LEVEL_MULTICHANNEL");
loglogi("init(): setting capable level to LEVEL_MULTICHANNEL");
mCapableSpatLevel = level;
break;
}
@@ -223,7 +223,7 @@ public class SpatializerHelper {
mTransauralSupported = true;
break;
default:
Log.e(TAG, "Spatializer reports unknown supported mode:" + mode);
logloge("init(): Spatializer reports unknown supported mode:" + mode);
break;
}
}
@@ -277,7 +277,7 @@ public class SpatializerHelper {
* @param featureEnabled
*/
synchronized void reset(boolean featureEnabled) {
Log.i(TAG, "Resetting");
loglogi("Resetting featureEnabled=" + featureEnabled);
releaseSpat();
mState = STATE_UNINITIALIZED;
mSpatLevel = Spatializer.SPATIALIZER_IMMERSIVE_LEVEL_NONE;
@@ -318,23 +318,24 @@ public class SpatializerHelper {
if (enabledAvailable.second) {
// available for Spatial audio, check w/ effect
able = canBeSpatializedOnDevice(DEFAULT_ATTRIBUTES, DEFAULT_FORMAT, ROUTING_DEVICES);
Log.i(TAG, "onRoutingUpdated: can spatialize media 5.1:" + able
loglogi("onRoutingUpdated: can spatialize media 5.1:" + able
+ " on device:" + ROUTING_DEVICES[0]);
setDispatchAvailableState(able);
} else {
Log.i(TAG, "onRoutingUpdated: device:" + ROUTING_DEVICES[0]
loglogi("onRoutingUpdated: device:" + ROUTING_DEVICES[0]
+ " not available for Spatial Audio");
setDispatchAvailableState(false);
}
if (able && enabledAvailable.first) {
Log.i(TAG, "Enabling Spatial Audio since enabled for media device:"
loglogi("Enabling Spatial Audio since enabled for media device:"
+ ROUTING_DEVICES[0]);
} else {
Log.i(TAG, "Disabling Spatial Audio since disabled for media device:"
loglogi("Disabling Spatial Audio since disabled for media device:"
+ ROUTING_DEVICES[0]);
}
setDispatchFeatureEnabledState(able && enabledAvailable.first);
setDispatchFeatureEnabledState(able && enabledAvailable.first,
"onRoutingUpdated");
if (mDesiredHeadTrackingMode != Spatializer.HEAD_TRACKING_MODE_UNSUPPORTED
&& mDesiredHeadTrackingMode != Spatializer.HEAD_TRACKING_MODE_DISABLED) {
@@ -347,7 +348,7 @@ public class SpatializerHelper {
private final class SpatializerCallback extends INativeSpatializerCallback.Stub {
public void onLevelChanged(byte level) {
logd("SpatializerCallback.onLevelChanged level:" + level);
loglogi("SpatializerCallback.onLevelChanged level:" + level);
synchronized (SpatializerHelper.this) {
mSpatLevel = spatializationLevelToSpatializerInt(level);
}
@@ -358,7 +359,7 @@ public class SpatializerHelper {
}
public void onOutputChanged(int output) {
logd("SpatializerCallback.onOutputChanged output:" + output);
loglogi("SpatializerCallback.onOutputChanged output:" + output);
int oldOutput;
synchronized (SpatializerHelper.this) {
oldOutput = mSpatOutput;
@@ -374,20 +375,21 @@ public class SpatializerHelper {
// spatializer head tracking callback from native
private final class SpatializerHeadTrackingCallback
extends ISpatializerHeadTrackingCallback.Stub {
public void onHeadTrackingModeChanged(byte mode) {
logd("SpatializerHeadTrackingCallback.onHeadTrackingModeChanged mode:" + mode);
public void onHeadTrackingModeChanged(byte mode) {
int oldMode, newMode;
synchronized (this) {
oldMode = mActualHeadTrackingMode;
mActualHeadTrackingMode = headTrackingModeTypeToSpatializerInt(mode);
newMode = mActualHeadTrackingMode;
}
loglogi("SpatializerHeadTrackingCallback.onHeadTrackingModeChanged mode:"
+ Spatializer.headtrackingModeToString(newMode));
if (oldMode != newMode) {
dispatchActualHeadTrackingMode(newMode);
}
}
public void onHeadToSoundStagePoseUpdated(float[] headToStage) {
public void onHeadToSoundStagePoseUpdated(float[] headToStage) {
if (headToStage == null) {
Log.e(TAG, "SpatializerHeadTrackingCallback.onHeadToStagePoseUpdated"
+ "null transform");
@@ -404,7 +406,8 @@ public class SpatializerHelper {
for (float val : headToStage) {
t.append("[").append(String.format(Locale.ENGLISH, "%.3f", val)).append("]");
}
logd("SpatializerHeadTrackingCallback.onHeadToStagePoseUpdated headToStage:" + t);
loglogi("SpatializerHeadTrackingCallback.onHeadToStagePoseUpdated headToStage:"
+ t);
}
dispatchPoseUpdate(headToStage);
}
@@ -444,11 +447,9 @@ public class SpatializerHelper {
}
synchronized void addCompatibleAudioDevice(@NonNull AudioDeviceAttributes ada) {
// TODO add log
Log.i(TAG, "addCompatibleAudioDevice: dev=" + ada);
loglogi("addCompatibleAudioDevice: dev=" + ada);
final int deviceType = ada.getType();
final boolean wireless = isWireless(deviceType);
boolean updateRouting = false;
boolean isInList = false;
for (SADeviceState deviceState : mSADevices) {
@@ -456,8 +457,6 @@ public class SpatializerHelper {
&& (wireless && ada.getAddress().equals(deviceState.mDeviceAddress))
|| !wireless) {
isInList = true;
// state change?
updateRouting = !deviceState.mEnabled;
deviceState.mEnabled = true;
break;
}
@@ -467,33 +466,24 @@ public class SpatializerHelper {
wireless ? ada.getAddress() : null);
dev.mEnabled = true;
mSADevices.add(dev);
updateRouting = true;
}
//if (updateRouting) {
onRoutingUpdated();
//}
onRoutingUpdated();
}
synchronized void removeCompatibleAudioDevice(@NonNull AudioDeviceAttributes ada) {
// TODO add log
Log.i(TAG, "removeCompatibleAudioDevice: dev=" + ada);
loglogi("removeCompatibleAudioDevice: dev=" + ada);
final int deviceType = ada.getType();
final boolean wireless = isWireless(deviceType);
boolean updateRouting = false;
for (SADeviceState deviceState : mSADevices) {
if (deviceType == deviceState.mDeviceType
&& (wireless && ada.getAddress().equals(deviceState.mDeviceAddress))
|| !wireless) {
// state change?
updateRouting = deviceState.mEnabled;
deviceState.mEnabled = false;
break;
}
}
//###if (updateRouting) {
onRoutingUpdated();
//###}
onRoutingUpdated();
}
/**
@@ -631,6 +621,7 @@ public class SpatializerHelper {
}
synchronized void setFeatureEnabled(boolean enabled) {
loglogi("setFeatureEnabled(" + enabled + ") was featureEnabled:" + mFeatureEnabled);
if (mFeatureEnabled == enabled) {
return;
}
@@ -654,7 +645,7 @@ public class SpatializerHelper {
switch (mState) {
case STATE_UNINITIALIZED:
if (enabled) {
throw(new IllegalStateException("Can't enable when uninitialized"));
throw (new IllegalStateException("Can't enable when uninitialized"));
}
return;
case STATE_NOT_SUPPORTED:
@@ -681,7 +672,7 @@ public class SpatializerHelper {
return;
}
}
setDispatchFeatureEnabledState(enabled);
setDispatchFeatureEnabledState(enabled, "setSpatializerEnabledInt");
}
synchronized int getCapableImmersiveAudioLevel() {
@@ -705,7 +696,8 @@ public class SpatializerHelper {
* Update the feature state, no-op if no change
* @param featureEnabled
*/
private synchronized void setDispatchFeatureEnabledState(boolean featureEnabled) {
private synchronized void setDispatchFeatureEnabledState(boolean featureEnabled, String source)
{
if (featureEnabled) {
switch (mState) {
case STATE_DISABLED_UNAVAILABLE:
@@ -717,9 +709,12 @@ public class SpatializerHelper {
case STATE_ENABLED_AVAILABLE:
case STATE_ENABLED_UNAVAILABLE:
// already enabled: no-op
loglogi("setDispatchFeatureEnabledState(" + featureEnabled
+ ") no dispatch: mState:"
+ spatStateString(mState) + " src:" + source);
return;
default:
throw(new IllegalStateException("Invalid mState:" + mState
throw (new IllegalStateException("Invalid mState:" + mState
+ " for enabled true"));
}
} else {
@@ -733,12 +728,17 @@ public class SpatializerHelper {
case STATE_DISABLED_AVAILABLE:
case STATE_DISABLED_UNAVAILABLE:
// already disabled: no-op
loglogi("setDispatchFeatureEnabledState(" + featureEnabled
+ ") no dispatch: mState:" + spatStateString(mState)
+ " src:" + source);
return;
default:
throw (new IllegalStateException("Invalid mState:" + mState
+ " for enabled false"));
}
}
loglogi("setDispatchFeatureEnabledState(" + featureEnabled
+ ") mState:" + spatStateString(mState));
final int nbCallbacks = mStateCallbacks.beginBroadcast();
for (int i = 0; i < nbCallbacks; i++) {
try {
@@ -755,7 +755,7 @@ public class SpatializerHelper {
switch (mState) {
case STATE_UNINITIALIZED:
case STATE_NOT_SUPPORTED:
throw(new IllegalStateException(
throw (new IllegalStateException(
"Should not update available state in state:" + mState));
case STATE_DISABLED_UNAVAILABLE:
if (available) {
@@ -763,6 +763,8 @@ public class SpatializerHelper {
break;
} else {
// already in unavailable state
loglogi("setDispatchAvailableState(" + available
+ ") no dispatch: mState:" + spatStateString(mState));
return;
}
case STATE_ENABLED_UNAVAILABLE:
@@ -771,11 +773,15 @@ public class SpatializerHelper {
break;
} else {
// already in unavailable state
loglogi("setDispatchAvailableState(" + available
+ ") no dispatch: mState:" + spatStateString(mState));
return;
}
case STATE_DISABLED_AVAILABLE:
if (available) {
// already in available state
loglogi("setDispatchAvailableState(" + available
+ ") no dispatch: mState:" + spatStateString(mState));
return;
} else {
mState = STATE_DISABLED_UNAVAILABLE;
@@ -784,12 +790,15 @@ public class SpatializerHelper {
case STATE_ENABLED_AVAILABLE:
if (available) {
// already in available state
loglogi("setDispatchAvailableState(" + available
+ ") no dispatch: mState:" + spatStateString(mState));
return;
} else {
mState = STATE_ENABLED_UNAVAILABLE;
break;
}
}
loglogi("setDispatchAvailableState(" + available + ") mState:" + spatStateString(mState));
final int nbCallbacks = mStateCallbacks.beginBroadcast();
for (int i = 0; i < nbCallbacks; i++) {
try {
@@ -814,7 +823,7 @@ public class SpatializerHelper {
mSpatHeadTrackingCallback = new SpatializerHeadTrackingCallback();
mSpat = AudioSystem.getSpatializer(mSpatCallback);
try {
mSpat.setLevel((byte) Spatializer.SPATIALIZER_IMMERSIVE_LEVEL_MULTICHANNEL);
mSpat.setLevel((byte) Spatializer.SPATIALIZER_IMMERSIVE_LEVEL_MULTICHANNEL);
mIsHeadTrackingSupported = mSpat.isHeadTrackingSupported();
//TODO: register heatracking callback only when sensors are registered
if (mIsHeadTrackingSupported) {
@@ -852,8 +861,6 @@ public class SpatializerHelper {
// virtualization capabilities
synchronized boolean canBeSpatialized(
@NonNull AudioAttributes attributes, @NonNull AudioFormat format) {
logd("canBeSpatialized usage:" + attributes.getUsage()
+ " format:" + format.toLogFriendlyString());
switch (mState) {
case STATE_UNINITIALIZED:
case STATE_NOT_SUPPORTED:
@@ -880,7 +887,8 @@ public class SpatializerHelper {
mASA.getDevicesForAttributes(
attributes, false /* forVolume */).toArray(devices);
final boolean able = canBeSpatializedOnDevice(attributes, format, devices);
logd("canBeSpatialized returning " + able);
logd("canBeSpatialized usage:" + attributes.getUsage()
+ " format:" + format.toLogFriendlyString() + " returning " + able);
return able;
}
@@ -1317,11 +1325,11 @@ public class SpatializerHelper {
final boolean init = mFeatureEnabled && (mSpatLevel != SpatializationLevel.NONE);
final String action = init ? "initializing" : "releasing";
if (mSpat == null) {
Log.e(TAG, "not " + action + " sensors, null spatializer");
logloge("not " + action + " sensors, null spatializer");
return;
}
if (!mIsHeadTrackingSupported) {
Log.e(TAG, "not " + action + " sensors, spatializer doesn't support headtracking");
logloge("not " + action + " sensors, spatializer doesn't support headtracking");
return;
}
int headHandle = -1;
@@ -1346,7 +1354,7 @@ public class SpatializerHelper {
// does this happen before routing is updated?
// avoid by supporting adding device here AND in onRoutingUpdated()
headHandle = getHeadSensorHandleUpdateTracker();
Log.i(TAG, "head tracker sensor handle initialized to " + headHandle);
loglogi("head tracker sensor handle initialized to " + headHandle);
screenHandle = getScreenSensorHandle();
Log.i(TAG, "found screen sensor handle initialized to " + screenHandle);
} else {
@@ -1389,7 +1397,7 @@ public class SpatializerHelper {
case SpatializerHeadTrackingMode.RELATIVE_SCREEN:
return Spatializer.HEAD_TRACKING_MODE_RELATIVE_DEVICE;
default:
throw(new IllegalArgumentException("Unexpected head tracking mode:" + mode));
throw (new IllegalArgumentException("Unexpected head tracking mode:" + mode));
}
}
@@ -1404,7 +1412,7 @@ public class SpatializerHelper {
case Spatializer.HEAD_TRACKING_MODE_RELATIVE_DEVICE:
return SpatializerHeadTrackingMode.RELATIVE_SCREEN;
default:
throw(new IllegalArgumentException("Unexpected head tracking mode:" + sdkMode));
throw (new IllegalArgumentException("Unexpected head tracking mode:" + sdkMode));
}
}
@@ -1417,7 +1425,7 @@ public class SpatializerHelper {
case SpatializationLevel.SPATIALIZER_MCHAN_BED_PLUS_OBJECTS:
return Spatializer.SPATIALIZER_IMMERSIVE_LEVEL_MCHAN_BED_PLUS_OBJECTS;
default:
throw(new IllegalArgumentException("Unexpected spatializer level:" + level));
throw (new IllegalArgumentException("Unexpected spatializer level:" + level));
}
}
@@ -1430,18 +1438,19 @@ public class SpatializerHelper {
+ Spatializer.headtrackingModeToString(mActualHeadTrackingMode));
pw.println("\tmDesiredHeadTrackingMode:"
+ Spatializer.headtrackingModeToString(mDesiredHeadTrackingMode));
String modesString = "";
pw.println("\tsupports binaural:" + mBinauralSupported + " / transaural:"
+ mTransauralSupported);
StringBuilder modesString = new StringBuilder();
int[] modes = getSupportedHeadTrackingModes();
for (int mode : modes) {
modesString += Spatializer.headtrackingModeToString(mode) + " ";
modesString.append(Spatializer.headtrackingModeToString(mode)).append(" ");
}
pw.println("\tsupports binaural:" + mBinauralSupported + " / transaural"
+ mTransauralSupported);
pw.println("\tsupported head tracking modes:" + modesString);
pw.println("\theadtracker available:" + mHeadTrackerAvailable);
pw.println("\tmSpatOutput:" + mSpatOutput);
pw.println("\tdevices:\n");
pw.println("\tdevices:");
for (SADeviceState device : mSADevices) {
pw.println("\t\t" + device + "\n");
pw.println("\t\t" + device);
}
}
@@ -1464,6 +1473,25 @@ public class SpatializerHelper {
}
}
private static String spatStateString(int state) {
switch (state) {
case STATE_UNINITIALIZED:
return "STATE_UNINITIALIZED";
case STATE_NOT_SUPPORTED:
return "STATE_NOT_SUPPORTED";
case STATE_DISABLED_UNAVAILABLE:
return "STATE_DISABLED_UNAVAILABLE";
case STATE_ENABLED_UNAVAILABLE:
return "STATE_ENABLED_UNAVAILABLE";
case STATE_ENABLED_AVAILABLE:
return "STATE_ENABLED_AVAILABLE";
case STATE_DISABLED_AVAILABLE:
return "STATE_DISABLED_AVAILABLE";
default:
return "invalid state";
}
}
private static boolean isWireless(int deviceType) {
for (int type : WIRELESS_TYPES) {
if (type == deviceType) {
@@ -1474,7 +1502,7 @@ public class SpatializerHelper {
}
private static boolean isWirelessSpeaker(int deviceType) {
for (int type: WIRELESS_SPEAKER_TYPES) {
for (int type : WIRELESS_SPEAKER_TYPES) {
if (type == deviceType) {
return true;
}
@@ -1516,4 +1544,14 @@ public class SpatializerHelper {
}
return screenHandle;
}
private static void loglogi(String msg) {
AudioService.sSpatialLogger.loglogi(msg, TAG);
}
private static String logloge(String msg) {
AudioService.sSpatialLogger.loglog(msg, AudioEventLogger.Event.ALOGE, TAG);
return msg;
}
}