1121093 - MOZ_ASSERT(mState == Disabling || mState == Enabling);

Status: RESOLVED WONTFIX

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

Description

[Gregor Wagner [:gwagner]]

Seen on current trunk during monkey testing:

Program received signal SIGSEGV, Segmentation fault.
0xb4da9f28 in mozilla::dom::FMRadioService::Notify (this=<optimized out>, aInfo=...) at ../../../dom/fmradio/FMRadioService.cpp:878
878	      MOZ_ASSERT(mState == Disabling || mState == Enabling);
(gdb) 
(gdb) bt
#0  0xb4da9f28 in mozilla::dom::FMRadioService::Notify (this=<optimized out>, aInfo=...) at ../../../dom/fmradio/FMRadioService.cpp:878
#1  0xb4663148 in Broadcast (aParam=..., this=0xae79e434) at ../dist/include/mozilla/Observer.h:72
#2  mozilla::hal::NotifyFMRadioStatus (aFMRadioState=...) at ../../hal/Hal.cpp:1037
#3  0xb4667092 in mozilla::hal_impl::DisableFMRadio () at ../../hal/gonk/GonkFMRadio.cpp:411
#4  0xb4662114 in mozilla::hal::DisableFMRadio () at ../../hal/Hal.cpp:1070
#5  0xb4dab00c in mozilla::dom::DisableRunnable::Run (this=<optimized out>) at ../../../dom/fmradio/FMRadioService.cpp:261
#6  0xb433b658 in nsThread::ProcessNextEvent (this=0xb6afd320, aMayWait=<optimized out>, aResult=0xbec645bf) at ../../../xpcom/threads/nsThread.cpp:855
#7  0xb434fe00 in NS_ProcessNextEvent (aThread=0xb6afd320, aMayWait=aMayWait@entry=false) at /Volumes/2mac/moz/ib2g/xpcom/glue/nsThreadUtils.cpp:265
#8  0xb4504724 in mozilla::ipc::MessagePump::Run (this=0xb6ae4160, aDelegate=0xb26b71a0) at ../../../ipc/glue/MessagePump.cpp:99
#9  0xb44f0f90 in MessageLoop::RunInternal (this=this@entry=0xb26b71a0) at ../../../ipc/chromium/src/base/message_loop.cc:233
#10 0xb44f0faa in RunHandler (this=0xb26b71a0) at ../../../ipc/chromium/src/base/message_loop.cc:226
#11 MessageLoop::Run (this=0xb26b71a0) at ../../../ipc/chromium/src/base/message_loop.cc:200
#12 0xb5116212 in nsBaseAppShell::Run (this=0xb293a5e0) at ../../widget/nsBaseAppShell.cpp:164
#13 0xb554a7e6 in nsAppStartup::Run (this=0xb29760a0) at ../../../../toolkit/components/startup/nsAppStartup.cpp:281
#14 0xb55680e6 in XREMain::XRE_mainRun (this=this@entry=0xbec64750) at ../../../toolkit/xre/nsAppRunner.cpp:4141
#15 0xb55682e4 in XREMain::XRE_main (this=this@entry=0xbec64750, argc=argc@entry=1, argv=argv@entry=0xb6a2b190, aAppData=aAppData@entry=0xb6f31858 <_ZL8sAppData>)
    at ../../../toolkit/xre/nsAppRunner.cpp:4217
#16 0xb556845e in XRE_main (argc=1, argv=0xb6a2b190, aAppData=0xb6f31858 <_ZL8sAppData>, aFlags=<optimized out>) at ../../../toolkit/xre/nsAppRunner.cpp:4437
#17 0xb6f16126 in do_main (argc=argc@entry=1, argv=argv@entry=0xb6a2b190) at ../../../b2g/app/nsBrowserApp.cpp:165
#18 0xb6f16262 in b2g_main (argc=argc@entry=1, argv=argv@entry=0xbec65a24) at ../../../b2g/app/nsBrowserApp.cpp:293
#19 0xb6f15f90 in RunProcesses (aReservedFds=..., argv=0xbec65a24, argc=1) at ../../../b2g/app/B2GLoader.cpp:225
#20 main (argc=1, argv=0xbec65a24) at ../../../b2g/app/B2GLoader.cpp:290

Comment 1

[Hema Koka [:hema]]

Any idea why?

Thanks
Hema

Comment 2

[Michael Wu [:mwu]]

What device?

Comment 3

[Gregor Wagner [:gwagner]]

Flame

Comment 4

[Pin Zhang [:pzhang] (inactive)]

Is it possible to reproduce this issue? Any logs?

Comment 5

[Hema Koka [:hema]]

adding qawanted to help reproduce and provide logs.

thanks!

Comment 6

[Dave Hylands [:dhylands]]

I'll take a quick look to since I have an idea what the problem might b

Comment 7

[Dave Hylands [:dhylands]]

I took a look at this and something seems to be totally out of whack.

The stack trace shows that DisableRunnable::Run calls DisableFMRadio.

DisableFMRadio then calls NotifyFMRadioStatus and passes in FM_RADIO_OPERATION_DISABLE

However, the ASSERT that's happening is inside the case for FM_RADIO_OPERATION_ENABLE not DISABLE.

The other bizarre thing, is that DisableFMRadio sets sRadioEnabled to false, which means that the assert on line 877 MOZ_ASSERT(IsFMRadioOn()); should have fired and didn't.

gwagner: Is this still happening?

If so, can I send you a logging patch so that we can collect some more information?

Comment 8

[Gregor Wagner [:gwagner]]

(In reply to Dave Hylands [:dhylands] from comment #7)
> I took a look at this and something seems to be totally out of whack.
> 
> The stack trace shows that DisableRunnable::Run calls DisableFMRadio.
> 
> DisableFMRadio then calls NotifyFMRadioStatus and passes in
> FM_RADIO_OPERATION_DISABLE
> 
> However, the ASSERT that's happening is inside the case for
> FM_RADIO_OPERATION_ENABLE not DISABLE.
> 
> The other bizarre thing, is that DisableFMRadio sets sRadioEnabled to false,
> which means that the assert on line 877 MOZ_ASSERT(IsFMRadioOn()); should
> have fired and didn't.
> 
> gwagner: Is this still happening?
> 
> If so, can I send you a logging patch so that we can collect some more
> information?

This happened during random monkey testing so its hard to say if it still reproduces. I can definitely add a logging patch and do more random testing in the radio app.

Comment 9

[Pin Zhang [:pzhang] (inactive)]

Since Dave has taken this issue, clear r? on me.

Comment 10

[Hema Koka [:hema]]

Dave is going to provide a logging patch to Gregor to see if he can reproduce this again with some extra logging. (leaving Ni for dave for the logging patch)

Once we have that info, please renom for 2.2 if the crash still happens. 

THanks
Hema

Comment 11

[Gregor Wagner [:gwagner]]

Today I hit something similar:
Program received signal SIGSEGV, Segmentation fault.
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
0xb4d09624 in mozilla::dom::FMRadioService::Notify (this=<optimized out>, aInfo=...) at ../../../dom/fmradio/FMRadioService.cpp:877
877	      MOZ_ASSERT(IsFMRadioOn());
(gdb) [Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
b[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
t
#0  0xb4d09624 in mozilla::dom::FMRadioService::Notify (this=<optimized out>, aInfo=...) at ../../../dom/fmradio/FMRadioService.cpp:877
#1  0xb458920e in Broadcast (aParam=..., this=0xae87aa14) at ../dist/include/mozilla/Observer.h:72
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
#2  mozilla::hal::NotifyFMRadioStatus (aFMRadioState=...) at ../../hal/Hal.cpp:1037
#3  0xb458d362 in mozilla::hal_impl::RadioUpdate::Run (this=0xaa7135c0) at ../../hal/gonk/GonkFMRadio.cpp:101
#4  0xb425bfe0 in nsThread::ProcessNextEvent (this=0xb6afe320, aMayWait=<optimized out>, aResult=0xbe812837) at ../../../xpcom/threads/nsThread.cpp:855
#5  0xb4271070 in NS_ProcessNextEvent (aThread=0xb6afe320, aMayWait=aMayWait@entry=true) at /Volumes/2mac/moz/ib2g/xpcom/glue/nsThreadUtils.cpp:265
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
#6  0xb4426b52 in mozilla::ipc::MessagePump::Run (this=0xb25c3160, aDelegate=0xb25bb1a0) at ../../../ipc/glue/MessagePump.cpp:140
#7  0xb4412980 in MessageLoop::RunInternal (this=this@entry=0xb25bb1a0) at ../../../ipc/chromium/src/base/message_loop.cc:233
#8  0xb441299a in RunHandler (this=0xb25bb1a0) at ../../../ipc/chromium/src/base/message_loop.cc:226
#9  MessageLoop::Run (this=0xb25bb1a0) at ../../../ipc/chromium/src/base/message_loop.cc:200
#10 0xb5097b16 in nsBaseAppShell::Run (this=0xb2774340) at ../../widget/nsBaseAppShell.cpp:164
[Child 2063] WARNING: Transparent content with displayports can be expensive.: file ../../../layout/base/nsDisplayList.cpp, line 1662
#11 0xb54d42e2 in nsAppStartup::Run (this=0xb6ab2610) at ../../../../toolkit/components/startup/nsAppStartup.cpp:281
#12 0xb54f1d96 in XREMain::XRE_mainRun (this=this@entry=0xbe8129c0) at ../../../toolkit/xre/nsAppRunner.cpp:4160
#13 0xb54f1f94 in XREMain::XRE_main (this=this@entry=0xbe8129c0, argc=argc@entry=1, argv=argv@entry=0xb6a2b190, aAppData=aAppData@entry=0xb6f8d858 <_ZL8sAppData>) at ../../../toolkit/xre/nsAppRunner.cpp:4236
#14 0xb54f210e in XRE_main (argc=1, argv=0xb6a2b190, aAppData=0xb6f8d858 <_ZL8sAppData>, aFlags=<optimized out>) at ../../../toolkit/xre/nsAppRunner.cpp:4456
#15 0xb6f72126 in do_main (argc=argc@entry=1, argv=argv@entry=0xb6a2b190) at ../../../b2g/app/nsBrowserApp.cpp:167
#16 0xb6f72262 in b2g_main (argc=argc@entry=1, argv=argv@entry=0xbe813c94) at ../../../b2g/app/nsBrowserApp.cpp:299
#17 0xb6f71f90 in RunProcesses (aReservedFds=..., argv=0xbe813c94, argc=1) at ../../../b2g/app/B2GLoader.cpp:225
#18 main (argc=1, argv=0xbe813c94) at ../../../b2g/app/B2GLoader.cpp:290

Comment 12

[Dave Hylands [:dhylands]]

Attachment: Logging patch

Here's a logging patch that may shed some more light.

I'd really like to see the logcat output with the threads identified (so adb logcat -v threadtime)

Comment 13

[Gregor Wagner [:gwagner]]

Attachment: radio.txt

Comment 14

[Gregor Wagner [:gwagner]]

I am still seeing this crash. Any updates Dave?

Comment 15

[Dave Hylands [:dhylands]]

Sorry - I've been distracted with other issues.

I'm hoping I'll be able to get back to this by the end of the week.

Comment 16

[Dave Hylands [:dhylands]]

Hmm. The attached radio.txt appears to be truncated and doesn't include the assertion failure.

Comment 17

[Gregor Wagner [:gwagner]]

Attachment: radio2.txt

Lets try again

Comment 18

[Dave Hylands [:dhylands]]

I figured out the problem (or a problem anyways).

The radion is failing to be initialized, as evidenced by these messages:

> 05-05 20:04:05.560  9725  9725 I qcom-fm : /system/etc/init.qcom.fm.sh: In FM shell Script 
> 05-05 20:04:05.570  9726  9726 I qcom-fm : /system/etc/init.qcom.fm.sh: mode: normal 
> 05-05 20:04:05.580  9727  9727 I qcom-fm : /system/etc/init.qcom.fm.sh: isAnalog:  
> 05-05 20:04:05.590  9728  9728 I qcom-fm : /system/etc/init.qcom.fm.sh: Transport : smd 
> 05-05 20:04:05.610  9729  9729 I qcom-fm : /system/etc/init.qcom.fm.sh: Version : 197632 
> 05-05 20:04:05.620  9730  9730 I qcom-fm : /system/etc/init.qcom.fm.sh: inserting the radio transport module 
> 05-05 20:04:06.690  9734  9734 E qcom-fm : /system/etc/init.qcom.fm.sh: FM QSoC firmware download and/or calibration failed: exit code 255 

This then causes a failure in the initMsmFMRadio function, which causes it to return early, leaving sRadioEnabled set to false.

runMsmFMRadio then detects that sRadioEnabled is not set and it sends a failure notification:
https://dxr.mozilla.org/mozilla-central/source/hal/gonk/GonkFMRadio.cpp#242-243

This then gets fielded here:
https://dxr.mozilla.org/mozilla-central/source/dom/fmradio/FMRadioService.cpp#879

which is asserting without checking aInfo.status() to see if the enable suceeded or not.

That covers the assert from both radio.txt and radio2.txt, and doesn't explain the assert in the title. I'm going to leave myself as ni? so I don't forget to try and create a patch.

Comment 19

[Dave Hylands [:dhylands]]

Attachment: Deal with Radio HW initialization failure.

GonkFMRadio has return a failure status on Enable and Seek, so I added checks to these 2 to have it report the failures up the chain.

Comment 20

[Dave Hylands [:dhylands]]

Gregor, I attached a patch to deal with the IsFMRadioOn assert. I'm not sure if it will deal with the other assert (in the title).

Could you try this out?

Comment 21

[Pi Wei Cheng [:piwei] (inactive)]

Excluding this bug in QAnalysts query as we're not equipped to run monkey tests.

Comment 22

[Dave Hylands [:dhylands]]

Not working on FxOS any more, so removing myself as assignee

Comment 23

[Dave Hylands [:dhylands]]

fmradio is being removed from the hal, so I'm clearing the ni flag.

Comment 24

[BMO Automation]

Firefox OS is not being worked on