[Galaxy S II Original Android Development] StevenHarperUK:
Yes I am trying to find out where the problem is.

I/AudioService( 1995): AudioFocus abandonAudioFocus() from android.media.AudioManager@416a3478
V/MediaPlaybackService( 3625): AudioFocus: received AUDIOFOCUS_GAIN

AudioService.java gets the Call from AudioManager.java

/** @see AudioManager#abandonAudioFocus(IAudioFocusDispatcher) */
public int abandonAudioFocus(IAudioFocusDispatcher fl, String clientId) {
Log.i(TAG, " AudioFocus abandonAudioFocus() from " + clientId);
try {
// this will take care of notifying the new focus owner if needed
synchronized(mAudioFocusLock) {
[B]removeFocusStackEntry(clientId, true);[/B]
}
} catch (java.util.ConcurrentModificationException cme) {
// Catching this exception here is temporary. It is here just to prevent
// a crash seen when the "Silent" notification is played. This is believed to be fixed
// but this try catch block is left just to be safe.
Log.e(TAG, "FATAL EXCEPTION AudioFocus abandonAudioFocus() caused " + cme);
cme.printStackTrace();
}

return AudioManager.AUDIOFOCUS_REQUEST_GRANTED;
}

This code then does the removeFocusStackEntry(clientId, true);

This has the TRUE setting - so it will notify listening next item down the stack

(it does a .pop() first)

/**
* Helper function:
* Called synchronized on mAudioFocusLock
* Remove a focus listener from the focus stack.
* @param focusListenerToRemove the focus listener
* @param signal if true and the listener was at the top of the focus stack, i.e. it was holding
* focus, notify the next item in the stack it gained focus.
*/
private void removeFocusStackEntry(String clientToRemove, boolean [B]signal[/B]) {
// is the current top of the focus stack abandoning focus? (because of request, not death)
if (!mFocusStack.empty() && mFocusStack.peek().mClientId.equals(clientToRemove))
{
//Log.i(TAG, " removeFocusStackEntry() removing top of stack");
FocusStackEntry fse = mFocusStack.pop();
fse.unlinkToDeath();
if ([B]signal[/B]) {
// notify the new top of the stack it gained focus
[B] notifyTopOfAudioFocusStack();[/B]
// there's a new top of the stack, let the remote control know
synchronized(mRCStack) {
[B] checkUpdateRemoteControlDisplay_syncAfRcs(RC_INFO_ALL);[/B]
}
}
} else {
// focus is abandoned by a client that's not at the top of the stack,
// no need to update focus.
Iterator<FocusStackEntry> stackIterator = mFocusStack.iterator();
while(stackIterator.hasNext()) {
FocusStackEntry fse = (FocusStackEntry)stackIterator.next();
if(fse.mClientId.equals(clientToRemove)) {
Log.i(TAG, " AudioFocus abandonAudioFocus(): removing entry for "
+ fse.mClientId);
stackIterator.remove();
fse.unlinkToDeath();
}
}
}
}

So here we are:

Either there are 2 on the stack (unlikely)

Or the call to checkUpdateRemoteControlDisplay_syncAfRcs(RC_INFO_ALL); is where to look.

Right now testing on a stock ROM to get a logcat (from my 2nd device)

---------- Post added at 08:24 PM ---------- Previous post was at 08:18 PM ----------

Looking at this now : Stacktrace from a Stock ROM

http://pastebin.com/9xDL5X2s

---------- Post added at 08:33 PM ---------- Previous post was at 08:24 PM ----------

Interesting. (all this is on the STOCK logcat)

When the abandonAudioFocus() is called (on STOCK)

The Player get the AudioFocus: received AUDIOFOCUS_GAIN event.

When this happens the AudioManager then re-Asks for the focus again AudioFocus requestAudioFocus()

This is not like CM9 where the CM9 Player does not re-ask for Focus - it just gets it as it is the next one down the stack (well it doesn't - but maybe the bug is with the code that is called by AudioService after this - checkUpdateRemoteControlDisplay_syncAfRcs(RC_INFO_ALL);)

I/AudioService( 2714): AudioFocus [B]abandonAudioFocus()[/B] from android.media.AudioManager@408c0360
E/SensorManager( 2714): unregisterListener:: all sensors, listener = android.hardware.motion.MotionRecognitionService$3@40929900
I/NotificationService( 2714): unregister
V/CorePlayerService(16095): [B]AudioFocus: received AUDIOFOCUS_GAIN[/B]
D/MotionRecognitionService( 2714): .unregisterCallback : 0, client=com.android.server.NotificationPlayer$1@40799790
D/CorePlayerService(16095): mMediaplayerHandler:4
I/StagefrightPlayer( 2593): isUlpAudio
D/CorePlayerService(16095): play()
I/AudioService( 2714): [B]AudioFocus requestAudioFocus() from android.media.AudioManager[/B]@40580f90com.android.music.player.service.CorePlayerService$7@4057fda0
I/AudioService( 2714): Remote Control registerMediaButtonEventReceiver() for ComponentInfo{com.android.music/com.android.music.player.receiver.BluetoothIntentReceiver}
D/CorePlayerService(16095): pauseAnotherPlay() is called

---------- Post added at 08:54 PM ---------- Previous post was at 08:33 PM ----------

Looking more at this I think the checkUpdateRemoteControlDisplay_syncAfRcs(RC_INFO_ ALL);

is not the problem.

It must be when the notifyTopOfAudioFocusStack() message gets picked up - looking into that now.

---------- Post added at 09:02 PM ---------- Previous post was at 08:54 PM ----------

It this it?

In Audio Service - when the Volume gets set back - the audio gets set to one volume. setStreamVolumeInt(STREAM_VOLUME_ALIAS[streamType], index, false, true);

Then updated to another

sendVolumeUpdate(streamType, oldIndex, index, flags);

Investigating.....

index = rescaleIndex(index * 10, streamType, STREAM_VOLUME_ALIAS[streamType]);
[B]setStreamVolumeInt(STREAM_VOLUME_ALIAS[streamType], index, false, true);[/B]

index = (streamState.muteCount() != 0) ? streamState.mLastAudibleIndex : streamState.mIndex;

[B] sendVolumeUpdate(streamType, oldIndex, index, flags);[/B]

---------- Post added at 09:06 PM ---------- Previous post was at 09:02 PM ----------

Added some debug to AudioService.java - will take a bit build etc.

---------- Post added at 09:25 PM ---------- Previous post was at 09:06 PM ----------

Hmm No that's not it.

---------- Post added at 09:41 PM ---------- Previous post was at 09:25 PM ----------

Right I think it's in the Native code.

The MediaPlaybackService get the AudioFocus Message

Then AudioHardwareYamaha sets the volume twice

First correctly setHeadphoneVolume: Set Headset Analog Volume control(8)

Then wrong setHeadphoneVolume: Set Headset Analog Volume control(8)

V/[B]MediaPlaybackService( 3625): AudioFocus: received[/B] AUDIOFOCUS_GAIN
I/AudioHardwareYamaha( 1865): AudioHardware::setDevices(devices=00000004h, mask=00023FFFh)
V/yamaha::media::CManager( 1865): setDevices(devices=00000004h)
V/yamaha::media::VolumeCtrl( 1865): VolumeCtrl::createVolume()
D/yamaha::media::VolumeCtrl( 1865): Dir0 : AP Playback Music HP (0001h)
D/yamaha::media::VolumeCtrl( 1865): Dir0Att : AP Playback Music HP (0001h)
D/yamaha::media::VolumeCtrl( 1865): DacMaster : AP Playback Music HP (0001h)
D/yamaha::media::VolumeCtrl( 1865): Hp : AP Playback Music HP (F201h)
D/yamaha::media::VolumeCtrl( 1865): HpGain : AP Playback Music HP (0001h)
V/yamaha::media::VolumeCtrl( 1865): Hp = 7 (F001h)
V/yamaha::media::VolumeCtrl( 1865): VolumeCtrl::setVolume()
D/yamaha::media::VolumeCtrl( 1865): VolumeCtrl::setVolume() FM Playback: Ready
D/yamaha::media::VolumeCtrl( 1865): VolumeCtrl::setVolume() VoiceCall: Ready
E/AudioHardwareYamaha( 1865): [B]setHeadphoneVolume: Set Headset Analog Volume control(8)[/B]
V/yamaha::media::CManager( 1865): setHeadphoneVolume(volume=8)
V/yamaha::media::VolumeCtrl( 1865): VolumeCtrl::setAnalogVolume(id=1, volume=7)
V/yamaha::media::VolumeCtrl( 1865): VolumeCtrl::createVolume()
D/yamaha::media::VolumeCtrl( 1865): Dir0 : AP Playback Music HP (0001h)
D/yamaha::media::VolumeCtrl( 1865): Dir0Att : AP Playback Music HP (0001h)
D/yamaha::media::VolumeCtrl( 1865): DacMaster : AP Playback Music HP (0001h)
D/yamaha::media::VolumeCtrl( 1865): Hp : AP Playback Music HP (F201h)
D/yamaha::media::VolumeCtrl( 1865): HpGain : AP Playback Music HP (0001h)
V/yamaha::media::VolumeCtrl( 1865): Hp = 7 (F001h)
V/yamaha::media::VolumeCtrl( 1865): VolumeCtrl::setVolume()
D/yamaha::media::VolumeCtrl( 1865): VolumeCtrl::setVolume() FM Playback: Ready
D/yamaha::media::VolumeCtrl( 1865): VolumeCtrl::setVolume() VoiceCall: Ready
E/AudioHardwareYamaha( 1865):[B] setHeadphoneVolume: Set Headset Analog Volume control(1)[/B]
V/yamaha::media::CManager( 1865): setHeadphoneVolume(volume=1)
V/yamaha::media::VolumeCtrl( 1865): VolumeCtrl::setAnalogVolume(id=1, volume=5)
V/yamaha::media::VolumeCtrl( 1865): VolumeCtrl::createVolume()

---------- Post added at 09:47 PM ---------- Previous post was at 09:41 PM ----------

Hmm taking a look at the MediaPlaybackService.java

We see the volume set down low mPlayer.setVolume(mCurrentVolume);

Then the play() makes a fade-in - maybe this is it

Possibly the fade-in is failing - only getting to the first volume (1)

case AudioManager.AUDIOFOCUS_GAIN:
Log.v(LOGTAG, "AudioFocus: received AUDIOFOCUS_GAIN");
if(!isPlaying() && mPausedByTransientLossOfFocus) {
mPausedByTransientLossOfFocus = false;
mCurrentVolume = 0f;
[B]mPlayer.setVolume(mCurrentVolume);[/B]
play(); // also queues a fade-in
} else {
mMediaplayerHandler.removeMessages(FADEDOWN);
mMediaplayerHandler.sendEmptyMessage(FADEUP);
}
break;

-------------------

Right Getting near now

This Fade code looks a bit strange - it stops the fade-in at 1.0f

case FADEUP:
mCurrentVolume += .01f;
if (mCurrentVolume < 1.0f) {
mMediaplayerHandler.sendEmptyMessageDelayed(FADEUP, 10);
} else {
mCurrentVolume = 1.0f;
}
mPlayer.setVolume(mCurrentVolume);
break;

-----------------------------

This float is not it - the 1f id the fraction of the current volume that was set - so 1f is 100% of the current volume.

Commenting out the lines that adjust volume here has no effect.

Its the code that is adjusting the Headphones volume that I need to find.