4.2/4.3 MediaPlayer.setNextMediaPlayer(..) BUG

ssuukk — Thu, 06 Feb 2014 18:23:04 GMT

Hello Sony,

It seems there's a bug in MediaPlayer.setNextMediaPlayer(..) that causes DSP engine (audio effects like Equalizer, Virtualizer and BassBoost) to become unusable randomly on start of playback of next track. This function is used for gapeless playback and it is very obvious when the effects go down, the sound changes drastically and it is not possible to apply effects to audio session anymore. Interestingly this bug occurs more often with screen off, but it is not 100% reproducable. Below are:

1) logcat of DSP going down on track switch

2) a logcat o trying to apply DSP after 1) happens (aaah, post too long, so the logcat is available if you require)

02-06 16:43:24.211: D/AudioTrack(6933): latency() mLatency = 265, newLatency = 297
02-06 16:43:24.631: D/XenoAmp(25755): Coś pod adresem:192.168.1.101
02-06 16:43:24.671: D/XenoAmp(25755): Brak NetBIOS pod adresem:192.168.1.101
02-06 16:43:24.681: D/AudioTrack(6933): latency() mLatency = 265, newLatency = 297
02-06 16:43:24.741: D/XenoAmp(25755): Coś pod adresem:192.168.1.102
02-06 16:43:24.741: D/XenoAmp(25755): Brak NetBIOS pod adresem:192.168.1.102
02-06 16:43:25.321: D/AudioTrack(6933): latency() mLatency = 265, newLatency = 297
02-06 16:43:25.351: D/XenoAmp(25755): Coś pod adresem:192.168.1.104
02-06 16:43:25.371: D/XenoAmp(25755): I jest to samba192.168.1.104
02-06 16:43:25.371: D/XenoAmp(25755): Playlist not in cache:/storage/emulated/0/xenoamp/__NET__.m3u8
02-06 16:43:25.381: D/XenoAmp(25755): Sciezka:::::::/storage/emulated/0/xenoamp/__NET__.m3u8
02-06 16:43:25.421: D/AudioTrack(6933): latency() mLatency = 265, newLatency = 297
02-06 16:43:25.471: D/XenoAmp(25755): Kontent gotowy, wywołuję runnable =============================
02-06 16:43:25.471: D/XenoAmp(25755): po notyfikacji końca
02-06 16:43:25.471: D/XenoAmp(25755): Playlist from cache:/storage/emulated/0/xenoamp/__NET__.m3u8
02-06 16:43:25.471: D/XenoAmp(25755): Playlist from cache:/storage/emulated/0/xenoamp/__NET__.m3u8
02-06 16:43:25.491: D/XenoAmp(25755): Mamy hosta:WORKGROUP\USER-HIXBQ8OQB1
02-06 16:43:25.511: D/AudioTrack(6933): latency() mLatency = 265, newLatency = 297
02-06 16:43:25.551: D/XenoAmp(25755): Coś pod adresem:192.168.1.105
02-06 16:43:25.561: D/XenoAmp(25755): Brak NetBIOS pod adresem:192.168.1.105
02-06 16:43:25.561: D/XenoAmp(25755): Coś pod adresem:192.168.1.106
02-06 16:43:25.571: D/XenoAmp(25755): Brak NetBIOS pod adresem:192.168.1.106
02-06 16:43:25.611: D/AudioTrack(6933): latency() mLatency = 265, newLatency = 297
02-06 16:43:26.461: D/XenoAmp(25755): Coś pod adresem:192.168.1.108
02-06 16:43:26.481: D/XenoAmp(25755): Brak NetBIOS pod adresem:192.168.1.108
02-06 16:43:28.381: D/AudioTrack(6933): latency() mLatency = 265, newLatency = 297
02-06 16:43:28.471: W/AwesomePlayer(6933): Trying to create tunnel player mIsTunnelAudio 0, LPAPlayer::mObjectsAlive 0, TunnelPlayer::mTunnelObjectsAlive = 0, (mAudioPlayer == NULL) 1
02-06 16:43:28.481: W/AudioFlinger(6933): session id 632 not found for pid 6933
02-06 16:43:28.481: D/AudioPolicyManagerALSA(6933): getOutput() No sound is output on PrimaryOutput
02-06 16:43:28.481: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:28.481: D/AudioPolicyManagerALSA(6933): isStreamActive: 0
02-06 16:43:28.491: D/AudioHardwareALSAExt(6933): setParameters()
02-06 16:43:28.491: D/AudioEffectALSA(6933): setParameters: routing=8
02-06 16:43:28.491: D/AudioEffectALSA(6933): setParameters: ret = 0
02-06 16:43:28.491: D/ALSAStreamOps(6933): setParameters(): keyRouting with device 0x8
02-06 16:43:28.491: D/AudioHardwareALSA(6933): device = 0x8,mCurDevice 0x8
02-06 16:43:28.491: D/AudioHardwareALSA(6933): bool android_audio_legacy::AudioHardwareALSA::routeCall(int, int, uint32_t): CurCallState=1 newCallState=1, vsid =10c01000
02-06 16:43:28.491: D/ALSADevice(6933): mInChannels:1
02-06 16:43:28.491: D/ALSADevice(6933): route: devices 0x8 in mode 0
02-06 16:43:28.491: D/ALSADevice(6933): setEndpDevice: device 8
02-06 16:43:28.491: D/ALSADevice(6933): setMixerControl:: name DS1 DAP Endpoint count 1
02-06 16:43:28.501: D/ALSADevice(6933): DMID value: 0
02-06 16:43:28.501: D/ALSADevice(6933): setMixerControl:: name DS1 Security count 1
02-06 16:43:28.501: D/ALSADevice(6933): switchDevice: device 0x8 mode:0
02-06 16:43:28.501: V/ALSADeviceExt(6933): nonCallOutputRouting: 8
02-06 16:43:28.501: V/ALSADeviceExt(6933): Routing to rx=Headphones
02-06 16:43:28.501: V/ALSADeviceExt(6933): nonCallInputRouting: 0
02-06 16:43:28.501: V/ALSADeviceExt(6933): Routing to tx=none
02-06 16:43:28.501: D/alsa_ucm(6933): snd_use_case_set(): uc_mgr 0xb859b300 identifier _enadev value Headphones
02-06 16:43:28.501: D/alsa_ucm(6933): Set mixer controls for HiFi enable 1
02-06 16:43:28.501: D/alsa_ucm(6933): Setting mixer control: SLIMBUS_0_RX Audio Mixer MultiMedia1, value: 1
02-06 16:43:28.501: V/ALSADeviceExt(6933): sendEffectParam: call
02-06 16:43:28.501: D/AudioEffectALSA(6933): getEffectParam: update flag = 0x0000,
02-06 16:43:28.501: D/AudioEffectALSA(6933): getEffectParam: count = 0
02-06 16:43:28.501: V/ALSADeviceExt(6933): sendEffectParam: list free
02-06 16:43:28.501: D/ALSADevice(6933): switchDevice: mCurTxUCMDevice Speaker Tx mCurRxDevDevice Headphones
02-06 16:43:28.501: D/ALSADevice(6933): rx_ACDB_id=10, tx_ACDB_id=11
02-06 16:43:28.521: I/AudioPolicyManagerALSA(6933): setOutputDevice: Update device output(0), mDevice=8, device=8
02-06 16:43:28.521: I/AudioPolicyManagerALSA(6933): setOutputDevice: Update device output(1), mDevice=8, device=8
02-06 16:43:28.521: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:28.551: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:28.561: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:28.561: W/MediaPlayer(25755): info/warning (2, 0)
02-06 16:43:28.571: I/MediaPlayer(25755): Info (2,0)
02-06 16:43:28.581: D/XenoAmp(25755): On completion switches wrappers
02-06 16:43:28.581: D/XenoAmp(25755): TDS Updatuje w bazie!Section V
02-06 16:43:28.591: D/Event(25755): No subscribers registered for event class pl.qus.xenoamp.event.PlaylistChangeSaveEvent
02-06 16:43:28.591: D/Event(25755): No subscribers registered for event class de.greenrobot.event.NoSubscriberEvent
02-06 16:43:28.591: D/XenoAmp(25755): []kolejny 7/14:[tune] /storage/removable/sdcard1/My documents/My Music/Music for 18 FLAC/08 Section VI.flac
02-06 16:43:28.601: D/XenoAmp(25755): Playable. ###################################################[tune] /storage/removable/sdcard1/My documents/My Music/Music for 18 FLAC/08 Section VI.flac
02-06 16:43:28.611: D/XenoAmp(25755): []kolejny 8/14:[tune] /storage/removable/sdcard1/My documents/My Music/Music for 18 FLAC/09 Section VII.flac
02-06 16:43:28.611: D/XenoAmp(25755): Playable. ###################################################[tune] /storage/removable/sdcard1/My documents/My Music/Music for 18 FLAC/09 Section VII.flac
02-06 16:43:28.631: D/XenoAmp(25755): =========== początek updatu notyfikacji:Section VI, 0
02-06 16:43:28.631: I/AudioService(1098): AudioFocus requestAudioFocus() from android.media.AudioManager@424b6238pl.qus.xenoamp.xenoservice.XenoAmpService$1@41f133a8
02-06 16:43:28.641: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:28.641: I/AudioService(1098): Remote Control registerMediaButtonIntent() for PendingIntent{43757c38: PendingIntentRecord{4378a420 pl.qus.xenoamp broadcastIntent}}
02-06 16:43:28.721: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:28.771: D/XenoAmp(25755): =========== koniec updatu notyfikacji
02-06 16:43:28.771: D/XenoAmp(25755): Preparing next wrapper
02-06 16:43:28.781: D/XenoAmp(25755): prepareMediaPlayer:class pl.qus.xenoamp.structures.PlayableLocal:::::/storage/removable/sdcard1/My documents/My Music/Music for 18 FLAC/09 Section VII.flac
02-06 16:43:28.781: D/XenoAmp(25755): Przed new MediaPlayer
02-06 16:43:28.801: D/AwesomePlayer(6933): Before reset_l
02-06 16:43:28.801: D/AwesomePlayer(6933): printFileName fd(33) -> /storage/removable/sdcard1/My documents/My Music/Music for 18 FLAC/09 Section VII.flac
02-06 16:43:28.811: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:28.911: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:28.981: D/QCUtils(6933): extended extractor not needed, return default
02-06 16:43:28.981: D/AwesomePlayer(6933): Tunnel Mime Type: audio/raw, object alive = 0, mTunnelAliveAP = 0
02-06 16:43:28.981: D/AwesomePlayer(6933): maxPossible tunnels = 4
02-06 16:43:28.991: D/AwesomePlayer(6933): Normal Audio Playback
02-06 16:43:28.991: D/AwesomePlayer(6933): Set Audio Track as Audio Source
02-06 16:43:28.991: D/XenoAmp(25755): mediaplayer gotowy
02-06 16:43:28.991: D/XenoAmp(25755): Viper Audio not present
02-06 16:43:29.001: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:29.011: D/XenoAmp(25755): apply: xenoVolume:59, log:1.0
02-06 16:43:29.011: D/XenoAmp(25755): Chaining next to current
02-06 16:43:29.091: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:29.101: V/SLSPlayStatusReceiver(5531): Action received was: com.adam.aslfms.notify.playstatechanged
02-06 16:43:29.171: D/ScrobblingService(5531): State: COMPLETE
02-06 16:43:29.171: D/ScrobblingService(5531): Won't queue track, not played long enough: 28217 vs 176890
02-06 16:43:29.181: D/ScrobblingService(5531): Track [mAlbum=Music For 18 Musicians, mArtist=Steve Reich, mDuration=361, mMbId=, mMusicAPI=MusicAPI [clashWithScrobbleDroid=0, enabled=1, id=1, msg=null, name=XenoAmp, pkg=pl.qus.xenoamp], mQueued=false, mRating=, mRowId=-1, mSource=P, mTimePlayed=28217, mTrack=Section V, mTracknr=7, mUnknownDuration=false, mWhen=1391701380, mWhenToCountTimeFrom=13251896]
02-06 16:43:29.191: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:29.211: V/SLSPlayStatusReceiver(5531): Action received was: com.adam.aslfms.notify.playstatechanged
02-06 16:43:29.241: D/ScrobblingService(5531): State: START
02-06 16:43:29.271: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:29.281: D/NPNotifier(5531): Notifying now playing: Last.fm
02-06 16:43:29.281: D/NPNotifier(5531): Last.fm: Track [mAlbum=Music For 18 Musicians, mArtist=Steve Reich, mDuration=287, mMbId=, mMusicAPI=MusicAPI [clashWithScrobbleDroid=0, enabled=1, id=1, msg=null, name=XenoAmp, pkg=pl.qus.xenoamp], mQueued=false, mRating=, mRowId=-1, mSource=P, mTimePlayed=0, mTrack=Section VI, mTracknr=8, mUnknownDuration=false, mWhen=1391701409, mWhenToCountTimeFrom=13251973]
02-06 16:43:29.311: D/NPNotifier(5531): Notifying now playing: Libre.fm
02-06 16:43:29.311: D/NPNotifier(5531): Libre.fm: Track [mAlbum=Music For 18 Musicians, mArtist=Steve Reich, mDuration=287, mMbId=, mMusicAPI=MusicAPI [clashWithScrobbleDroid=0, enabled=1, id=1, msg=null, name=XenoAmp, pkg=pl.qus.xenoamp], mQueued=false, mRating=, mRowId=-1, mSource=P, mTimePlayed=0, mTrack=Section VI, mTracknr=8, mUnknownDuration=false, mWhen=1391701409, mWhenToCountTimeFrom=13251973]
02-06 16:43:29.361: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:29.381: E/BitmapFactory(1613): Unable to decode stream: java.io.FileNotFoundException: /: open failed: EISDIR (Is a directory)
02-06 16:43:29.391: I/System.out(1613): resolveUri failed on bad bitmap uri:
02-06 16:43:29.471: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:29.491: I/NPNotifier(5531): Nowplaying success: Last.fm
02-06 16:43:29.551: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:29.571: I/NPNotifier(5531): Nowplaying success: Libre.fm
02-06 16:43:29.641: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340
02-06 16:43:29.661: D/dalvikvm(5531): GC_CONCURRENT freed 419K, 73% free 4426K/16384K, paused 3ms+2ms, total 54ms
02-06 16:43:29.741: D/AudioTrack(6933): latency() mLatency = 340, newLatency = 340

Re: 4.2/4.3 MediaPlayer.setNextMediaPlayer(..) BUG

Bobeobi — Thu, 06 Feb 2014 22:01:53 GMT

Dude, I hope Sony devs will hear you, 'cause they say they need 2 months to fix Sound enchantments I new firmware.

topic 4.2/4.3 MediaPlayer.setNextMediaPlayer(..) BUG in XPERIA archive

4.2/4.3 MediaPlayer.setNextMediaPlayer(..) BUG

Re: 4.2/4.3 MediaPlayer.setNextMediaPlayer(..) BUG