717096 - Crash may occur when switching between webm tab or App and Flash tab (java.lang.IllegalStateException: play() called on uninitialized AudioTrack)

Status: VERIFIED FIXED

(Core :: Audio/Video, defect, P1)

Description

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

Attachment: logcat

1. go to http://http://people.mozilla.com/~nhirata/html_tp/big_buck_bunny_480p.webm
2. play the video
3. go to http://www.cnn.com/video
4. click on the video and play
5. switch between the videos until the videos stop playing

Expected: switching will occur just fine
Actual: eventually you will crash

Note:
Fennec 20120110, Nexus S, Flash 11

01-10 15:45:18.109: W/dalvikvm(1284): threadid=24: thread exiting with uncaught exception (group=0x40015560)
01-10 15:45:18.109: W/PowerManagerService(114): Caller does not have DEVICE_POWER permission.  pid=1284 uid=10053
01-10 15:45:18.113: I/GeckoPluginsAudio(1284): 0x49aa8760 - Write failed -3
01-10 15:45:18.148: W/AudioTrack(1284): obtainBuffer() track 0x3c1da8 disabled, restarting
01-10 15:45:18.210: E/AndroidRuntime(1284): FATAL EXCEPTION: Thread-97
01-10 15:45:18.210: E/AndroidRuntime(1284): java.lang.IllegalStateException: play() called on uninitialized AudioTrack.
01-10 15:45:18.210: E/AndroidRuntime(1284): 	at android.media.AudioTrack.play(AudioTrack.java:824)
01-10 15:45:18.210: E/AndroidRuntime(1284): 	at dalvik.system.NativeStart.run(Native Method)
01-10 15:45:18.253: I/GeckoApp(1284): pause
01-10 15:45:18.253: W/ActivityManager(114):   Force finishing activity org.mozilla.fennec/.App
01-10 15:45:18.332: W/AudioTrack(1284): obtainBuffer() track 0x48aae0 disabled, restarting
01-10 15:45:18.386: D/dalvikvm(1284): GC_EXTERNAL_ALLOC freed 836K, 61% free 3226K/8071K, external 7673K/11670K, paused 122ms
01-10 15:45:18.449: V/RenderScript_jni(198): surfaceCreated
01-10 15:45:18.449: V/RenderScript_jni(198): surfaceChanged
01-10 15:45:18.453: W/AudioTrack(1284): obtainBuffer() track 0x394278 disabled, restarting
01-10 15:45:18.742: I/GeckoApp(1284): stop
01-10 15:45:18.750: I/GeckoApp(1284): destroy

Comment 1

[Brad Lassey [:blassey] (use needinfo?)]

Dougt, do you want to take this since you wrote the audio stuff?

Comment 2

[Doug Turner (:dougt)]

i am not working on these right now.  resetting assignee.

Comment 3

[Kartikaya Gupta (email:[e-mail])]

Fixing title. The ViewRoot exception does occur in the log, but is not the cause of the crash (it was also fixed in bug 715836).

Comment 4

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

Java crash; nom-ing for blocking fennec

Comment 5

[Kevin Brosnan [:kbrosnan]]

Not a top crash, not blocking. Still good to fix though.

Comment 6

[Scoobidiver (away)]

There's one crash in 13.0a1/20120310: bp-9f800e70-a9ee-4bb6-9c09-e25042120310.

Comment 7

[Scoobidiver (away)]

It's #4 top crasher in 13.0a2.

Comment 8

[Chris Peterson [:cpeterson]]

snorp, bon appétit!

Comment 9

[JP Rosevear [:jpr]]

Crashes in 14.0a1 still, #18

Comment 10

[JP Rosevear [:jpr]]

Renoming with topcrash designation.

Comment 11

[Brad Lassey [:blassey] (use needinfo?)]

#18 top crash is not high enough to warrant blocking on

Comment 12

[Sheila Mooney]

You guys can decide if this is blocking or not BUT, it's reproducible, it's at #9 in the past day, #11 in the past 3 days. If was low on the list in the 7 day report because of all the other crashes that were still appearing because people hadn't updated. Because it's reproducible don't you think it warrants some investigation?

Comment 13

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

renoming based on comment 12

Comment 14

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

I ran into this bug by playing a youtube video in fennec, and switching to a different app (google +) by hitting the back button.  I think this might be a more common use case... ie a social app like twitter, facebook, google plus to switch to a website with flash and then switching back.

Comment 15

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

I was thinking of bug 703601 had a similarity, but bug 703601 is marked fixed.

Comment 16

[Gian-Carlo Pascutto [:gcp]]

From what I can see, switching to and from the Flash tab (WebM has nothing to do with this), causes some kind of leak, which causes the AudioTrack to fail to allocate:

E/AudioFlinger( 2597): not enough memory for AudioTrack size=88264
D/MemoryDealer( 2597):   AudioTrack (0xaf4c0, size=1048576)
D/MemoryDealer( 2597):     0: 000af4d8 | 0x00000000 | 0x000158E0 | A 
D/MemoryDealer( 2597):     1: 000af508 | 0x000158E0 | 0x000158E0 | A 
D/MemoryDealer( 2597):     2: 00071248 | 0x0002B1C0 | 0x000158E0 | A 
D/MemoryDealer( 2597):     3: 00081968 | 0x00040AA0 | 0x000158E0 | A 
D/MemoryDealer( 2597):     4: 0007b3d0 | 0x00056380 | 0x000158E0 | A 
D/MemoryDealer( 2597):     5: 00068e30 | 0x0006BC60 | 0x000158E0 | A 
D/MemoryDealer( 2597):     6: 00071a30 | 0x00081540 | 0x000158E0 | A 
D/MemoryDealer( 2597):     7: 00060ea0 | 0x00096E20 | 0x000158E0 | A 
D/MemoryDealer( 2597):     8: 00068bd0 | 0x000AC700 | 0x000158E0 | A 
D/MemoryDealer( 2597):     9: 00060e38 | 0x000C1FE0 | 0x000158E0 | A 
D/MemoryDealer( 2597):    10: 00068a90 | 0x000D78C0 | 0x000158E0 | A 
D/MemoryDealer( 2597):    11: 000cb390 | 0x000ED1A0 | 0x00012E60 | F 
D/MemoryDealer( 2597):   size allocated: 971168 (948 KB)
E/AudioTrack(20444): AudioFlinger could not create track, status: -12
E/AudioTrack-JNI(20444): Error initializing AudioTrack
E/AudioTrack-Java(20444): [ android.media.AudioTrack ] Error code -20 when initializing AudioTrack.

I guess we don't properly check for that in some places and eventually crash. Still digging the code now.

Comment 17

[Chris Peterson [:cpeterson]]

Could we be leaking AudioTracks?

Comment 18

[Gian-Carlo Pascutto [:gcp]]

I've seen no evidence (yet!) that it's AudioTracks specifically that we're leaking, but we're almost certainly leaking *something*.

Comment 19

[Gian-Carlo Pascutto [:gcp]]

I've got some fixes that make the audio plugin code more robust when dealing with errors, and makes it free the internal audio buffers explicitly, as well as fix some bugs like not getting a global ref to a class. After these, we no longer get the crash due to "play called on ...", and you can switch back and forth quite a bit longer...

...however, we're still leaking *somewhere*, and eventually one of the many PushLocalFrame calls we have will generate a: 
W/System.err(21665): java.lang.OutOfMemoryError: out of stack in JNI PushLocalFrame

And we'll die. Our current code doesn't really allow sane error handling in those AutoLocalJNIFrame things.

I don't see evidence that AudioTrack is responsible here. Probably just Flash being Flash or us leaking in interacting with it?

My fix will make this signature go away, but we'll get (slightly less) OOM errors instead.

Comment 20

[Gian-Carlo Pascutto [:gcp]]

Attachment: Patch. Add exception handling, make sure FindClass gets global ref. Release native buffers.

Comment 21

[Brad Lassey [:blassey] (use needinfo?)]

Comment on attachment 621568 [details] [diff] [review]
Patch. Add exception handling, make sure FindClass gets global ref. Release native buffers.

Review of attachment 621568 [details] [diff] [review]:
-----------------------------------------------------------------

r- to get the logic in anp_audio_newTrack cleaned up

::: dom/plugins/base/android/ANPAudio.cpp
@@ +103,5 @@
>  
>  static jclass
>  init_jni_bindings(JNIEnv *jenv) {
> +  jclass jc_local = jenv->FindClass("android/media/AudioTrack");
> +  jclass jc = (jclass)jenv->NewGlobalRef(jc_local);

jclass jc = jclass)jenv->NewGlobalRef(jenv->FindClass("android/media/AudioTrack"));

@@ +278,5 @@
>                                  jformat,
>                                  s->bufferSize,
>                                  MODE_STREAM);
>  
>    jthrowable exception = jenv->ExceptionOccurred();

use a AutoLocalJNIFrame here, it'll avoid a lot of this code goop and the need for a goto

Comment 22

[Gian-Carlo Pascutto [:gcp]]

Attachment: Add exception handling, make sure FindClass gets global ref. Release native buffers.

A goto or code duplication? The duplication is small so let's take the simpler control flow here.

Comment 23

[Gian-Carlo Pascutto [:gcp]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/f18d4a2fce0d

Comment 24

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/f18d4a2fce0d

Comment 25

[Gian-Carlo Pascutto [:gcp]]

Comment on attachment 621620 [details] [diff] [review]
Add exception handling, make sure FindClass gets global ref. Release native buffers.

[Approval Request Comment]
Mobile only. Blocking Fennec. Also likely fixes 746696 which is another blocker.

Comment 26

[Alex Keybl [:akeybl]]

We are leaving all non-beta+ bugs nominated for Aurora approval in the queue until FN14 Beta 1 is signed off on by QA.

Comment 27

[Gian-Carlo Pascutto [:gcp]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/a8a1d8dfba1d

Comment 29

[Cristian Nicolae (:xti)]

This crash doesn't occur anymore on the latest Nightly and Aurora builds. Instead another issue can be noticed and is described in Bug 759830. Closing bug as verified fixed on:

Firefox 15.0a1 (2012-05-30)
Firefox 14.0a2 (2012-05-30)

Device: Galaxy Nexus
OS: Android 4.0.2