Closed Bug 1229651 Opened 8 years ago Closed 8 years ago

Crashing of Video app during loading permanently renders the app unusable

Categories

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

ARM
Gonk (Firefox OS)
defect
Not set
normal

Tracking

(blocking-b2g:2.5+, b2g-v2.2 unaffected, b2g-v2.5 verified, b2g-master verified)

VERIFIED FIXED
blocking-b2g 2.5+
Tracking Status
b2g-v2.2 --- unaffected
b2g-v2.5 --- verified
b2g-master --- verified

People

(Reporter: u547545, Assigned: djf)

References

Details

(Keywords: regression, smoketest, Whiteboard: [mozfr-community] [dogfood-blocker])

Attachments

(7 files)

Attached image 2015-12-02-06-25-04.png
User Agent: Mozilla/5.0 (X11; Ubuntu; Linux i686; rv:42.0) Gecko/20100101 Firefox/42.0
Build ID: 20151030084423

Steps to reproduce:

Tested with ZTE Open C FR.

1) Open the video application.


Actual results:

-> The video application does not display anything. She indefinitely load.
(The blue and black loading line at the top of the screen).

Reproducible 5/5.


Expected results:

-> The video application should open. It should offer me to play videos.

_______
OS Version: 2.6.0.0-prerelease
Build Number: eng..20140806.064432
Platform Version: 45.0a1
Build Identifier: 20151202003955
Update Channel: nightly
Git Commit Info: 2015-12-01 18:47:31 (7847a3c1)
Whiteboard: [mozfr-community]
This was encountered during Smoketest. It has occurred on multiple devices, but we have been unable to find consistent reproduction steps.  Once this issue occurs, the video app will be unable to play videos that were already present before the issue occurred. Furthermore, this issue often appears to persist even after performing a factory reset, or full flashing another build to the device.  Camera and Gallery apps are still functional, but the Video App is unable to discover and play videos.

Note: We were able to recover the use of the video app after using 'ADB Shell' in the command line to delete the contents of 'storage/sdcard0'.  Simply deleting the files via USB Storage in Settings did not resolve this issue.

Upgrading this issue to Smoketest Blocker.

STR:
1) Record a video in the Camera
3) Launch the Video app and attempt to view the recorded video
3) Launch the Gallery app and view the recorded video.
4) Close the Camera, Video, and Gallery apps.
5) Repeat steps 1-4 multiple times.

Environmental Variables:
Device: Aries 2.6
BuildID: 20151203121905
Gaia: 97266c579c544f5ba57a701f39893cc86d46774a
Gecko: 85cf2e720a8405c43eabc9b34cce381b66d25ef9
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

********************************************

This issue was NOT seen to occur on the latest Flame Nightly  build.
This issue appears to only affect the Aries device.

Environmental Variables:
Device: Flame 2.6
BuildID: 20151203053521
Gaia: 97266c579c544f5ba57a701f39893cc86d46774a
Gecko: 85cf2e720a8405c43eabc9b34cce381b66d25ef9
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
Status: UNCONFIRMED → NEW
Ever confirmed: true
Keywords: smoketest
QA Whiteboard: [severe]
Summary: (B2G 2.6) The video application inexorably load → [Aries](B2G 2.6) The video application inexorably load
Summary: [Aries](B2G 2.6) The video application inexorably load → [Aries](B2G 2.6) The video app does not load properly
QA Contact: pcheng
We can't reliably reproduce this on a fresh flash (once it occurs, it occurs permanently until reflashed, but the problem is getting it to occur from scratch). Adding steps-wanted.
STR:
0) Phone is connected via USB cable to computer
1) On a fresh flash, open Video app (there should be no videos in it)
2) Tap on 'Go to Camera' button
3) Record 3 videos, each about 5 seconds
4) Return to Home, open up Terminal
5) 'adb root' the device first, then 'adb shell b2g-ps', find the process ID # of Video app
6) Immediately after you open up Video app, execute in terminal 'adb shell kill (video app process ID)'
7) Launch Video app again

Expected: Video app launches with the 3 videos that was created at step 3 loaded

Actual: Video app launches with loading bar appearing infinitely on top and no video is being loaded, subsequently breaking the video app until device is reflashed.

Repro rate: 8/8

Aries 2.5, Flame 2.6, Flame 2.5, are also affected.

Device: Aries 2.5
BuildID: 20151203092237
Gaia: 2d54c29f429bed790b5d8284633812dc2b782518
Gecko: 241f079cd53c932561c6aa32b9b93c44cd0846d0
Gonk: a19052e4389c3ae2d8fc3e7a74a475401baacc56
Version: 44.0a2 (2.5) 
Firmware Version: D5803_23.1.A.1.28_NCB.ftf
User Agent: Mozilla/5.0 (Mobile; rv:44.0) Gecko/44.0 Firefox/44.0

Device: Flame 2.5
BuildID: 20151203091655
Gaia: 2d54c29f429bed790b5d8284633812dc2b782518
Gecko: 241f079cd53c932561c6aa32b9b93c44cd0846d0
Gonk: 205ac4204bbbb2098a8046444acba551ba5dc75a
Version: 44.0a2 (2.5) 
Firmware Version: v18Dv4
User Agent: Mozilla/5.0 (Mobile; rv:44.0) Gecko/44.0 Firefox/44.0

--------

Flame 2.2 is unaffected. Video app could be loaded without issue following STR. Repro rate: 0/3.

Device: Flame 2.2
BuildID: 20151203032504
Gaia: 885647d92208fb67574ced44004ab2f29d23cb45
Gecko: 4381c4b69b9c
Gonk: bd9cb3af2a0354577a6903917bc826489050b40d
Version: 37.0 (2.2) 
Firmware Version: v18Dv4
User Agent: Mozilla/5.0 (Mobile; rv:37.0) Gecko/37.0 Firefox/37.0
QA Whiteboard: [severe] → [severe] [QAnalysts-Triage?]
Flags: needinfo?(jmercado)
Keywords: steps-wanted
Summary: [Aries](B2G 2.6) The video app does not load properly → Crashing of Video app during loading renders the app unable permanently
QA Whiteboard: [severe] [QAnalysts-Triage?] → [severe]
Flags: needinfo?(jmercado)
Summary: Crashing of Video app during loading renders the app unable permanently → Crashing of Video app during loading permanently renders the app unusable
Let's use these new steps to find the window.
[Blocking Requested - why for this release]:
Regression/Crash bug, shall we nominate it?
blocking-b2g: --- → 2.5?
b2g-inbound Regression Window:

Last Working Environmental Variables:
Device: Flame KK master (512mb)
Gaia-Rev        91cac94948094cfdcd00cba5c6483e27e80cb3b0
Gecko-Rev       https://hg.mozilla.org/integration/b2g-inbound/rev/3eaedda79e46530dc03b17bbaea52a2248aefe23
Build-ID        20151030192729
Version         45.0a1
Device-Name     flame
FW-Release      4.4.2
FW-Incremental  eng.cltbld.20151103.182550
FW-Date         Tue Nov  3 18:26:03 EST 2015
Firmware Version       v18D v4
Bootloader             L1TC000118D0

First Broken Environmental Variables:
Device: Flame KK master(512mb)
Build-ID        20151031120755
Gaia-Rev        717ee46c64fde7d69a1146f3c54e95b2ef20e706
Gecko-Rev       https://hg.mozilla.org/integration/b2g-inbound/rev/d9bfbd50c917e7f432a4a8cb12a21dca0b96cc0a
Version         45.0a1
Device-Name     flame
FW-Release      4.4.2
FW-Incremental  eng.cltbld.20151102.041923
FW-Date         Mon Nov  2 04:19:39 EST 2015
Firmware Version       v18D v4
Bootloader             L1TC000118D0

First Broken Gaia & Last Working Gecko - issue DOES repro
Gaia-Rev        717ee46c64fde7d69a1146f3c54e95b2ef20e706
Gecko-Rev       3eaedda79e46530dc03b17bbaea52a2248aefe23

First Broken Gecko & Last Working Gaia - issue DOES NOT repro
Gaia-Rev        91cac94948094cfdcd00cba5c6483e27e80cb3b0
Gecko-Rev       d9bfbd50c917e7f432a4a8cb12a21dca0b96cc0a


Gaia pushlog:
https://github.com/mozilla-b2g/gaia/compare/91cac94948094cfdcd00cba5c6483e27e80cb3b0...717ee46c64fde7d69a1146f3c54e95b2ef20e706
QA Whiteboard: [severe] → [severe][MGSEI-Triage+]
This issue seems to have been caused by the changes in bug 1210860.  Russ can you please take a look?
Blocks: 1210860
Flags: needinfo?(rnicoletti)
I will try to take a look at this while at mozlando. Leaving the NI for now.
I am able to recreate the problem on aries. My STR:

1. User camera to record one or two vidoes
2. Open video app

There is a timing issue related to parsing the metadata of the newly created videos before the media db is ready. This is indeed a result of the bug 1210860 patch as part of the patch changed the timing of the video loading from when the media db was fully ready to when it was simply enumerable. The problem occurs when there is metadata to be parsed when the db is being enumerated.

The actual error occurs here: https://github.com/mozilla-b2g/gaia/blob/master/shared/js/mediadb.js#L968

David, I added the following lines after this line: https://github.com/mozilla-b2g/gaia/blob/master/apps/video/js/metadata.js#L67

   if (videodb.state !== MediaDB.READY) {
     setTimeout(processFirstQueuedItem);
     return;
   }

but I've seen other problems when running with this code, for example a crash. However, I haven't made much progress diagnosing the crash. I won't be able to make much progress while at mozlando. Can you take a look?
Flags: needinfo?(rnicoletti) → needinfo?(dflanagan)
Today, the problem seems to be resolved.
Can anyone confirm?

_______
OS Version: 2.6.0.0-prerelease
Build Number: eng..20140806.064432
Platform Version: 45.0a1
Build Identifier: 20151212003449
Update Channel: nightly
Git Commit Info: 2015-12-11 18:28:24 (43339d3f)
There have been no recent changes to the video app recently so the underlying problem (explained in comment 10) still exists. My guess is the problem is not reproducing for you because of the inherent unpredictability of timing issues.
Assignee: nobody → rnicoletti
(In reply to Stephane Stenger from comment #11)
> Today, the problem seems to be resolved.
> Can anyone confirm?

This issue is still happening today. Follow the STR at comment 4.
Whiteboard: [mozfr-community] → [mozfr-community] [dogfood-blocker]
David, this is the patch that detects when the db is not ready and retries after a short delay.
This is the logcat where I was using a slightly different approach from the attached patch. The approach is the same in that if the db is not ready I'm waiting for it to become ready but this logic was in processFirstQueuedItem as opposed to startParsingMetadata.

The initDB session starts on line 267 of the log and the indexedDB error first appears on line 413.
Attachment #8698579 - Attachment description: patch (including diagnostics) → patch with some instrumentation
Attachment #8698579 - Attachment is patch: false
Russ, Piwei mentioned that the app continues to crash even after reboot.  Would this mean that there's something cached in terms of the bad data that makes it continue to crash?  ie is there some sort of temp file that we can delete so that we can get the app to work again?
Flags: needinfo?(rnicoletti)
The workaround is to remove from the sdcard the videos that were most recently recorded (those that were recorded that haven't yet been loaded by the video app). And then to restart the device. I can't explain precisely why the restart is necessary but I've found it helps. Perhaps David would have more to say about that.
Flags: needinfo?(rnicoletti)
Assignee: rnicoletti → dflanagan
Flags: needinfo?(dflanagan)
I think I may understand what is going on here...

The video app is a little different from Gallery and Music in that new videos can be stored in the DB even before their metadata parsing is complete. If this happens, then when we enumerate the DB, we immediately queue those entries for metadata parsing.  This used to work because we didn't enumerate the DB until MediaDB was fully ready.  But now to speed startup time we enumerate the db before MediaDB is fully ready. 

Making that change for Gallery was relatively straightforward because items in the db always had metadata. But for video we have this other case where items can be stored in the db without their metadata.

If this is the problem, it fits with the STR in comment #4. The video app is running in the background, so when we record videos with the camera, the new files are found and added to the DB. But metadata parsing is not done because the background video app doesn't want to grab the video decoding hardware away from the foreground app.  Then we kill the video app before it ever comes to the foreground, so it never does the metadata parsing.

When we start up again, we enumerate the DB quickly, find these videos with no metadata, and try to parse the metadata before MediaDB is ready. MediaDB throws an exception in this case. We don't catch it, and end up in a situation where neither the success or error callbacks are ever called, so the video app thinks it is parsing metadata forever!

If this is what is going on, then the fix will be to defer metadata parsing until the db is ready, and maybe also to add exception handling so we can at least call an error callback.
Comment on attachment 8700465 [details] [review]
[gaia] davidflanagan:bug1229651.2 > mozilla-b2g:master

Punam,

Russ is on PTO until January. Could you review this small patch?

This fixes a smoketest blocker that Russ (and I) caused when making the video app startup go faster. I think the patch should be easy enough to understand in the context of my comment above.

QA really wants to get this bug fixed before releasing an OTA so I think we can count on them to do lots of testing.
Attachment #8700465 - Flags: review?(pdahiya)
Naoki and Pi Wei: can you test this patch and verify that it fixes the bug for you?
Flags: needinfo?(pcheng)
Flags: needinfo?(nhirata.bugzilla)
Flags: needinfo?(pcheng)
Keywords: qawanted
Flags: needinfo?(nhirata.bugzilla) → needinfo?(pcheng)
Naoki and I tested the patch and confirmed that this solves the issue. And I couldn't find any new bugs caused by this patch. Looks good to land.
QA Whiteboard: [severe][MGSEI-Triage+] → [severe][MGSEI-Triage+] [QAnalyst-Triage?]
Flags: needinfo?(pcheng)
Flags: needinfo?(jmercado)
Flags: needinfo?(dflanagan)
Keywords: qawanted
Comment on attachment 8700465 [details] [review]
[gaia] davidflanagan:bug1229651.2 > mozilla-b2g:master

Thanks David for the patch that ensures metadata is parsed only when MediaDB is ready. It looks good and has r+.
Attachment #8700465 - Flags: review?(pdahiya) → review+
Landed on master: https://github.com/mozilla-b2g/gaia/commit/384ebe2e7c7ac368635537c469e19c6837b02ede
Status: NEW → RESOLVED
Closed: 8 years ago
Flags: needinfo?(dflanagan)
Resolution: --- → FIXED
Thanks David, Pi-Wei! Will work to get an update out :)
Comment on attachment 8700750 [details] [review]
[gaia] davidflanagan:bug1229651-v2.5 > mozilla-b2g:v2.5

Mahe approved this for uplift to 2.5 over IRC. Will land as soon as the tests run.
Attachment #8700750 - Flags: approval-gaia-v2.5+
QA Whiteboard: [severe][MGSEI-Triage+] [QAnalyst-Triage?] → [severe][MGSEI-Triage+] [QAnalyst-Triage+]
Flags: needinfo?(jmercado)
This issue is no longer occurring on Flame 2.6 and Aries 2.6. I checked using the steps in Comment 4.

Environmental Variables:
Device: Aries 2.6 [Full Flash]
BuildID: 20151222120532
OTAID: 20151222115357
Gaia: f3cf488a97ecaec43369f3e3d8a7dda52be019f9
Gecko: ad16863d1d45bd3fd7906c76fa1ac1e12d24a133
Gonk: a19052e4389c3ae2d8fc3e7a74a475401baacc56
Version: 46.0a1 (2.6) 
Firmware Version: D5803_23.1.A.1.28_NCB.ftf
User Agent: Mozilla/5.0 (Mobile; rv:46.0) Gecko/46.0 Firefox/46.0

Environmental Variables:
Device: FlameKK 2.6 [Full Flash][512mb]
BuildID: 20151222030233
Gaia: f3cf488a97ecaec43369f3e3d8a7dda52be019f9
Gecko: ad16863d1d45bd3fd7906c76fa1ac1e12d24a133
Gonk: 205ac4204bbbb2098a8046444acba551ba5dc75a
Version: 46.0a1 (2.6) 
Firmware Version: v18D
User Agent: Mozilla/5.0 (Mobile; rv:46.0) Gecko/46.0 Firefox/46.0

Result:
The video app loads correctly after crashing.
QA Whiteboard: [severe][MGSEI-Triage+] [QAnalyst-Triage+] → [severe][MGSEI-Triage+] [QAnalyst-Triage?]
Flags: needinfo?(jmercado)
Status: RESOLVED → VERIFIED
QA Whiteboard: [severe][MGSEI-Triage+] [QAnalyst-Triage?] → [severe][MGSEI-Triage+] [QAnalyst-Triage+]
Flags: needinfo?(jmercado)
Setting verifyme to get this checked on 2.5 as it is blocking for that branch.
Keywords: verifyme
This bug has been verified as "pass" on the latest build of Flame 2.5 and Aries KK 2.5 by the STR in comment 4.

Actual results: Video app launches with the 3 videos that was created at step 3 loaded.
See attachment: verified_Aries_v2.5.3gp
Reproduce rate: 0/10


Device: Flame 2.5_512mb (Pass)
Build ID               20151223152613
Gaia Revision          8db2cdd9eb9b42932c4dfc86d109b3e46c220809
Gaia Date              2015-12-23 13:30:29
Gecko Revision         http://hg.mozilla.org/releases/mozilla-b2g44_v2_5/rev/6fac3536a96a87185a6415d6ae2c36a85612e863
Gecko Version          44.0
Device Name            flame
Firmware(Release)      4.4.2
Firmware(Incremental)  eng.worker.20151223.143931
Firmware Date          Wed Dec 23 14:39:41 UTC 2015
Firmware Version       v18D v4
Bootloader             L1TC000118D0

Device: Aries KK 2.5 (Pass)
Build ID               20151223153111
Gaia Revision          8db2cdd9eb9b42932c4dfc86d109b3e46c220809
Gaia Date              2015-12-23 13:30:29
Gecko Revision         http://hg.mozilla.org/releases/mozilla-b2g44_v2_5/rev/6fac3536a96a87185a6415d6ae2c36a85612e863
Gecko Version          44.0
Device Name            aries
Firmware(Release)      4.4.2
Firmware(Incremental)  eng.worker.20151223.144147
Firmware Date          Wed Dec 23 14:41:54 UTC 2015
Bootloader             s1
patch already landed on 2.5. Updating blocking flag
blocking-b2g: 2.5? → 2.5+
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: