1226307 - [music] Fast-seeking to the end of the song skips over a song (goes from track 1 directly to 3)

Status: RESOLVED WONTFIX

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

Description

[Jim Porter (:squib)]

+++ This bug was initially created as a clone of Bug #1222387 +++

If you hold down the >| and fast-seek to the end of a song, we get two "ended" events from Gecko, causing us to go to the next track *twice*. This results in us skipping over the second track. I have a build here from October 2, and it still happens there, so this has been around for a while.

Comment 1

[Carrie.Yang Leave from Mozilla]

This bug can be repro on the latest build of Flame KK v2.5& master 512mb by the STR in Comment 0.
Actual results: Fast-seeking to the end of the song skips over a song.
See attachment: Flame_v2.5.3gp and logcat_2130.txt.
Reproduce rate: 10/10

Device: Flame KK v2.5 512mb (Affected)
Build ID               20151119010236
Gaia Revision          28d63cf3bdc4417f7ad8cab2230f096bf9f6d3b5
Gaia Date              2015-11-17 07:35:12
Gecko Revision         http://hg.mozilla.org/releases/mozilla-b2g44_v2_5/rev/afcf8a4b4cf310edd0e442fa80506d5cce291666
Gecko Version          44.0a2
Device Name            flame
Firmware(Release)      4.4.2
Firmware(Incremental)  eng.worker.20151119.001411
Firmware Date          Thu Nov 19 00:14:20 UTC 2015
Firmware Version       v18D v4
Bootloader             L1TC000118D0

Device: Flame KK v2.6 (Affected)
Build ID               20151119150204
Gaia Revision          94a821b49f4dca3f9321cd80e13c44c4a6696952
Gaia Date              2015-11-19 15:35:33
Gecko Revision         https://hg.mozilla.org/mozilla-central/rev/cc325db44f6f8a58604d60b746c140e73f3d8216
Gecko Version          45.0a1
Device Name            flame
Firmware(Release)      4.4.2
Firmware(Incremental)  eng.cltbld.20151119.182720
Firmware Date          Thu Nov 19 18:27:32 EST 2015
Firmware Version       v18D v4
Bootloader             L1TC000118D0

Comment 2

[Carrie.Yang Leave from Mozilla]

Attachment: Flame_v2.5.3gp

Comment 3

[Carrie.Yang Leave from Mozilla]

Attachment: logcat_2130.txt

Comment 4

[Carrie.Yang Leave from Mozilla]

The oldest build in b2g-inbound / mozilla-inbound is 20150827172449 / 20150827152849, which is later than the first broken build & last working build, so I try to do the regression in Nightly builds.

Nightly Regression Window:

Last Working Environmental Variables:
Device: Flame KK master (512mb)
Build ID               20150422010202
Gaia Revision          15134b080b5f406e5aa36f5136c17dafb4e31f64
Gaia Date              2015-04-21 19:52:45
Gecko Revision         https://hg.mozilla.org/mozilla-central/rev/946ac85af8f4
Gecko Version          40.0a1
Device Name            flame
Firmware(Release)      4.4.2
Firmware(Incremental)  eng.cltbld.20150429.043837
Firmware Date          Wed Apr 29 04:38:48 EDT 2015
Fireware Version       v18D v4
Bootloader             L1TC000118D0

First Broken Environmental Variables:
Device: Flame KK master (512mb)
Build ID               20150422160203
Gaia Revision          9d4f756aa35cb7f030a92f3c1f65fb55254ddd1d
Gaia Date              2015-04-22 17:32:36
Gecko Revision         https://hg.mozilla.org/mozilla-central/rev/a9311ec2dd39
Gecko Version          40.0a1
Device Name            flame
Firmware(Release)      4.4.2
Firmware(Incremental)  eng.cltbld.20150425.043856
Firmware Date          Sat Apr 25 04:39:08 EDT 2015
Fireware Version       v18D v4
Bootloader             L1TC000118D0

First Broken Gaia & Last Working Gecko - issue DOES repro
Gaia Revision          9d4f756aa35cb7f030a92f3c1f65fb55254ddd1d
Gecko Revision         https://hg.mozilla.org/mozilla-central/rev/946ac85af8f4

First Broken Gecko & Last Working Gaia – issue DOES NOT repro
Gaia Revision          15134b080b5f406e5aa36f5136c17dafb4e31f64
Gecko Revision         https://hg.mozilla.org/mozilla-central/rev/a9311ec2dd39

Gaia pushlog:
https://github.com/mozilla-b2g/gaia/compare/15134b080b5f406e5aa36f5136c17dafb4e31f64...9d4f756aa35cb7f030a92f3c1f65fb55254ddd1d

Comment 5

[John Thomas [:Johnt]]

This issue appears to be caused by the implementation of Music NGA.
Specifically it is caused by changes made in Bug 1208108 OR Bug 1208154

B2G Inbound Regression Window

Last Working
Environmental Variables:
Device: Flame 2.5
BuildID: 20150928123103
Gaia: c7cf2abd0ebb83ef238b3a3f150d49300a2ee7d7
Gecko: 251526a15d4101492849ca8912cea54f7ed740ec
Version: 44.0a1 (2.5) 
Firmware Version: v18D
User Agent: Mozilla/5.0 (Mobile; rv:44.0) Gecko/44.0 Firefox/44.0

First Broken
Environmental Variables:
Device: Flame 2.5
BuildID: 20150928124002
Gaia: 33381d5a9136e673e50b798ffb7727c2b5c23496
Gecko: 92e4ddc1f040a26521b4674780b1334b5544a8a9
Version: 44.0a1 (2.5) 
Firmware Version: v18D
User Agent: Mozilla/5.0 (Mobile; rv:44.0) Gecko/44.0 Firefox/44.0

Last Working gaia / First Broken gecko - This issue does NOT occur with broken Gecko
Gaia: c7cf2abd0ebb83ef238b3a3f150d49300a2ee7d7
Gecko: 92e4ddc1f040a26521b4674780b1334b5544a8a9

Last Working gecko / First Broken gaia - This issue DOES occur with broken Gaia
Gecko: 251526a15d4101492849ca8912cea54f7ed740ec
Gaia: 33381d5a9136e673e50b798ffb7727c2b5c23496

Gaia Inbound Pushlog:
https://github.com/mozilla-b2g/gaia/compare/c7cf2abd0ebb83ef238b3a3f150d49300a2ee7d7...33381d5a9136e673e50b798ffb7727c2b5c23496

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

Additional note: This issue does NOT occur on Aries Master

Environmental Variables:
Device: Aries 2.6 Kk
BuildID: 20151120133504
Gaia: 94a821b49f4dca3f9321cd80e13c44c4a6696952
Gecko: ec628289d8b4ed310463a0729c3e60a7798dfcac
Gonk: a19052e4389c3ae2d8fc3e7a74a475401baacc56
Version: 45.0a1 (2.6) 
Firmware Version: D5803_23.1.A.1.28_NCB.ftf
User Agent: Mozilla/5.0 (Mobile; rv:45.0) Gecko/45.0 Firefox/45.0

Comment 6

[Jim Porter (:squib)]

(In reply to John Thomas [:Johnt] from comment #5)
> This issue appears to be caused by the implementation of Music NGA.
> Specifically it is caused by changes made in Bug 1208108 OR Bug 1208154

Then why does the same thing happen in OGA, which hasn't seen any (significant) change since before NGA landed? I'm not convinced that NGA is at fault here.

Comment 7

[John Thomas [:Johnt]]

(In reply to Jim Porter (:squib) from comment #6)
> Then why does the same thing happen in OGA, which hasn't seen any
> (significant) change since before NGA landed? I'm not convinced that NGA is
> at fault here.

------

I attempted this issue on the latest Flame 2.6 Eng build using the music OGA app and was NOT able to repro this issue.

Environmental Variables:
Device: Flame 2.6 Eng Kk Fullflash (512mb)
BuildID: 20151120030231
Gaia: 94a821b49f4dca3f9321cd80e13c44c4a6696952
Gecko: 3835b568092ae3b71adc931d24928670ad7141a7
Gonk: 205ac4204bbbb2098a8046444acba551ba5dc75a
Version: 45.0a1 (2.6) 
Firmware Version: v18D
User Agent: Mozilla/5.0 (Mobile; rv:45.0) Gecko/45.0 Firefox/45.0

Comment 8

[Jim Porter (:squib)]

I just did it right now. Were you trying with the same songs? There are a couple of songs where this works for me.

Comment 9

[John Thomas [:Johnt]]

I was trying the same songs specifically on the "Artist" tab. (What my window was based on.) However after further investigating with the same variables from Comment 7 it DOES seem to repro in OGA but specifically in the Songs tab.

Comment 10

[Jayme Mercado [:JMercado] (Inactive 3/4/2016)]

Let's get another window here using the songs tab instead of the artist tab.

Comment 11

[Jean-Yves Avenard [:jya]]

In Bug 1222387, the regression fixed was when seeking to a negative value when readyState was HAVE_NOTHING

If this is a condition that actually happens, it's really a matter of garbage in garbage out (and it appears to happen as this was the only way you could get currentTime to have a negative value)

Comment 12

[Jim Porter (:squib)]

(In reply to Jean-Yves Avenard [:jya] from comment #11)
> In Bug 1222387, the regression fixed was when seeking to a negative value
> when readyState was HAVE_NOTHING
> 
> If this is a condition that actually happens, it's really a matter of
> garbage in garbage out (and it appears to happen as this was the only way
> you could get currentTime to have a negative value)

I'll have to check and see if things are better after your patch, but I'm still wondering where those negative numbers were coming from, since 1) as far as I can tell, this was happening when readyState != HAVE_NOTHING, and 2) we never set currentTime to a negative number ourselves, so it must be coming from somewhere else.

Comment 13

[Jim Porter (:squib)]

[Blocking Requested - why for this release]: This should block because it's split off from another blocking bug, and is equally bad. We should never skip over a song entirely just because you fast-forwarded to the end of one.

Comment 14

[Jayme Mercado [:JMercado] (Inactive 3/4/2016)]

Bug 1145758 seems to have caused this issue.

Central Regression Window:

Last Working 
Environmental Variables:
Device: Flame 2.5
BuildID: 20150421200413
Gaia: 15134b080b5f406e5aa36f5136c17dafb4e31f64
Gecko: 946ac85af8f4
Gonk: 205ac4204bbbb2098a8046444acba551ba5dc75a
Version: 40.0a1 (2.5) 
Firmware Version: v18D
User Agent: Mozilla/5.0 (Mobile; rv:40.0) Gecko/40.0 Firefox/40.0

First Broken 
Environmental Variables:
Device: Flame 2.5
BuildID: 20150422062923
Gaia: a7dcc5fb595030dab140d5ff0e7eb5ef04017d51
Gecko: a955d8a44ca4
Gonk: 205ac4204bbbb2098a8046444acba551ba5dc75a
Version: 40.0a1 (2.5) 
Firmware Version: v18D
User Agent: Mozilla/5.0 (Mobile; rv:40.0) Gecko/40.0 Firefox/40.0

Last Working gaia / First Broken gecko -  Issuedoes NOT occur
Gaia: 15134b080b5f406e5aa36f5136c17dafb4e31f64
Gecko: a955d8a44ca4

First Broken gaia / Last Working gecko - Issue DOES occur
Gaia: a7dcc5fb595030dab140d5ff0e7eb5ef04017d51
Gecko: 946ac85af8f4

Gecko Pushlog: https://github.com/mozilla-b2g/gaia/compare/15134b080b5f406e5aa36f5136c17dafb4e31f64...a7dcc5fb595030dab140d5ff0e7eb5ef04017d51

Comment 15

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

David, can you take a look at this please? Looks like this was caused by the landing for bug 1145758.

Comment 16

[David Flanagan [:djf]]

Jim: does the regression window in comment 14 and 15 help with this? I don't know whether my patch from bug 1145758 made it into the refactored music app or not, but if so, then maybe this is a clue about what is going on.

Let me know if you'd like me to take a look.  And if not, consider assigning the bug to yourself.

Comment 17

[Justin D'Arcangelo [:justindarc]]

(In reply to David Flanagan [:djf] from comment #16)
> Jim: does the regression window in comment 14 and 15 help with this? I don't
> know whether my patch from bug 1145758 made it into the refactored music app
> or not, but if so, then maybe this is a clue about what is going on.
> 
> Let me know if you'd like me to take a look.  And if not, consider assigning
> the bug to yourself.

This code definitely didn't get copied over to the NGA app. So, its likely that there is coincidentally some commonality between this patch and what we are currently doing.

Comment 18

[Jim Porter (:squib)]

The relevant part *did* get copied over to NGA: namely, the fact that we don't have an endedTimer as a workaround anymore.

Comment 19

[Justin D'Arcangelo [:justindarc]]

(In reply to Jim Porter (:squib) from comment #18)
> The relevant part *did* get copied over to NGA: namely, the fact that we
> don't have an endedTimer as a workaround anymore.

Interesting. So, the removal of the workaround for Bug 783512 is the issue? Its sad that we even need to work around this to begin with.

Comment 20

[Jim Porter (:squib)]

Well, the workaround that was removed is almost identical to the one you proposed in the other bug, so I'd guess that's the issue. :)

Comment 21

[David Flanagan [:djf]]

It wasn't just the removal of a workaround. Take a look at the patch in that bug. I also had to add a new workaround because resuming playback of an mp4 file that was very near to the end was very slow. So there was code in there that would call next() if the user resumed playing when very close to the end of the song...

It does appear, however, that Jim saw this coming: https://bugzilla.mozilla.org/show_bug.cgi?id=1145758#c21

Comment 22

[Jim Porter (:squib)]

(In reply to David Flanagan [:djf] from comment #21)
> It wasn't just the removal of a workaround. Take a look at the patch in that
> bug. I also had to add a new workaround because resuming playback of an mp4
> file that was very near to the end was very slow. So there was code in there
> that would call next() if the user resumed playing when very close to the
> end of the song...

True, and we should test whether that's still an issue.

> It does appear, however, that Jim saw this coming:
> https://bugzilla.mozilla.org/show_bug.cgi?id=1145758#c21

And yet I r+'ed the patch for some reason. I probably should have gone with my instincts and checked that case more carefully. :)

Comment 23

[Jim Porter (:squib)]

Actually, thinking about my old comment, I was probably worried that removing the workaround would result in *no* ended events being fired. Since Murphy's Law is in effect, of course we end up with *two* ended events fired instead.

Comment 24

[Hema Koka [:hema]]

Blocking this for 2.6

Comment 25

[BMO Automation]

Firefox OS is not being worked on