874165 - Trying to play the Poppit game will periodically either hang or slow down to a crawl

Status: RESOLVED FIXED

(Firefox OS Graveyard :: General, defect)

Description

[Jason Smith [:jsmith]]

Regression on b2g18.

STR

1. Install the Poppit app
2. Try playing the game

Expected

The game should not hang nor hit extremely slow perf.

Actual

The game will slow down to a crawl during usage. Eventually, the app will hang to the point that the entire phone becomes non-functional for a few seconds (even the other hardware buttons won't work, including powering the phone off).

Reproduced this twice. I also know this working quite recently, so something regressed here. Poppit is a heavy user of mp3s, so investigating if this is a decoder regression might be worthwhile.

Comment 1

[Jason Smith [:jsmith]]

Attachment: Logcat on Startup

This is definitely a regression in the decoder. That logcat is crawling with lots of decoder errors.

Comment 2

[Jason Smith [:jsmith]]

Sotaro - Any ideas?

Comment 3

[Sotaro Ikeda [:sotaro]]

(In reply to Jason Smith [:jsmith] from comment #1)
> Created attachment 751780 [details]
> Logcat on Startup
> 
> This is definitely a regression in the decoder. That logcat is crawling with
> lots of decoder errors.

The codec's error log is not a problem. The error log is always printed when the app try to load multiple mp3 files. It is not a regression. At first, try to load hw audio codec and then try to load sw audio codec.

Comment 4

[Sotaro Ikeda [:sotaro]]

(In reply to Jason Smith [:jsmith] from comment #0)

> The game will slow down to a crawl during usage. Eventually, the app will
> hang to the point that the entire phone becomes non-functional for a few
> seconds (even the other hardware buttons won't work, including powering the
> phone off).

Audio codec can not make such kind of defect. It can not hang entire phone. It seems that the problem happens by other reasons.

Comment 5

[Sotaro Ikeda [:sotaro]]

I tried the Poppit on the following url. I can not reproduce the problem. How often does that happen?
http://mozqa.com/webapi-permissions-tests/  

I used leo device with v1-train ROM made from today's source code.

Comment 6

[Jason Smith [:jsmith]]

(In reply to Sotaro Ikeda [:sotaro] from comment #5)
> I tried the Poppit on the following url. I can not reproduce the problem.
> How often does that happen?
> http://mozqa.com/webapi-permissions-tests/  
> 
> I used leo device with v1-train ROM made from today's source code.

Oh. I reproduced this on unagi, not leo.

Comment 7

[Jason Smith [:jsmith]]

Attachment: Full Logcat

Still can reproduce on unagi, although the hang I just got happened during load of the app.

Comment 8

[Jason Smith [:jsmith]]

I am seeing the following in the logcat:

05-20 16:38:28.994: E/GeckoConsole(2534): [JavaScript Warning: "Media resource app://{d093c925-b2e2-485f-9242-6062d56d0dd8}/media/sounds/PrizeMonkey.mp3 could not be decoded." {file: "app://{d093c925-b2e2-485f-9242-6062d56d0dd8}/index.html" line: 0}]
05-20 16:38:29.024: E/GeckoConsole(2534): [JavaScript Warning: "Media resource app://{d093c925-b2e2-485f-9242-6062d56d0dd8}/media/sounds/PrizeMonkey.mp3 could not be decoded." {file: "app://{d093c925-b2e2-485f-9242-6062d56d0dd8}/index.html" line: 0}]
05-20 16:38:29.184: E/GeckoConsole(2534): [JavaScript Error: "uncaught exception: Failed to load resource: media/sounds/PrizeMonkey.mp3"]

Comment 9

[Sotaro Ikeda [:sotaro]]

In attachment 751901 [details], there are a mediaserver crash. It is bug Bug 871018. It start to happen by Bug 860760. And slow down might be caused by Bug 872462.

Comment 10

[Michael Vines [:m1] [:evilmachines]]

Sotaro, why does this bug depend on 874165?

Comment 11

[Andrew Overholt [:overholt]]

(In reply to Michael Vines [:m1] [:evilmachines] from comment #10)
> Sotaro, why does this bug depend on 874165?

Comment 12

[Sotaro Ikeda [:sotaro]]

(In reply to Andrew Overholt [:overholt] from comment #11)
> (In reply to Michael Vines [:m1] [:evilmachines] from comment #10)
> > Sotaro, why does this bug depend on 874165?

Bug 874165 is this bug number. Do you mean 871018 or 872462?

About Bug 871018, attachment 751901 [details] include the crash of Bug 871018. When the crash happens, sometimes mediaserver never restart and all device freeze happened on some devices in the past.

About Bug 872462, from the above I just thought same thing could happen as in 872462. I am going to check about it.

Comment 13

[Sotaro Ikeda [:sotaro]]

(In reply to Jason Smith [:jsmith] from comment #0)
> The game will slow down to a crawl during usage. Eventually, the app will
> hang to the point that the entire phone becomes non-functional for a few
> seconds (even the other hardware buttons won't work, including powering the
> phone off).

It is Bug 871018. By applying Bug 871018, the problem was solved on v1.1 unagi.

Comment 14

[Sotaro Ikeda [:sotaro]]

(In reply to Sotaro Ikeda [:sotaro] from comment #13)
> 
> It is Bug 871018. By applying Bug 871018, the problem was solved on v1.1
> unagi.

Corrction, I saw the problem still by applying Bug 871018. Though Bug 871018 is part of the problem.

Comment 15

[Sotaro Ikeda [:sotaro]]

When only sw audio codes are instantiated in app, the problem did not happen. And when pause() call is disabled, the problems did not happen.

Comment 16

[Sotaro Ikeda [:sotaro]]

It seem that when an audio codec is in remote process(mediaserver), pause() causes the performance problem.

Comment 17

[Sotaro Ikeda [:sotaro]]

current way of OMXCodec::start() and OMXCodec::pause() is different from how android stagefright is doing. And might be bad for OMXCodec.

OMXCodec::start(): expected to call once before start
OMXCodec::pause(): suspend pulling data. resume by a subsequent read-with-seek.

- OMXCodec::start()
http://androidxref.com/4.0.4/xref/frameworks/base/include/media/stagefright/MediaSource.h#39

- OMXCodec::pause()
http://androidxref.com/4.0.4/xref/frameworks/base/include/media/stagefright/MediaSource.h#96

Comment 18

[Sotaro Ikeda [:sotaro]]

CAF's OMXCodec::start() added some code to handle as resume. It is not present in AOSP's OMXCodec::start().

Comment 19

[Sotaro Ikeda [:sotaro]]

(In reply to Sotaro Ikeda [:sotaro] from comment #18)
> CAF's OMXCodec::start() added some code to handle as resume. It is not
> present in AOSP's OMXCodec::start().

CAF's OMXCodec::pause() also added some code to handle as pose. It is not present in AOSP's OMXCodec::pause().

Comment 20

[Sotaro Ikeda [:sotaro]]

Bug 871018 is fixed on hamachi(buri) and leo. By using the devices, I did not see "the entire phone becomes non-functional".

Comment 21

[Sotaro Ikeda [:sotaro]]

But I saw the following problem.
- When app go to background and then move back to front, game's sound becomes sometimes choppy and response becomes bad.

Then I saw similar report in media ML.
https://groups.google.com/forum/?fromgroups#!topic/mozilla.dev.media/UtdelygW4bM

Comment 22

[Sotaro Ikeda [:sotaro]]

I checked threads priorities of the app. Even when app go back to front only main thread's priority change to high priority. Other threads remain law priority.

Comment 23

[Sotaro Ikeda [:sotaro]]

Attachment: Thread priorites of the app at first start

Comment 24

[Sotaro Ikeda [:sotaro]]

Attachment: Threads priorites of the app at first start v2

Remove unnecessary threads.

Comment 25

[Sotaro Ikeda [:sotaro]]

Attachment: Threads priorites of the app since go back to forground

Comment 26

[Sotaro Ikeda [:sotaro]]

:jlebar, do you know why the app's threads' priorities are still low, even when app goes back to forground?

Comment 27

[Justin Lebar (not reading bugmail)]

(In reply to Sotaro Ikeda [:sotaro] from comment #26)
> :jlebar, do you know why the app's threads' priorities are still low, even
> when app goes back to forground?

Wow, that looks like a pretty bad bug.  I'll see if I can reproduce it.

Comment 28

[Justin Lebar (not reading bugmail)]

(In reply to Justin Lebar [:jlebar] from comment #27)
> Wow, that looks like a pretty bad bug.  I'll see if I can reproduce it.

Yeah, that's very, very bad.  Bug 879529.  Thanks, Sotaro.

Comment 29

[Sotaro Ikeda [:sotaro]]

Since Bug 879529 was fixed, this bug seems to be fixed. I created the rom whit a patch of Bug 871018, I did not see the problem.

The patch of Bug 871018 is applied only to hamachi(buri) and leo. Because qualcomm supports only ics_strawberry for v1.1. See Bug 878981.

Comment 30

[Jason Smith [:jsmith]]

Okay. Closing per comment 29. Sounds like bug 878981 is tracking the specific cases other than buri and leo.

Comment 31

[Jason Smith [:jsmith]]

I can confirm comment 29. Poppit runs cleanly now on b2g18 without hangs or slowness.

Comment 32

[:CSchmoeckel]

Added App Suite Test Case #8746 - Verify that 3rd party games can be played without slow down and hangs.