Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 5daf0268 authored by Ted Wang's avatar Ted Wang
Browse files

Avrcp log enhancement 

Add below logs into bluetooth_manager AvrcpTargerService section in
Bugreport:
  *Addressed player changed history
  *Volume control history
  *Passthrough commands history
  *Playback state change history of MediaController
  *Audio Playback state change history

Bug: 144678406
Test: Manual
Change-Id: Ie40332ec093635427d788b30fc97d95164c5d771
parent ad040d9d

src/com/android/bluetooth/avrcp/AvrcpEventLogger.java

0 → 100644
+79 −0
Original line number Diff line number Diff line 
/*

 * Copyright 2019 The Android Open Source Project

 *

 * Licensed under the Apache License, Version 2.0 (the "License");

 * you may not use this file except in compliance with the License.

 * You may obtain a copy of the License at

 *

 *      http://www.apache.org/licenses/LICENSE-2.0

 *

 * Unless required by applicable law or agreed to in writing, software

 * distributed under the License is distributed on an "AS IS" BASIS,

 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.

 * See the License for the specific language governing permissions and

 * limitations under the License.

 */



package com.android.bluetooth.avrcp;



import android.util.Log;



import com.android.bluetooth.Utils;



import com.google.common.collect.EvictingQueue;





// This class is to store logs for Avrcp for given size.

public class AvrcpEventLogger {

    private final String mTitle;

    private final EvictingQueue<Event> mEvents;



    // Event class contain timestamp and log context.

    private class Event {

        private final String mTimeStamp;

        private final String mMsg;



        Event(String msg) {

            mTimeStamp = Utils.getLocalTimeString();

            mMsg = msg;

        }



        public String toString() {

            return (new StringBuilder(mTimeStamp)

                    .append(" ").append(mMsg).toString());

        }

    }



    AvrcpEventLogger(int size, String title) {

        mEvents = EvictingQueue.create(size);

        mTitle = title;

    }



    synchronized void add(String msg) {

        Event event = new Event(msg);

        mEvents.add(event);

    }



    synchronized void logv(String tag, String msg) {

        add(msg);

        Log.v(tag, msg);

    }



    synchronized void logd(String tag, String msg) {

        logd(true, tag, msg);

    }



    synchronized void logd(boolean debug, String tag, String msg) {

        add(msg);

        if (debug) {

            Log.d(tag, msg);

        }

    }



    synchronized void dump(StringBuilder sb) {

        sb.append("Avrcp ").append(mTitle).append(":\n");

        for (Event event : mEvents) {

            sb.append("  ").append(event.toString()).append("\n");

        }

    }

}

src/com/android/bluetooth/avrcp/AvrcpTargetService.java

+11 −1
Original line number Diff line number Diff line
@@ -50,7 +50,11 @@ public class AvrcpTargetService extends ProfileService { 
    private static final String AVRCP_ENABLE_PROPERTY = "persist.bluetooth.enablenewavrcp";



    private static final int AVRCP_MAX_VOL = 127;

    private static final int MEDIA_KEY_EVENT_LOGGER_SIZE = 20;

    private static final String MEDIA_KEY_EVENT_LOGGER_TITLE = "Media Key Events";

    private static int sDeviceMaxVolume = 0;

    private final AvrcpEventLogger mMediaKeyEventLogger = new AvrcpEventLogger(

            MEDIA_KEY_EVENT_LOGGER_SIZE, MEDIA_KEY_EVENT_LOGGER_TITLE);



    private MediaPlayerList mMediaPlayerList;

    private AudioManager mAudioManager;
@@ -365,7 +369,11 @@ public class AvrcpTargetService extends ProfileService { 
    // TODO (apanicke): Handle key events here in the service. Currently it was more convenient to

    // handle them there but logically they make more sense handled here.

    void sendMediaKeyEvent(int event, boolean pushed) {

        if (DEBUG) Log.d(TAG, "getMediaKeyEvent: event=" + event + " pushed=" + pushed);

        BluetoothDevice activeDevice = getA2dpActiveDevice();

        MediaPlayerWrapper player = mMediaPlayerList.getActivePlayer();

        mMediaKeyEventLogger.logd(DEBUG, TAG, "getMediaKeyEvent:" + " device=" + activeDevice

                + " event=" + event + " pushed=" + pushed

                + " to " + (player == null ? null : player.getPackageName()));

        mMediaPlayerList.sendMediaKeyEvent(event, pushed);

    }
@@ -394,6 +402,8 @@ public class AvrcpTargetService extends ProfileService { 
            tempBuilder.append("\nMedia Player List is empty\n");

        }



        mMediaKeyEventLogger.dump(tempBuilder);

        tempBuilder.append("\n");

        mVolumeManager.dump(tempBuilder);



        // Tab everything over by two spaces

src/com/android/bluetooth/avrcp/AvrcpVolumeManager.java

+26 −14
Original line number Diff line number Diff line
@@ -38,10 +38,14 @@ class AvrcpVolumeManager extends AudioDeviceCallback { 
    // All volumes are stored at system volume values, not AVRCP values

    private static final String VOLUME_MAP = "bluetooth_volume_map";

    private static final String VOLUME_BLACKLIST = "absolute_volume_blacklist";

    private static final String VOLUME_CHANGE_LOG_TITLE = "Volume Events";

    private static final int AVRCP_MAX_VOL = 127;

    private static final int STREAM_MUSIC = AudioManager.STREAM_MUSIC;

    private static final int VOLUME_CHANGE_LOGGER_SIZE = 30;

    private static int sDeviceMaxVolume = 0;

    private static int sNewDeviceVolume = 0;

    private final AvrcpEventLogger mVolumeEventLogger = new AvrcpEventLogger(

            VOLUME_CHANGE_LOGGER_SIZE, VOLUME_CHANGE_LOG_TITLE);



    Context mContext;

    AudioManager mAudioManager;
@@ -80,7 +84,8 @@ class AvrcpVolumeManager extends AudioDeviceCallback { 
        // If absolute volume for the device is supported, set the volume for the device

        if (mDeviceMap.get(device)) {

            int avrcpVolume = systemToAvrcpVolume(savedVolume);

            Log.i(TAG, "switchVolumeDevice: Updating device volume: avrcpVolume=" + avrcpVolume);

            mVolumeEventLogger.logd(TAG,

                    "switchVolumeDevice: Updating device volume: avrcpVolume=" + avrcpVolume);

            mNativeInterface.sendVolumeChanged(device.getAddress(), avrcpVolume);

        }

    }
@@ -120,8 +125,8 @@ class AvrcpVolumeManager extends AudioDeviceCallback { 
            return;

        }

        SharedPreferences.Editor pref = getVolumeMap().edit();

        Log.i(TAG, "storeVolume: Storing stream volume level for device " + device

                + " : " + storeVolume);

        mVolumeEventLogger.logd(TAG, "storeVolume: Storing stream volume level for device "

                        + device + " : " + storeVolume);

        mVolumeMap.put(device, storeVolume);

        pref.putInt(device.getAddress(), storeVolume);

        // Always use apply() since it is asynchronous, otherwise the call can hang waiting for
@@ -139,7 +144,8 @@ class AvrcpVolumeManager extends AudioDeviceCallback { 
            return;

        }

        SharedPreferences.Editor pref = getVolumeMap().edit();

        Log.i(TAG, "RemoveStoredVolume: Remove stored stream volume level for device " + device);

        mVolumeEventLogger.logd(TAG,

                    "RemoveStoredVolume: Remove stored stream volume level for device " + device);

        mVolumeMap.remove(device);

        pref.remove(device.getAddress());

        // Always use apply() since it is asynchronous, otherwise the call can hang waiting for
@@ -164,11 +170,11 @@ class AvrcpVolumeManager extends AudioDeviceCallback { 
    void setVolume(@NonNull BluetoothDevice device, int avrcpVolume) {

        int deviceVolume =

                (int) Math.floor((double) avrcpVolume * sDeviceMaxVolume / AVRCP_MAX_VOL);

        if (DEBUG) {

            Log.d(TAG, "setVolume: avrcpVolume=" + avrcpVolume

        mVolumeEventLogger.logd(DEBUG, TAG, "setVolume:"

                        + " device=" + device

                        + " avrcpVolume=" + avrcpVolume

                        + " deviceVolume=" + deviceVolume

                        + " sDeviceMaxVolume=" + sDeviceMaxVolume);

        }

        mAudioManager.setStreamVolume(AudioManager.STREAM_MUSIC, deviceVolume,

                AudioManager.FLAG_SHOW_UI | AudioManager.FLAG_BLUETOOTH_ABS_VOLUME);

        storeVolumeForDevice(device);
@@ -178,11 +184,11 @@ class AvrcpVolumeManager extends AudioDeviceCallback { 
        int avrcpVolume =

                (int) Math.floor((double) deviceVolume * AVRCP_MAX_VOL / sDeviceMaxVolume);

        if (avrcpVolume > 127) avrcpVolume = 127;

        if (DEBUG) {

            Log.d(TAG, "sendVolumeChanged: avrcpVolume=" + avrcpVolume

        mVolumeEventLogger.logd(DEBUG, TAG, "sendVolumeChanged:"

                        + " device=" + device

                        + " avrcpVolume=" + avrcpVolume

                        + " deviceVolume=" + deviceVolume

                        + " sDeviceMaxVolume=" + sDeviceMaxVolume);

        }

        mNativeInterface.sendVolumeChanged(device.getAddress(), avrcpVolume);

        storeVolumeForDevice(device);

    }
@@ -290,6 +296,12 @@ class AvrcpVolumeManager extends AudioDeviceCallback { 
                        d.getAddress(), deviceName, (Integer) value, absoluteVolume));

            }

        }



        StringBuilder tempBuilder = new StringBuilder();

        mVolumeEventLogger.dump(tempBuilder);

        // Tab volume event logs over by two spaces

        sb.append(tempBuilder.toString().replaceAll("(?m)^", "  "));

        tempBuilder.append("\n");

    }



    static void d(String msg) {

src/com/android/bluetooth/avrcp/MediaPlayerList.java

+26 −12
Original line number Diff line number Diff line
@@ -69,6 +69,10 @@ public class MediaPlayerList { 
    private static final int NO_ACTIVE_PLAYER = 0;

    private static final int BLUETOOTH_PLAYER_ID = 0;

    private static final String BLUETOOTH_PLAYER_NAME = "Bluetooth Player";

    private static final int ACTIVE_PLAYER_LOGGER_SIZE = 5;

    private static final String ACTIVE_PLAYER_LOGGER_TITLE = "Active Player Events";

    private static final int AUDIO_PLAYBACK_STATE_LOGGER_SIZE = 15;

    private static final String AUDIO_PLAYBACK_STATE_LOGGER_TITLE = "Audio Playback State Events";



    // mediaId's for the now playing list will be in the form of "NowPlayingId[XX]" where [XX]

    // is the Queue ID for the requested item.
@@ -85,6 +89,10 @@ public class MediaPlayerList { 
    private MediaSessionManager mMediaSessionManager;

    private MediaData mCurrMediaData = null;

    private final AudioManager mAudioManager;

    private final AvrcpEventLogger mActivePlayerLogger = new AvrcpEventLogger(

            ACTIVE_PLAYER_LOGGER_SIZE, ACTIVE_PLAYER_LOGGER_TITLE);

    private final AvrcpEventLogger mAudioPlaybackStateLogger = new AvrcpEventLogger(

            AUDIO_PLAYBACK_STATE_LOGGER_SIZE, AUDIO_PLAYBACK_STATE_LOGGER_TITLE);



    private Map<Integer, MediaPlayerWrapper> mMediaPlayers =

            Collections.synchronizedMap(new HashMap<Integer, MediaPlayerWrapper>());
@@ -240,8 +248,6 @@ public class MediaPlayerList { 
        return mMediaPlayers.get(mActivePlayerId);

    }







    // In this case the displayed player is the Bluetooth Player, the number of items is equal

    // to the number of players. The root ID will always be empty string in this case as well.

    void getPlayerRoot(int playerId, GetPlayerRootCallback cb) {
@@ -527,7 +533,8 @@ public class MediaPlayerList { 


        mActivePlayerId = playerId;

        getActivePlayer().registerCallback(mMediaPlayerCallback);

        Log.i(TAG, "setActivePlayer(): setting player to " + getActivePlayer().getPackageName());

        mActivePlayerLogger.logd(TAG, "setActivePlayer(): setting player to "

                + getActivePlayer().getPackageName());



        // Ensure that metadata is synced on the new player

        if (!getActivePlayer().isMetadataSynced()) {
@@ -674,7 +681,8 @@ public class MediaPlayerList { 
                        1.0f);

            currMediaData.state = builder.build();

        }

        Log.i(TAG, "updateMediaForAudioPlayback: update state=" + currMediaData.state);

        mAudioPlaybackStateLogger.logd(TAG, "updateMediaForAudioPlayback: update state="

                + currMediaData.state);

        sendMediaUpdate(currMediaData);

    }
@@ -692,21 +700,24 @@ public class MediaPlayerList { 
                return;

            }

            boolean isActive = false;

            Log.v(TAG, "onPlaybackConfigChanged(): Configs list size=" + configs.size());

            AudioPlaybackConfiguration activeConfig = null;

            for (AudioPlaybackConfiguration config : configs) {

                if (config.isActive() && (config.getAudioAttributes().getUsage()

                            == AudioAttributes.USAGE_ASSISTANCE_NAVIGATION_GUIDANCE)

                        && (config.getAudioAttributes().getContentType()

                            == AudioAttributes.CONTENT_TYPE_SPEECH)) {

                    if (DEBUG) {

                        Log.d(TAG, "onPlaybackConfigChanged(): config=" + config);

                    }

                    activeConfig = config;

                    isActive = true;

                }

            }

            if (isActive != mAudioPlaybackIsActive) {

                Log.d(TAG, "onPlaybackConfigChanged isActive=" + isActive

                        + ", mAudioPlaybackIsActive=" + mAudioPlaybackIsActive);

                mAudioPlaybackStateLogger.logd(DEBUG, TAG, "onPlaybackConfigChanged: "

                        + (mAudioPlaybackIsActive ? "Active" : "Non-active") + " -> "

                        + (isActive ? "Active" : "Non-active"));

                if (isActive) {

                    mAudioPlaybackStateLogger.logd(DEBUG, TAG, "onPlaybackConfigChanged: "

                            + "active config: " + activeConfig);

                }

                mAudioPlaybackIsActive = isActive;

                updateMediaForAudioPlayback();

            }
@@ -803,9 +814,12 @@ public class MediaPlayerList { 
            sb.append(player.toString().replaceAll("(?m)^", "  "));

            sb.append("\n");

        }

        // TODO (apanicke): Add media key events



        mActivePlayerLogger.dump(sb);

        sb.append("\n");

        mAudioPlaybackStateLogger.dump(sb);

        sb.append("\n");

        // TODO (apanicke): Add last sent data

        // TODO (apanicke): Add addressed player history

    }



    private static void e(String message) {

src/com/android/bluetooth/avrcp/MediaPlayerWrapper.java

+9 −1
Original line number Diff line number Diff line
@@ -42,10 +42,14 @@ class MediaPlayerWrapper { 
    private static final String TAG = "AvrcpMediaPlayerWrapper";

    private static final boolean DEBUG = false;

    static boolean sTesting = false;

    private static final int PLAYBACK_STATE_CHANGE_EVENT_LOGGER_SIZE = 5;

    private static final String PLAYBACK_STATE_CHANGE_LOGGER_EVENT_TITLE =

            "Playback State change Event";



    private MediaController mMediaController;

    private String mPackageName;

    private Looper mLooper;

    private final AvrcpEventLogger mPlaybackStateChangeEventLogger;



    private MediaData mCurrentData;
@@ -81,6 +85,8 @@ class MediaPlayerWrapper { 
        mMediaController = controller;

        mPackageName = controller.getPackageName();

        mLooper = looper;

        mPlaybackStateChangeEventLogger = new AvrcpEventLogger(

                PLAYBACK_STATE_CHANGE_EVENT_LOGGER_SIZE, PLAYBACK_STATE_CHANGE_LOGGER_EVENT_TITLE);



        mCurrentData = new MediaData(null, null, null);

        mCurrentData.queue = Util.toMetadataList(getQueue());
@@ -399,7 +405,8 @@ class MediaPlayerWrapper { 
                return;

            }



            Log.v(TAG, "onPlaybackStateChanged(): " + mPackageName + " : " + state.toString());

            mPlaybackStateChangeEventLogger.logv(TAG, "onPlaybackStateChanged(): "

                    + mPackageName + " : " + state.toString());



            if (!playstateEquals(state, getPlaybackState())) {

                e("The callback playback state doesn't match the current state");
@@ -513,6 +520,7 @@ class MediaPlayerWrapper { 
        for (Metadata data : mCurrentData.queue) {

            sb.append("    " + data + "\n");

        }

        mPlaybackStateChangeEventLogger.dump(sb);

        return sb.toString();

    }

}