1156519 - [Music] Music track completes and stops with a few seconds left, failing to proceed to the next track

Status: VERIFIED FIXED

(Firefox OS Graveyard :: Gaia::Music, defect)

Description

[Joshua Mitchell (Inactive)]

Attachment: logcat_20150420_1445.txt

Description:
If you are playing music that should transfer from one song to another (playlists, songlist, etc), if you are not in the music app the song will end with a few seconds remaining on the track and will not advance to the next song. The song itself plays completely, no lyrics or notes are missed, but for longer songs (4 minutes) there is usually 8 seconds left on the track. If you hit 'Next Track' it will repeat the current track. This occurs hitting track forward from the notification menu or from returning to the music app. This bug occurs with plugged headphones or playing through speaker. 


Repro Steps: (required: several songs)
1) Update a Flame to 20150420010204
2) Launch Music app
3) Select Songs panel
4) Select first song and play
5) Hit Home Button to return to homescreen (can also repro from going to other apps)
6) Wait for song to be over


Actual:
Song does not advance to next track, returning to music app may show song in stopped state with several seconds remaining


Expected:
Song will end and advance to the next track



Environmental Variables:
Device: Flame 3.0
Build ID: 20150420010204
Gaia: cb41d8421da5dc4f16ea566ea2917a9b7f828154
Gecko: 50b95032152c
Gonk: b83fc73de7b64594cd74b33e498bf08332b5d87b
Version: 40.0a1 (3.0)
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:40.0) Gecko/40.0 Firefox/40.0


Repro frequency: 14/15
See attached: logcat

Comment 1

[Joshua Mitchell (Inactive)]

Issue does reproduce in Flame 2.2

Device: Flame 2.2 (KK - Nightly - Full Flash - 319mem)
Build ID: 20150420002502
Gaia: c15a2b6d3a783813959c2b3bffd2a131f4270b9e
Gecko: cc02ee38b252
Gonk: ebad7da532429a6f5efadc00bf6ad8a41288a429
Version: 37.0 (2.2)
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:37.0) Gecko/37.0 Firefox/37.0


Issue does NOT reproduce in Flame 2.1

Actual Results: Music app moves onto the next track

Device: Flame 2.1 (KK - Nightly - Full Flash - 319mem)
Build ID: 20150420001205
Gaia: bbe983b4e8bebfec26b3726b79568a22d667223c
Gecko: b85d4f4a6d61
Gonk: ebad7da532429a6f5efadc00bf6ad8a41288a429
Version: 34.0 (2.1)
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:34.0) Gecko/34.0 Firefox/34.0

Comment 2

[Peter Bylenga [:PBylenga]]

Functional regression of a core feature.

Requesting a window.

Comment 3

[Hema Koka [:hema]]

Blocking Reason: Regression from 2.1

David or Punam,

Could one of you check once we have a regression window from QA and if it points to the app side? Dominic, Hub and Jim are already on other music blockers. Leaving an NI on you.

Thanks
Hema

Comment 4

[David Flanagan [:djf]]

Joshua,

What kind of music files does this occur on?  mp3? aac? Something else? Does it seem like it happens with any music file on your phone, or is there some specific one that makes it happen?

What do you mean "the song plays completely but there are usually 8 seconds left on the track". Do you mean that the phone shows 8 seconds remaining even though the song has finished?  

And are you seeing this on the lockscreen, in the notification tray or in the music app itself?

Comment 5

[Oliver Nelson [:oliverthor]]

I believe this was only tested against mp3s.

[Behavior] The present song plays to completion, however another track does not start up. When returning to the music app, the user would observe the current song UI and a paused track with 8 seconds remaining on the timeline. Though the timeline shows 8 seconds remaining, tapping play will restart the song.

[In Music App] If the user remains in the music app, actively listening and observing the timeline, music progression will perform as expected and this bug does not occur. 

[Lockscreen] The actual behavior of this bug is observed when a song finishes from lockscreen as well: song plays to completion but is 'paused' 8 seconds to the end when returning to app. 

[Notification Tray] The song will appear 'paused' in tray if finished outside the app. Tapping play on this song in the tray widget at this time will restart the song, rather than play the 'remaining' 8 seconds the music app advertises.

Comment 6

[David Flanagan [:djf]]

Thanks for the detailed clarifications, Oliver.

I'll take this and look into it. 

First, I want to see if it is related to, or the same as, 1155118.

Comment 7

[David Flanagan [:djf]]

It sounds like this may be a dupe of 1155118. Hub says that that bug is a regression caused by bug 1145758. If this wasn't a blocker, I'd just mark it as a dupe. But since it seems kind of serious, I'll let Hub keep working on 1155118 and I'll work on it here in this bug.

Comment 8

[David Flanagan [:djf]]

Here's what seems to be going on here:

1) When the music app is not in the foreground, we stop listening to timeupdate events. This is good. But it completely breaks the old bug workaround that we have in for missing ended events.  So if they player has been working when in the background, it means we don't need that workaround anymore, since we haven't ever actually been using it in that case.

2) When the player reaches the end of a song, it sends a "pause" event and then sends an "ended" event. 
So, when we're not visible, we're not listening for timeupdate events, so we don't register a ended timer, and we do pay attention to ended events.  This worked, until bug 1145758 which added a paused check as part of the ended event handler.  Since we always get a pause event before the ended event, we end up ignoring the ended event because we were just paused.

So in this case, when we're in the background, there is nothing to call this.next() and we never advance to the next song.

Given that app has been working okay in the background even with the old workaround inadvertently disabled, I say that is evidence that it is safe to just remove the workaround.  That is what Jim was advocating in his review of the regressing bug anyway.

So, let's back out 1145758. That should resolve this bug and the bug 1155118 duplicate. Then, let's remove the old endedTimer workaround code.  Hopefully doing that will be enough to resolve bug 1145758.

Comment 9

[David Flanagan [:djf]]

I've confirmed that backing out 1145758 resolves this bug.

Comment 11

[David Flanagan [:djf]]

The regressing patch from bug 1145758 has been backed out of master and v2.2, and that resolves this bug.

https://github.com/mozilla-b2g/gaia/commit/5b4660ba64e7792bb7bc8369056c6d7419dc99fb
https://github.com/mozilla-b2g/gaia/commit/41a85c5f9db291d4f7c0e94c8416b5115b4ee407

Comment 12

[KTucker [:KTucker][Inactive 3/4/2016]]

Adding verifyme and qawanted to ensure that this has been fixed.

Comment 13

[KTucker [:KTucker][Inactive 3/4/2016]]

This issue has been verified as fixed on the Flame 3.0 and 2.2

The song in the playlist plays to the end and goes to the next song without issue when the music app is in the background. I tested while being in other apps, notification tray and the lockscreen.

Environmental Variables:
Device: Flame 3.0(Full Flash)(KK)(319mb)
BuildID: 20150422010202
Gaia: 15134b080b5f406e5aa36f5136c17dafb4e31f64
Gecko: 946ac85af8f4
Gonk: b83fc73de7b64594cd74b33e498bf08332b5d87b
Version: 40.0a1 (3.0) 
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:40.0) Gecko/40.0 Firefox/40.0

Environmental Variables:
Device: Flame 2.2(Full Flash)(Kk)(319mb)
BuildID: 20150422002505
Gaia: 41a85c5f9db291d4f7c0e94c8416b5115b4ee407
Gecko: a87a05e7d0ef
Gonk: ebad7da532429a6f5efadc00bf6ad8a41288a429
Version: 37.0 (2.2) 
Firmware Version: v18D-1
User Agent: Mozilla/5.0 (Mobile; rv:37.0) Gecko/37.0 Firefox/37.0