search

smithdtyler / prettygoodmusicplayer

A music player app for Android hits the basics hard
GNU General Public License v3.0
52 stars 23 forks source link

Player stops responding to bluetooth commands after a while (LG G3) #72

Closed smithdtyler closed 9 years ago

smithdtyler commented 9 years ago

Problem is intermittent, and didn't manifest itself on Droid Maxx.

Info from Logcat while this problem was occurring (I was pressing the pause button repeatedly):

01-27 08:54:08.286: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:08.306: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:08.306: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:08.306: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:08.306: I/WindowManager(2637): interceptKeyTq keycode=127 down=false screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:08.306: I/WindowManager(2637): interceptKeyTi keyCode=127 down=false repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:08.306: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_UP, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319941044, downTime=319941013, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:08.546: E/bt-avp(5129): opcode 7c
01-27 08:54:08.546: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:08.546: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (1) 1:press, 0:release
01-27 08:54:08.546: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:08.546: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (1) 1:press, 0:release
01-27 08:54:08.546: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:08.546: D/LTECallInterface(3165): isInLTEVideoCall
01-27 08:54:08.546: D/VT_VideoCallControl(3165): getVtCallState : 0
01-27 08:54:08.546: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:08.546: I/WindowManager(2637): interceptKeyTq keycode=127 down=true screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:08.546: I/WindowManager(2637): interceptKeyTi keyCode=127 down=true repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:08.546: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_DOWN, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319941282, downTime=319941282, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:08.566: E/bt-avp(5129): opcode 7c
01-27 08:54:08.566: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:08.576: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:08.576: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:08.576: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:08.576: I/WindowManager(2637): interceptKeyTq keycode=127 down=false screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:08.576: I/WindowManager(2637): interceptKeyTi keyCode=127 down=false repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:08.576: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_UP, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319941315, downTime=319941282, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:08.586: D/LGBluetoothAvrcpAdapter(5129): Timer expired. Sending request for play state
01-27 08:54:08.586: E/LGBluetoothAvrcpManager(5129): [BTUI] command : NOTIFY response(CHANGED) : EventPlaybackPosChanged
01-27 08:54:08.586: D/LGBluetoothAvrcpManager(5129): [BTUI] calculated position is larger than duration
01-27 08:54:08.586: D/LGBluetoothAvrcpManager(5129): [BTUI] response : CHANGED : EventPlaybackPosChanged : 149490
01-27 08:54:08.586: D/BluetoothAVRCP1.3ServiceJni(5129): onSongPositionChangedNative
01-27 08:54:08.636: E/bt-avp(5129): opcode 0
01-27 08:54:08.636: I/BluetoothAVRCP1.3ServiceJni(5129): BTRC_EVT_PLAY_POS_CHANGED
01-27 08:54:08.636: D/LGBluetoothAvrcpManager(5129): [BTUI] calculated position is larger than duration
01-27 08:54:08.636: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayPosition = 149490
01-27 08:54:08.636: D/LGBluetoothAvrcpAdapter(5129): [BTUI] getPlayPosition() :149490
01-27 08:54:08.636: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayStatus = 1 (PLAYING)
01-27 08:54:08.636: D/LGBluetoothAvrcpAdapter(5129): [BTUI] getPlayStatus() :1 (PLAYING)
01-27 08:54:08.636: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayStatus = 1 (PLAYING)
01-27 08:54:08.636: D/LGBluetoothAvrcpAdapter(5129): Starting play position changed timer
01-27 08:54:08.636: D/LGBluetoothAvrcpAdapter(5129): Play position changed timer delay: 1 seconds
01-27 08:54:08.666: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:08.666: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:08.666: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:08.666: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:08.666: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:08.776: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:08.776: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:08.776: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:08.776: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:08.776: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:08.776: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:08.776: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:08.776: V/MediaPlayerService(2014): [2066] getCurrentPosition = 193910
01-27 08:54:08.936: E/bt-avp(5129): opcode 7c
01-27 08:54:08.936: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:08.936: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (1) 1:press, 0:release
01-27 08:54:08.936: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:08.936: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (1) 1:press, 0:release
01-27 08:54:08.936: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:08.936: I/WindowManager(2637): interceptKeyTq keycode=127 down=true screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:08.936: I/WindowManager(2637): interceptKeyTi keyCode=127 down=true repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:08.936: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_DOWN, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319941673, downTime=319941673, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:08.946: D/LTECallInterface(3165): isInLTEVideoCall
01-27 08:54:08.946: D/VT_VideoCallControl(3165): getVtCallState : 0
01-27 08:54:08.946: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:08.946: E/bt-avp(5129): opcode 7c
01-27 08:54:08.946: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:08.966: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:08.966: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:08.966: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:08.966: I/WindowManager(2637): interceptKeyTq keycode=127 down=false screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:08.966: I/WindowManager(2637): interceptKeyTi keyCode=127 down=false repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:08.966: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_UP, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319941705, downTime=319941673, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:09.076: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:09.086: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:09.086: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:09.086: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:09.086: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:09.126: E/bt-avp(5129): opcode 7c
01-27 08:54:09.126: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:09.126: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (1) 1:press, 0:release
01-27 08:54:09.126: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:09.126: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (1) 1:press, 0:release
01-27 08:54:09.126: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:09.126: I/WindowManager(2637): interceptKeyTq keycode=127 down=true screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:09.126: I/WindowManager(2637): interceptKeyTi keyCode=127 down=true repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:09.126: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_DOWN, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319941865, downTime=319941865, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:09.136: D/LTECallInterface(3165): isInLTEVideoCall
01-27 08:54:09.136: D/VT_VideoCallControl(3165): getVtCallState : 0
01-27 08:54:09.136: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:09.136: E/bt-avp(5129): opcode 7c
01-27 08:54:09.136: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:09.156: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:09.156: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:09.156: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:09.156: I/WindowManager(2637): interceptKeyTq keycode=127 down=false screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:09.156: I/WindowManager(2637): interceptKeyTi keyCode=127 down=false repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:09.156: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_UP, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319941896, downTime=319941865, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:09.186: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:09.186: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:09.186: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:09.186: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:09.186: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:09.266: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:09.266: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:09.276: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:09.276: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:09.276: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:09.276: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:09.276: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:09.276: V/MediaPlayerService(2014): [2066] getCurrentPosition = 194397
01-27 08:54:09.326: E/bt-avp(5129): opcode 7c
01-27 08:54:09.326: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:09.326: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (1) 1:press, 0:release
01-27 08:54:09.326: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:09.326: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (1) 1:press, 0:release
01-27 08:54:09.326: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:09.326: D/LTECallInterface(3165): isInLTEVideoCall
01-27 08:54:09.326: D/VT_VideoCallControl(3165): getVtCallState : 0
01-27 08:54:09.326: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:09.326: E/bt-avp(5129): opcode 7c
01-27 08:54:09.326: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:09.326: I/WindowManager(2637): interceptKeyTq keycode=127 down=true screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:09.326: I/WindowManager(2637): interceptKeyTi keyCode=127 down=true repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:09.326: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_DOWN, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319942061, downTime=319942061, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:09.356: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:09.356: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:09.356: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:09.356: I/WindowManager(2637): interceptKeyTq keycode=127 down=false screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:09.356: I/WindowManager(2637): interceptKeyTi keyCode=127 down=false repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:09.356: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_UP, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319942092, downTime=319942061, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:09.636: D/LGBluetoothAvrcpAdapter(5129): Timer expired. Sending request for play state
01-27 08:54:09.636: E/LGBluetoothAvrcpManager(5129): [BTUI] command : NOTIFY response(CHANGED) : EventPlaybackPosChanged
01-27 08:54:09.646: D/LGBluetoothAvrcpManager(5129): [BTUI] calculated position is larger than duration
01-27 08:54:09.646: D/LGBluetoothAvrcpManager(5129): [BTUI] response : CHANGED : EventPlaybackPosChanged : 149490
01-27 08:54:09.646: D/BluetoothAVRCP1.3ServiceJni(5129): onSongPositionChangedNative
01-27 08:54:09.686: E/bt-avp(5129): opcode 0
01-27 08:54:09.686: I/BluetoothAVRCP1.3ServiceJni(5129): BTRC_EVT_PLAY_POS_CHANGED
01-27 08:54:09.686: D/LGBluetoothAvrcpManager(5129): [BTUI] calculated position is larger than duration
01-27 08:54:09.686: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayPosition = 149490
01-27 08:54:09.686: D/LGBluetoothAvrcpAdapter(5129): [BTUI] getPlayPosition() :149490
01-27 08:54:09.686: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayStatus = 1 (PLAYING)
01-27 08:54:09.686: D/LGBluetoothAvrcpAdapter(5129): [BTUI] getPlayStatus() :1 (PLAYING)
01-27 08:54:09.686: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayStatus = 1 (PLAYING)
01-27 08:54:09.686: D/LGBluetoothAvrcpAdapter(5129): Starting play position changed timer
01-27 08:54:09.686: D/LGBluetoothAvrcpAdapter(5129): Play position changed timer delay: 1 seconds
01-27 08:54:09.686: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:09.686: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:09.686: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:09.686: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:09.696: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:09.716: E/ThermalEngine(2021): [GPU_MON] 0 percent. Current Sampling Time is 1 sec 
01-27 08:54:09.736: E/bt-avp(5129): opcode 7c
01-27 08:54:09.736: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:09.736: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (1) 1:press, 0:release
01-27 08:54:09.736: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:09.736: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (1) 1:press, 0:release
01-27 08:54:09.736: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:09.736: I/WindowManager(2637): interceptKeyTq keycode=127 down=true screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:09.736: I/WindowManager(2637): interceptKeyTi keyCode=127 down=true repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:09.746: D/LTECallInterface(3165): isInLTEVideoCall
01-27 08:54:09.746: D/VT_VideoCallControl(3165): getVtCallState : 0
01-27 08:54:09.746: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:09.746: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_DOWN, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319942475, downTime=319942475, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:09.756: E/bt-avp(5129): opcode 7c
01-27 08:54:09.756: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:09.776: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:09.776: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:09.776: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:09.776: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:09.776: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:09.776: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:09.776: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:09.776: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:09.776: I/WindowManager(2637): interceptKeyTq keycode=127 down=false screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:09.776: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:09.776: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:09.776: V/MediaPlayerService(2014): [2066] getCurrentPosition = 194955
01-27 08:54:09.776: I/WindowManager(2637): interceptKeyTi keyCode=127 down=false repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:09.776: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_UP, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319942508, downTime=319942475, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:09.996: E/bt-avp(5129): opcode 7c
01-27 08:54:09.996: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:09.996: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (1) 1:press, 0:release
01-27 08:54:09.996: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:09.996: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (1) 1:press, 0:release
01-27 08:54:09.996: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:09.996: D/LTECallInterface(3165): isInLTEVideoCall
01-27 08:54:09.996: D/VT_VideoCallControl(3165): getVtCallState : 0
01-27 08:54:09.996: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:09.996: I/WindowManager(2637): interceptKeyTq keycode=127 down=true screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:09.996: I/WindowManager(2637): interceptKeyTi keyCode=127 down=true repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:09.996: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_DOWN, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319942733, downTime=319942733, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:10.026: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:10.026: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:10.026: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:10.026: E/bt-avp(5129): opcode 7c
01-27 08:54:10.026: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:10.026: I/WindowManager(2637): interceptKeyTq keycode=127 down=false screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:10.026: I/WindowManager(2637): interceptKeyTi keyCode=127 down=false repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:10.026: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_UP, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319942764, downTime=319942733, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:10.206: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:10.206: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:10.206: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:10.206: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:10.206: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:10.276: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:10.276: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:10.276: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:10.276: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:10.276: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:10.276: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:10.276: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:10.276: V/MediaPlayerService(2014): [2066] getCurrentPosition = 195442
01-27 08:54:10.526: D/PhoneInterfaceManager(3028): [PhoneIntfMgr] sigLevel = 2
01-27 08:54:10.526: D/BubblePopupHelper(2817): isShowingBubblePopup : false
01-27 08:54:10.556: E/bt-avp(5129): opcode 7c
01-27 08:54:10.556: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:10.556: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (1) 1:press, 0:release
01-27 08:54:10.556: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:10.556: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (1) 1:press, 0:release
01-27 08:54:10.556: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:10.556: D/LTECallInterface(3165): isInLTEVideoCall
01-27 08:54:10.556: D/VT_VideoCallControl(3165): getVtCallState : 0
01-27 08:54:10.556: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:10.556: I/WindowManager(2637): interceptKeyTq keycode=127 down=true screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:10.556: I/WindowManager(2637): interceptKeyTi keyCode=127 down=true repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:10.556: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_DOWN, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319943291, downTime=319943291, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:10.586: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:10.586: D/BTIF_RC(5129): [BTUI] isPlaying [1], pressed key [201]
01-27 08:54:10.586: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send PAUSE_KEY (0) 1:press, 0:release
01-27 08:54:10.586: E/bt-avp(5129): opcode 7c
01-27 08:54:10.586: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:10.586: I/WindowManager(2637): interceptKeyTq keycode=127 down=false screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:10.586: I/WindowManager(2637): interceptKeyTi keyCode=127 down=false repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:10.586: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_UP, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=319943323, downTime=319943291, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:10.686: D/LGBluetoothAvrcpAdapter(5129): Timer expired. Sending request for play state
01-27 08:54:10.686: E/LGBluetoothAvrcpManager(5129): [BTUI] command : NOTIFY response(CHANGED) : EventPlaybackPosChanged
01-27 08:54:10.686: D/LGBluetoothAvrcpManager(5129): [BTUI] calculated position is larger than duration
01-27 08:54:10.686: D/LGBluetoothAvrcpManager(5129): [BTUI] response : CHANGED : EventPlaybackPosChanged : 149490
01-27 08:54:10.686: D/BluetoothAVRCP1.3ServiceJni(5129): onSongPositionChangedNative
01-27 08:54:10.696: E/bt-avp(5129): opcode 0
01-27 08:54:10.696: I/BluetoothAVRCP1.3ServiceJni(5129): BTRC_EVT_PLAY_POS_CHANGED
01-27 08:54:10.696: D/LGBluetoothAvrcpManager(5129): [BTUI] calculated position is larger than duration
01-27 08:54:10.706: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayPosition = 149490
01-27 08:54:10.706: D/LGBluetoothAvrcpAdapter(5129): [BTUI] getPlayPosition() :149490
01-27 08:54:10.706: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayStatus = 1 (PLAYING)
01-27 08:54:10.706: D/LGBluetoothAvrcpAdapter(5129): [BTUI] getPlayStatus() :1 (PLAYING)
01-27 08:54:10.706: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayStatus = 1 (PLAYING)
01-27 08:54:10.706: D/LGBluetoothAvrcpAdapter(5129): Starting play position changed timer
01-27 08:54:10.706: D/LGBluetoothAvrcpAdapter(5129): Play position changed timer delay: 1 seconds
01-27 08:54:10.716: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:10.716: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:10.716: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:10.716: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:10.716: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:10.776: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:10.776: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:10.776: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:10.776: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:10.776: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:10.776: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:10.776: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:10.776: V/MediaPlayerService(2014): [2066] getCurrentPosition = 195907
01-27 08:54:11.226: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:11.226: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:11.226: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:11.226: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:11.226: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:11.266: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:11.266: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:11.266: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:11.266: V/MediaPlayerService(2014): [2066] getCurrentPosition = 196487
01-27 08:54:11.286: I/MusicPlaybackService(27650): Preferences update success: true
01-27 08:54:11.286: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:11.286: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:11.286: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:11.286: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:11.286: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:11.286: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:11.286: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:11.286: V/MediaPlayerService(2014): [2066] getCurrentPosition = 196487
01-27 08:54:11.456: D/BubblePopupHelper(2817): isShowingBubblePopup : false
01-27 08:54:11.456: D/PhoneInterfaceManager(3028): [PhoneIntfMgr] sigLevel = 2
01-27 08:54:11.706: D/LGBluetoothAvrcpAdapter(5129): Timer expired. Sending request for play state
01-27 08:54:11.706: E/LGBluetoothAvrcpManager(5129): [BTUI] command : NOTIFY response(CHANGED) : EventPlaybackPosChanged
01-27 08:54:11.706: D/LGBluetoothAvrcpManager(5129): [BTUI] calculated position is larger than duration
01-27 08:54:11.706: D/LGBluetoothAvrcpManager(5129): [BTUI] response : CHANGED : EventPlaybackPosChanged : 149490
01-27 08:54:11.706: D/BluetoothAVRCP1.3ServiceJni(5129): onSongPositionChangedNative
01-27 08:54:11.736: E/bt-avp(5129): opcode 0
01-27 08:54:11.736: I/BluetoothAVRCP1.3ServiceJni(5129): BTRC_EVT_PLAY_POS_CHANGED
01-27 08:54:11.736: D/LGBluetoothAvrcpManager(5129): [BTUI] calculated position is larger than duration
01-27 08:54:11.736: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayPosition = 149490
01-27 08:54:11.736: D/LGBluetoothAvrcpAdapter(5129): [BTUI] getPlayPosition() :149490
01-27 08:54:11.736: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayStatus = 1 (PLAYING)
01-27 08:54:11.736: D/LGBluetoothAvrcpAdapter(5129): [BTUI] getPlayStatus() :1 (PLAYING)
01-27 08:54:11.736: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayStatus = 1 (PLAYING)
01-27 08:54:11.736: D/LGBluetoothAvrcpAdapter(5129): Starting play position changed timer
01-27 08:54:11.736: D/LGBluetoothAvrcpAdapter(5129): Play position changed timer delay: 1 seconds
01-27 08:54:11.736: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:11.736: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:11.736: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:11.736: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:11.746: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:11.766: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:11.766: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:11.766: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:11.766: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:11.766: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:11.766: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:11.776: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:11.776: V/MediaPlayerService(2014): [2066] getCurrentPosition = 196882
01-27 08:54:12.106: E/bt-avp(5129): opcode 7c
01-27 08:54:12.106: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:12.106: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send STOP_KEY (1) 1:press, 0:release
01-27 08:54:12.106: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send STOP_KEY (1) 1:press, 0:release
01-27 08:54:12.106: I/WindowManager(2637): interceptKeyTq keycode=86 down=true screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:12.106: I/WindowManager(2637): interceptKeyTi keyCode=86 down=true repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:12.106: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_DOWN, keyCode=KEYCODE_MEDIA_STOP, scanCode=166, metaState=0, flags=0x8, repeatCount=0, eventTime=319944842, downTime=319944842, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:12.136: E/bt-avp(5129): opcode 7c
01-27 08:54:12.136: W/bt-btif(5129): bta_dm_rm_cback:1, status:7
01-27 08:54:12.136: D/BTIF_RC(5129): [BTUI] [r] AVRCP: Send STOP_KEY (0) 1:press, 0:release
01-27 08:54:12.136: E/BTIF_RC(5129): [BTUI] [s] AVRCP: Send STOP_KEY (0) 1:press, 0:release
01-27 08:54:12.136: I/WindowManager(2637): interceptKeyTq keycode=86 down=false screenIsOn=true keyguardActive=false policyFlags=2000001 isWakeKey=true
01-27 08:54:12.146: I/WindowManager(2637): interceptKeyTi keyCode=86 down=false repeatCount=0 keyguardOn=false mHomePressed=false canceled=false
01-27 08:54:12.146: I/ViewRootImpl(3183): ViewRoot's KeyEvent { action=ACTION_UP, keyCode=KEYCODE_MEDIA_STOP, scanCode=166, metaState=0, flags=0x8, repeatCount=0, eventTime=319944878, downTime=319944842, deviceId=19, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43e07b30 V.E..... R....... 0,0-1440,2560}
01-27 08:54:12.246: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:12.246: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:12.246: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:12.246: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:12.246: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:12.266: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:12.276: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:12.276: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:12.276: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:12.276: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:12.276: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:12.276: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:12.276: V/MediaPlayerService(2014): [2066] getCurrentPosition = 197439
01-27 08:54:12.736: D/LGBluetoothAvrcpAdapter(5129): Timer expired. Sending request for play state
01-27 08:54:12.736: E/LGBluetoothAvrcpManager(5129): [BTUI] command : NOTIFY response(CHANGED) : EventPlaybackPosChanged
01-27 08:54:12.736: D/LGBluetoothAvrcpManager(5129): [BTUI] calculated position is larger than duration
01-27 08:54:12.736: D/LGBluetoothAvrcpManager(5129): [BTUI] response : CHANGED : EventPlaybackPosChanged : 149490
01-27 08:54:12.736: D/BluetoothAVRCP1.3ServiceJni(5129): onSongPositionChangedNative
01-27 08:54:12.756: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:12.756: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:12.756: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:12.756: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:12.756: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:12.766: E/bt-avp(5129): opcode 0
01-27 08:54:12.766: I/BluetoothAVRCP1.3ServiceJni(5129): BTRC_EVT_PLAY_POS_CHANGED
01-27 08:54:12.776: D/LGBluetoothAvrcpManager(5129): [BTUI] calculated position is larger than duration
01-27 08:54:12.776: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayPosition = 149490
01-27 08:54:12.776: D/LGBluetoothAvrcpAdapter(5129): [BTUI] getPlayPosition() :149490
01-27 08:54:12.776: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayStatus = 1 (PLAYING)
01-27 08:54:12.776: D/LGBluetoothAvrcpAdapter(5129): [BTUI] getPlayStatus() :1 (PLAYING)
01-27 08:54:12.776: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayStatus = 1 (PLAYING)
01-27 08:54:12.776: D/LGBluetoothAvrcpAdapter(5129): Starting play position changed timer
01-27 08:54:12.776: D/LGBluetoothAvrcpAdapter(5129): Play position changed timer delay: 1 seconds
01-27 08:54:12.776: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:12.776: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:12.776: D/PhoneInterfaceManager(3028): [PhoneIntfMgr] sigLevel = 2
01-27 08:54:12.776: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:12.786: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:12.786: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:12.786: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:12.786: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:12.786: V/MediaPlayerService(2014): [2066] getCurrentPosition = 197973
01-27 08:54:12.786: D/BubblePopupHelper(2817): isShowingBubblePopup : false
01-27 08:54:13.276: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:13.276: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:13.276: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:13.276: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:13.276: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:13.276: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:13.276: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:13.276: V/MediaPlayerService(2014): [2066] getCurrentPosition = 198484
01-27 08:54:13.286: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:13.286: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:13.286: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:13.286: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:13.286: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:13.716: E/ThermalEngine(2021): [GPU_MON] 0 percent. Current Sampling Time is 1 sec 
01-27 08:54:13.776: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:13.776: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:13.776: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:13.776: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:13.776: D/LGBluetoothAvrcpAdapter(5129): Timer expired. Sending request for play state
01-27 08:54:13.776: E/LGBluetoothAvrcpManager(5129): [BTUI] command : NOTIFY response(CHANGED) : EventPlaybackPosChanged
01-27 08:54:13.776: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:13.776: D/LGBluetoothAvrcpManager(5129): [BTUI] calculated position is larger than duration
01-27 08:54:13.776: D/LGBluetoothAvrcpManager(5129): [BTUI] response : CHANGED : EventPlaybackPosChanged : 149490
01-27 08:54:13.776: D/BluetoothAVRCP1.3ServiceJni(5129): onSongPositionChangedNative
01-27 08:54:13.776: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:13.776: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:13.776: V/MediaPlayerService(2014): [2066] getCurrentPosition = 198949
01-27 08:54:13.796: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:13.796: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:13.796: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:13.796: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:13.796: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:13.806: E/bt-avp(5129): opcode 0
01-27 08:54:13.806: I/BluetoothAVRCP1.3ServiceJni(5129): BTRC_EVT_PLAY_POS_CHANGED
01-27 08:54:13.806: D/LGBluetoothAvrcpManager(5129): [BTUI] calculated position is larger than duration
01-27 08:54:13.806: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayPosition = 149490
01-27 08:54:13.806: D/LGBluetoothAvrcpAdapter(5129): [BTUI] getPlayPosition() :149490
01-27 08:54:13.806: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayStatus = 1 (PLAYING)
01-27 08:54:13.806: D/LGBluetoothAvrcpAdapter(5129): [BTUI] getPlayStatus() :1 (PLAYING)
01-27 08:54:13.806: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayStatus = 1 (PLAYING)
01-27 08:54:13.806: D/LGBluetoothAvrcpAdapter(5129): Starting play position changed timer
01-27 08:54:13.806: D/LGBluetoothAvrcpAdapter(5129): Play position changed timer delay: 1 seconds
01-27 08:54:14.186: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:14.186: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:14.186: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:14.186: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:14.196: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:14.276: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:14.276: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:14.276: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:14.276: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:14.276: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:14.276: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:14.276: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:14.286: V/MediaPlayerService(2014): [2066] getCurrentPosition = 199436
01-27 08:54:14.306: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:14.306: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:14.306: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:14.306: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:14.306: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:14.776: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:14.776: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:14.786: D/BubblePopupHelper(2817): isShowingBubblePopup : false
01-27 08:54:14.786: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:14.786: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:14.786: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:14.786: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:14.786: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:14.786: V/MediaPlayerService(2014): [2066] getCurrentPosition = 199993
01-27 08:54:14.796: D/PhoneInterfaceManager(3028): [PhoneIntfMgr] sigLevel = 2
01-27 08:54:14.806: D/LGBluetoothAvrcpAdapter(5129): Timer expired. Sending request for play state
01-27 08:54:14.806: E/LGBluetoothAvrcpManager(5129): [BTUI] command : NOTIFY response(CHANGED) : EventPlaybackPosChanged
01-27 08:54:14.806: D/LGBluetoothAvrcpManager(5129): [BTUI] calculated position is larger than duration
01-27 08:54:14.806: D/LGBluetoothAvrcpManager(5129): [BTUI] response : CHANGED : EventPlaybackPosChanged : 149490
01-27 08:54:14.806: D/BluetoothAVRCP1.3ServiceJni(5129): onSongPositionChangedNative
01-27 08:54:14.816: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:14.816: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:14.816: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:14.816: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:14.816: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:14.846: E/bt-avp(5129): opcode 0
01-27 08:54:14.846: I/BluetoothAVRCP1.3ServiceJni(5129): BTRC_EVT_PLAY_POS_CHANGED
01-27 08:54:14.846: D/LGBluetoothAvrcpManager(5129): [BTUI] calculated position is larger than duration
01-27 08:54:14.846: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayPosition = 149490
01-27 08:54:14.846: D/LGBluetoothAvrcpAdapter(5129): [BTUI] getPlayPosition() :149490
01-27 08:54:14.846: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayStatus = 1 (PLAYING)
01-27 08:54:14.846: D/LGBluetoothAvrcpAdapter(5129): [BTUI] getPlayStatus() :1 (PLAYING)
01-27 08:54:14.846: I/LGBluetoothAvrcpManager(5129): [BTUI] getPlayStatus = 1 (PLAYING)
01-27 08:54:14.846: D/LGBluetoothAvrcpAdapter(5129): Starting play position changed timer
01-27 08:54:14.846: D/LGBluetoothAvrcpAdapter(5129): Play position changed timer delay: 1 seconds
01-27 08:54:15.276: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:15.276: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:15.276: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:15.276: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:15.276: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:15.276: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:15.276: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:15.276: V/MediaPlayerService(2014): [2066] getCurrentPosition = 200481
01-27 08:54:15.316: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:15.316: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:15.316: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:15.316: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:15.326: D/PhoneApp(3028): getIsInUseVoLTE : false
01-27 08:54:15.776: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:15.776: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:15.776: V/MediaPlayerService(2014): [2066] isPlaying: 1
01-27 08:54:15.776: V/MediaPlayer[Native](27650): isPlaying: 1
01-27 08:54:15.776: V/MediaPlayer[Native](27650): getDuration_l
01-27 08:54:15.776: V/MediaPlayerService(2014): [2066] getDuration = 435304
01-27 08:54:15.776: V/MediaPlayer[Native](27650): getCurrentPosition
01-27 08:54:15.776: V/MediaPlayerService(2014): [2066] getCurrentPosition = 200945
01-27 08:54:15.826: D/audio_hw_extn(2014): audio_extn_get_parameters: returns 
01-27 08:54:15.826: V/msm8974_platform(2014): platform_get_parameters: exit: returns - 
01-27 08:54:15.826: V/audio_hw_primary(2014): adev_get_parameters: exit: returns - 
01-27 08:54:15.826: I/str_params(2014): key: 'isSwIrrc' value: ''
01-27 08:54:15.826: D/PhoneApp(3028): getIsInUseVoLTE : false
smithdtyler commented 9 years ago

Looks like this might be related to Android 4.3+ Potentially related SO post

smithdtyler commented 9 years ago

Success case:

01-31 20:21:24.114: V/MediaPlayer[Native](18583): isPlaying: 1
01-31 20:21:24.114: V/MediaPlayer[Native](18583): getDuration_l
01-31 20:21:24.114: V/MediaPlayer[Native](18583): getCurrentPosition
01-31 20:21:24.224: I/ViewRootImpl(18583): ViewRoot's KeyEvent { action=ACTION_DOWN, keyCode=KEYCODE_MEDIA_PLAY, scanCode=200, metaState=0, flags=0x8, repeatCount=0, eventTime=457497212, downTime=457497212, deviceId=26, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43f87d60 V.E..... R....... 0,0-1440,2392}
01-31 20:21:24.234: I/MusicBroadcastReceiver(18583): got a thingy!
01-31 20:21:24.234: I/MusicBroadcastReceiver(18583): Media Button Receiver: received media button intent: Intent { act=android.intent.action.MEDIA_BUTTON flg=0x10000010 cmp=com.smithdtyler.prettygoodmusicplayer/.MusicBroadcastReceiver (has extras) }
01-31 20:21:24.234: I/MusicBroadcastReceiver(18583): Got a key event
01-31 20:21:24.254: I/MusicBroadcastReceiver(18583): got a thingy!
01-31 20:21:24.254: I/MusicBroadcastReceiver(18583): Media Button Receiver: received media button intent: Intent { act=android.intent.action.MEDIA_BUTTON flg=0x10000010 cmp=com.smithdtyler.prettygoodmusicplayer/.MusicBroadcastReceiver (has extras) }
01-31 20:21:24.254: I/MusicBroadcastReceiver(18583): Got a key event
01-31 20:21:24.254: I/MusicBroadcastReceiver(18583): Got a key up event
01-31 20:21:24.254: I/MusicBroadcastReceiver(18583): key pressed KEYCODE_MEDIA_PLAY
01-31 20:21:24.254: I/MyService(18583): Received start id 12: Intent { cmp=com.smithdtyler.prettygoodmusicplayer/.MusicPlaybackService (has extras) }
01-31 20:21:24.254: I/ViewRootImpl(18583): ViewRoot's KeyEvent { action=ACTION_UP, keyCode=KEYCODE_MEDIA_PLAY, scanCode=200, metaState=0, flags=0x8, repeatCount=0, eventTime=457497243, downTime=457497212, deviceId=26, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43f87d60 V.E..... R....... 0,0-1440,2392}
01-31 20:21:24.264: I/MusicPlaybackService(18583): I got a message! 3
01-31 20:21:24.264: I/MusicPlaybackService(18583): I got a playpause message
01-31 20:21:24.264: V/MediaPlayer[Native](18583): isPlaying: 1
01-31 20:21:24.264: V/MediaPlayer[Native](18583): isPlaying: 1
01-31 20:21:24.264: V/MediaPlayer[Native](18583): pause
01-31 20:21:24.264: V/MediaPlayer[Native](18583): message received msg=7, ext1=0, ext2=0
01-31 20:21:24.264: D/MediaPlayer[Native](18583): calling notify_player_state: 32
01-31 20:21:24.264: V/MediaPlayer[Native](18583): unrecognized message: (7, 0, 0)
01-31 20:21:24.264: V/MediaPlayer[Native](18583): callback application
01-31 20:21:24.264: V/MediaPlayer[Native](18583): back from callback
01-31 20:21:24.264: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:24.274: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:24.274: D/MediaPlayer[JAVA](18583): broadcasting MEDIA_CHANGE_PLAYER_STATE(no context) : 0x0
01-31 20:21:24.274: E/MediaPlayer[Native](18583): invoke invokeId=0xbe885270
01-31 20:21:24.274: E/MediaPlayer[Native](18583): invoke key=0xbe885274
01-31 20:21:24.274: E/MediaPlayer[Native](18583): [MediaPlayer::getMediaSystemInfo] key = 4000
01-31 20:21:24.274: V/MediaPlayer[Native](18583): invoke 72
01-31 20:21:24.274: D/MediaPlayer[Native](18583): invoke lgeInvokeId=0x7e000002
01-31 20:21:24.274: D/MediaPlayer[Native](18583): MediaPlayer::invoke::getparam
01-31 20:21:24.274: D/MediaPlayer[Native](18583): MediaPlayer::getParameter mCurrentState = 0x00000020
01-31 20:21:24.274: D/MediaPlayer[JAVA](18583): broadcasting MEDIA_CHANGE_PLAYER_STATE(no context) : state = 32
01-31 20:21:24.274: V/MediaPlayer[Native](18583): getCurrentPosition
01-31 20:21:24.274: V/MediaPlayer[Native](18583): getDuration_l
01-31 20:21:24.574: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:24.574: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:24.584: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:24.584: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:24.584: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:24.594: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:24.594: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:24.594: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:24.594: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:24.594: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:24.594: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:24.594: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:25.024: I/ViewRootImpl(18583): ViewRoot's KeyEvent { action=ACTION_DOWN, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=457498012, downTime=457498012, deviceId=26, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43f87d60 V.E..... R....... 0,0-1440,2392}
01-31 20:21:25.034: I/MusicBroadcastReceiver(18583): got a thingy!
01-31 20:21:25.034: I/MusicBroadcastReceiver(18583): Media Button Receiver: received media button intent: Intent { act=android.intent.action.MEDIA_BUTTON flg=0x10000010 cmp=com.smithdtyler.prettygoodmusicplayer/.MusicBroadcastReceiver (has extras) }
01-31 20:21:25.034: I/MusicBroadcastReceiver(18583): Got a key event
01-31 20:21:25.054: I/MusicBroadcastReceiver(18583): got a thingy!
01-31 20:21:25.054: I/MusicBroadcastReceiver(18583): Media Button Receiver: received media button intent: Intent { act=android.intent.action.MEDIA_BUTTON flg=0x10000010 cmp=com.smithdtyler.prettygoodmusicplayer/.MusicBroadcastReceiver (has extras) }
01-31 20:21:25.054: I/MusicBroadcastReceiver(18583): Got a key event
01-31 20:21:25.054: I/MusicBroadcastReceiver(18583): Got a key up event
01-31 20:21:25.054: I/MusicBroadcastReceiver(18583): key pressed KEYCODE_MEDIA_PAUSE
01-31 20:21:25.054: I/MyService(18583): Received start id 13: Intent { cmp=com.smithdtyler.prettygoodmusicplayer/.MusicPlaybackService (has extras) }
01-31 20:21:25.054: I/MusicPlaybackService(18583): I got a message! 3
01-31 20:21:25.054: I/MusicPlaybackService(18583): I got a playpause message
01-31 20:21:25.054: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:25.054: I/ViewRootImpl(18583): ViewRoot's KeyEvent { action=ACTION_UP, keyCode=KEYCODE_MEDIA_PAUSE, scanCode=201, metaState=0, flags=0x8, repeatCount=0, eventTime=457498043, downTime=457498012, deviceId=26, source=0x101 } to com.android.internal.policy.impl.PhoneWindow$DecorView{43f87d60 V.E..... R....... 0,0-1440,2392}
01-31 20:21:25.064: V/MediaPlayer[Native](18583): isPlaying: 0
01-31 20:21:25.064: D/MusicPlaybackService(18583): requestAudioFocus result = 1
01-31 20:21:25.064: I/MusicPlaybackService(18583): About to play /storage/external_SD/Music/Tool/Salival/06 Merkaba (Live).mp3
01-31 20:21:25.064: D/MusicPlaybackService(18583): We got audio focus!
01-31 20:21:25.064: V/MediaPlayer[Native](18583): start
01-31 20:21:25.064: D/MediaPlayer[Native](18583): calling notify_player_state: 16
01-31 20:21:25.074: V/MediaPlayer[Native](18583): isPlaying: 1
smithdtyler commented 9 years ago

I'm going to try manually opening a connection to the bluetooth device to see if I can force the connection to stay open.

https://developer.android.com/guide/topics/connectivity/bluetooth.html#QueryingPairedDevices

smithdtyler commented 9 years ago

The app itself seems to be timing out in its bluetooth access window. I can turn my headset on and off with no effect, but if I restart the app I can regain bluetooth control. I think the app needs to do something to tell the OS "I'm still using bluetooth..."

smithdtyler commented 9 years ago

An approach of periodically checking the status of the device doesn't seem to help.

smithdtyler commented 9 years ago

Next I want to try periodically un-registering and re-registering for bluetooth events and media events. Perhaps my media event listener is being timed out?

I also should re-register the event listener when bluetooth is connected.

smithdtyler commented 9 years ago

This issue appears to be resolved by upgrading to Lollipop.