1265062 - B2G_DEBUG=1 for pine/kanikani does not boot: Assertion failure: originAttrsLoadInfo.mInIsolatedMozBrowser == loadContextIsInBE

Status: RESOLVED WONTFIX

(Firefox OS Graveyard :: General, defect)

Description

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

Attachment: logout.txt

1. build with B2G_DEBUG=1 ./build.sh -j1
2. after compile, ./flash.sh

Expected: bootable OS
Actual: keeps looking like it reboots.

Gecko (pine) :	e97ee27bce20
Gaia ( kanikani ) :	13bf75f40aa8ac8285acbb715d5156f14a70b047

Comment 1

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

I think it might be due to the following assert?  I'm not sure:

04-15 10:11:52.390 I/Gecko   (  319): ++DOMWINDOW == 5 (0xa9930400) [pid = 319] [serial = 5] [outer = 0xac207c00]
04-15 10:11:52.610 F/MOZ_Assert(  319): Assertion failure: originAttrsLoadInfo.mInIsolatedMozBrowser == loadContextIsInBE (The value of InIsolatedMozBrowser in the loadContext and in the loadInfo are not the same!), at /Projects/B2G_Aries_pine/pine/netwerk/base/nsNetUtil.cpp:2418
04-15 10:11:52.610 W/google-breakpad(  319): ExceptionHandler::GenerateDump cloned child 
04-15 10:11:52.610 W/google-breakpad(  319): 1141nAttrsLoadInfo.mInIs
04-15 10:11:52.610 W/google-breakpad(  319): 
04-15 10:11:52.610 W/google-breakpad(  319): ExceptionHandler::SendContinueSignalToChild sent continue signal to child
04-15 10:11:52.610 W/google-breakpad( 1141): ExceptionHandler::WaitForContinueSignal waiting for continue signal...
04-15 10:11:53.010 I/ServiceManager(  286): service 'android.security.keystore' died
04-15 10:11:53.010 I/ServiceManager(  286): service 'SurfaceFlinger' died
04-15 10:11:53.010 I/ServiceManager(  286): service 'permission' died
04-15 10:11:53.010 I/ServiceManager(  286): service 'display.qservice' died
04-15 10:11:53.360 E/sensorsd( 1038): recvmsg failed: Connection reset by peer
04-15 10:11:53.360 I/ServiceManager(  286): service 'media.audio_flinger' died
04-15 10:11:53.360 I/ServiceManager(  286): service 'media.player' died
04-15 10:11:53.360 I/ServiceManager(  286): service 'media.camera' died
04-15 10:11:53.360 I/ServiceManager(  286): service 'listen.service' died
04-15 10:11:53.360 I/ServiceManager(  286): service 'media.audio_policy' died

Comment 2

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

Attachment: manualbuildlog.txt

including build log.

Comment 3

[:gerard-majax]

Well I am starting to think this is the same root cause as bug 1262180 and bug 1264655 except I have no idea why for now :/

Comment 4

[:gerard-majax]

Also reproduced on mulet with debug build. It is not loading at all anymore :/

Comment 5

[:gerard-majax]

Attachment: rr backtrace

Comment 6

[:gerard-majax]

That check was introduced in bug 1125916

Comment 7

[:gerard-majax]

> (rr) print originAttrsLoadInfo
> $10 = {<mozilla::dom::OriginAttributesDictionary> = {<mozilla::dom::DictionaryBase> = {mIsAnyMemberPresent = false}, mAddonId = {<nsAString_internal> = {mData = 0x7f9f7b3b4f3c <gNullChar> u"", mLength = 0, mFlags = 1}, <No data fields>}, mAppId = 0, 
>     mInIsolatedMozBrowser = false, mSignedPkg = {<nsAString_internal> = {mData = 0x7f9f7b3b4f3c <gNullChar> u"", mLength = 0, mFlags = 1}, <No data fields>}, mUserContextId = 0}, <No data fields>}
> (rr) print loadContextIsInBE
> $11 = true
> (rr) print originAttrsLoadInfo.mInIsolatedMozBrowser 
> $12 = false

Comment 8

[:gerard-majax]

Christoph, I suspect there is something bad going on with the channels we are building/manipulating at some point, and this would result in inconsistent load info. Do you have any idea where I should check deeper/investigate? Thanks!

Comment 9

[:gerard-majax]

Maybe Dragana would know more? Any help is welcome :)

Comment 10

[:gerard-majax]

Disabling OOP does not help :/

Comment 11

[Dragana Damjanovic [:dragana]]

I had a short look at this, I think this is going to hit all not just b2g.

Comment 12

[:gerard-majax]

(In reply to Dragana Damjanovic [:dragana] from comment #11)
> I had a short look at this, I think this is going to hit all not just b2g.

Hit every platform? Just to be clear, I don't think you are breaking anything but rather exposing earlier the issue we have in bug 1262180 and bug 1264655 :)

Comment 13

[Christoph Kerschbaumer [:ckerschb]]

What you could do is the following: Find out where the channel is created and most importantly what arguments are used for NS_NewChannel. The best way to do this is print the URL of the channel (channel->GetURI(getter_Addrefs(tmpURI));) shortly before the assertion is triggered.

Once you have the URI of the channel you can set a breakpoint within nsIOService::NewChannelFromURIWithProxyFlagsInternal when that specific URI is created and work your way backwards scrolling through the stacktrace.

Once you have that you can compare the info in the loadContext and loadInfo and maybe we can find out where the code diverges. Does that make sense to you?

We have similar problems elsewhere, e.g. Bug 1264230 and also Bug 1264231. Once we have figured the problem for one of those bugs, most likely we can apply the same (or at least similar) fix to the other related bugs.

Comment 14

[:gerard-majax]

Thanks, I'll look into this !

Comment 15

[:gerard-majax]

> nsIOService::NewChannelFromURIWithProxyFlagsInternal(): URI@0x7f8d6c8ed500 channel@0x7ffeb90a1ab0 aURI=file:///home/alex/codaz/Mozilla/b2g/gaia/profile/apps/system/style/system/initlogo.css
> nsIOService::NewChannelFromURIWithProxyFlagsInternal(): URI@0x7f8d65a43e00 channel@0x7ffeb90a1e10 aURI=chrome://gaia/content/system/style/system/initlogo.css
> NS_CompareLoadInfoAndLoadContext(): Will assert isolation for URI@0x7ffeb90a1fc8 aChannel@0x7f8d6e840250 aChannel: file:///home/alex/codaz/Mozilla/b2g/gaia/profile/apps/system/style/system/initlogo.css
> Assertion failure: originAttrsLoadInfo.mInIsolatedMozBrowser == loadContextIsInBE (The value of InIsolatedMozBrowser in the loadContext and in the loadInfo are not the same!), at /home/alex/codaz/Mozilla/gecko-cinnabar/netwerk/base/nsNetUtil.cpp:2424

So we are asserting when manipulating the channel of "file:///home/alex/codaz/Mozilla/b2g/gaia/profile/apps/system/style/system/initlogo.css"

Comment 16

[:gerard-majax]

Attachment: rr backtrace of matching channel

This is the backtrace in rr after tracking the channel allocated. We can see the loadInfo comes from |nsIOService::NewChannelFromURIWithProxyFlags2|.

Comment 17

[:gerard-majax]

Comment on attachment 8742298 [details]
rr backtrace of matching channel

>Breakpoint 1, nsIOService::NewChannelFromURIWithProxyFlagsInternal (this=this@entry=0x7f8da2bacc80, aURI=aURI@entry=0x7f8d84ed9620, aProxyURI=aProxyURI@entry=0x0, aProxyFlags=aProxyFlags@entry=0, aLoadInfo=<optimized out>, 
>    result=result@entry=0x7ffeb90a1ea8) at /home/alex/codaz/Mozilla/gecko-cinnabar/netwerk/base/nsIOService.cpp:849
>849	    channel.forget(result);
>(rr) bt
>#0  0x00007f8d9382dce3 in nsIOService::NewChannelFromURIWithProxyFlagsInternal(nsIURI*, nsIURI*, unsigned int, nsILoadInfo*, nsIChannel**) (this=this@entry=0x7f8da2bacc80, aURI=aURI@entry=0x7f8d84ed9620, aProxyURI=aProxyURI@entry=0x0, aProxyFlags=aProxyFlags@entry=0, aLoadInfo=<optimized out>, result=result@entry=0x7ffeb90a1ea8) at /home/alex/codaz/Mozilla/gecko-cinnabar/netwerk/base/nsIOService.cpp:849
>#1  0x00007f8d93833bb3 in nsIOService::NewChannelFromURIWithProxyFlags2(nsIURI*, nsIURI*, unsigned int, nsIDOMNode*, nsIPrincipal*, nsIPrincipal*, unsigned int, unsigned int, nsIChannel**) (this=0x7f8da2bacc80, aURI=0x7f8d84ed9620, aProxyURI=aProxyURI@entry=0x0, aProxyFlags=aProxyFlags@entry=0, aLoadingNode=<optimized out>, aLoadingPrincipal=0x7f8d90bfde20, aTriggeringPrincipal=0x0, aSecurityFlags=8, aContentPolicyType=2, result=0x7ffeb90a1ea8)
>    at /home/alex/codaz/Mozilla/gecko-cinnabar/netwerk/base/nsIOService.cpp:894
>#2  0x00007f8d93833c02 in nsIOService::NewChannelFromURI2(nsIURI*, nsIDOMNode*, nsIPrincipal*, nsIPrincipal*, unsigned int, unsigned int, nsIChannel**) (this=<optimized out>, aURI=<optimized out>, aLoadingNode=<optimized out>, aLoadingPrincipal=<optimized out>, aTriggeringPrincipal=<optimized out>, aSecurityFlags=<optimized out>, aContentPolicyType=2, result=0x7ffeb90a1ea8) at /home/alex/codaz/Mozilla/gecko-cinnabar/netwerk/base/nsIOService.cpp:671
>#3  0x00007f8d9381900d in NS_NewChannelInternal(nsIChannel**, nsIURI*, nsINode*, nsIPrincipal*, nsIPrincipal*, unsigned int, unsigned int, nsILoadGroup*, nsIInterfaceRequestor*, unsigned int, nsIIOService*) (outChannel=outChannel@entry=0x7ffeb90a2550, aUri=aUri@entry=0x7f8d84ed9620, aLoadingNode=aLoadingNode@entry=
>    0x0, aLoadingPrincipal=aLoadingPrincipal@entry=0x7f8d90bfde20, aTriggeringPrincipal=aTriggeringPrincipal@entry=0x0, aSecurityFlags=aSecurityFlags@entry=8, aContentPolicyType=2, aLoadGroup=0x0, aCallbacks=0x0, aLoadFlags=0, aIoService=0x7f8da2bacc80)
>    at /home/alex/codaz/Mozilla/gecko-cinnabar/netwerk/base/nsNetUtil.inl:179
>#4  0x00007f8d938191c0 in NS_NewChannel(nsIChannel**, nsIURI*, nsIPrincipal*, unsigned int, unsigned int, nsILoadGroup*, nsIInterfaceRequestor*, unsigned int, nsIIOService*) (outChannel=outChannel@entry=0x7ffeb90a2550, aUri=aUri@entry=0x7f8d84ed9620, aLoadingPrincipal=aLoadingPrincipal@entry=0x7f8d90bfde20, aSecurityFlags=aSecurityFlags@entry=8, aContentPolicyType=aContentPolicyType@entry=2, aLoadGroup=aLoadGroup@entry=0x0, aCallbacks=0x0, aLoadFlags=0, aIoService=0x7f8da2bacc80)
>    at /home/alex/codaz/Mozilla/gecko-cinnabar/netwerk/base/nsNetUtil.inl:272
>#5  0x00007f8d93dae08e in ComponentLoaderInfo::EnsureScriptChannel() (this=0x7ffeb90a2538) at /home/alex/codaz/Mozilla/gecko-cinnabar/js/xpconnect/loader/mozJSComponentLoader.cpp:243
>#6  0x00007f8d93daf704 in mozJSComponentLoader::ObjectForLocation(ComponentLoaderInfo&, nsIFile*, JS::MutableHandle<JSObject*>, JS::MutableHandle<JSScript*>, char**, bool, JS::MutableHandle<JS::Value>) (this=this@entry=0x7f8da2b95520, aInfo=..., aComponentFile=0x7f8d90b82b40, aObject=..., aTableScript=..., aLocation=aLocation@entry=0x7f8d84efb3d0, aPropagateExceptions=false, aException=...) at /home/alex/codaz/Mozilla/gecko-cinnabar/js/xpconnect/loader/mozJSComponentLoader.cpp:842
>#7  0x00007f8d93db0087 in mozJSComponentLoader::LoadModule(mozilla::FileLocation&) (this=0x7f8da2b95520, aFile=...) at /home/alex/codaz/Mozilla/gecko-cinnabar/js/xpconnect/loader/mozJSComponentLoader.cpp:372
>#8  0x00007f8d937764d4 in nsComponentManagerImpl::KnownModule::Load() (this=0x7f8d84ebbe80) at /home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/components/nsComponentManager.cpp:861
>#9  0x00007f8d93776568 in nsFactoryEntry::GetFactory() (this=0x7f8d84ef0160) at /home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/components/nsComponentManager.cpp:1896
>#10 0x00007f8d93777182 in nsComponentManagerImpl::CreateInstanceByContractID(char const*, nsISupports*, nsID const&, void**) (this=<optimized out>, aContractID=<optimized out>, aDelegate=0x0, aIID=..., aResult=0x7ffeb90a2748)
>    at /home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/components/nsComponentManager.cpp:1200
>#11 0x00007f8d93775f29 in nsComponentManagerImpl::GetServiceByContractID(char const*, nsID const&, void**) (this=0x7f8da2ba70b0, aContractID=0x7f8d84edb040 "@mozilla.org/b2g/directory-provider;1", aIID=..., aResult=aResult@entry=0x7ffeb90a2848)
>    at /home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/components/nsComponentManager.cpp:1560
>#12 0x00007f8d937acc8e in CallGetService(char const*, nsID const&, void**) (aContractID=<optimized out>, aIID=..., aResult=aResult@entry=0x7ffeb90a2848) at /home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/glue/nsComponentManagerUtils.cpp:69
>#13 0x00007f8d937accad in nsGetServiceByContractID::operator()(nsID const&, void**) const (this=<optimized out>, aIID=..., aInstancePtr=0x7ffeb90a2848) at /home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/glue/nsComponentManagerUtils.cpp:280
>#14 0x00007f8d93763651 in nsDirectoryService::RegisterCategoryProviders() (aIID=..., aGS=..., this=0x7ffeb90a2818) at /home/alex/codaz/Mozilla/gecko-cinnabar/obj-mulet-dbg/dist/include/nsCOMPtr.h:1121
>#15 0x00007f8d93763651 in nsDirectoryService::RegisterCategoryProviders() (aGS=..., this=0x7ffeb90a2818) at /home/alex/codaz/Mozilla/gecko-cinnabar/obj-mulet-dbg/dist/include/nsCOMPtr.h:540
>#16 0x00007f8d93763651 in nsDirectoryService::RegisterCategoryProviders() (this=0x7f8d90bfc740) at /home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/io/nsDirectoryService.cpp:476
>#17 0x00007f8d937a7a40 in NS_InitXPCOM2(nsIServiceManager**, nsIFile*, nsIDirectoryServiceProvider*) (aResult=aResult@entry=0x7f8d90bdd550, aBinDirectory=<optimized out>, aAppFileLocationProvider=<optimized out>)
>    at /home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/build/XPCOMInit.cpp:729
>#18 0x00007f8d937a7c95 in NS_InitXPCOM2(nsIServiceManager**, nsIFile*, nsIDirectoryServiceProvider*) (aResult=aResult@entry=0x7f8d90bdd550, aBinDirectory=<optimized out>, aAppFileLocationProvider=<optimized out>)
>    at /home/alex/codaz/Mozilla/gecko-cinnabar/xpcom/build/XPCOMInit.cpp:782
>#19 0x00007f8d95a974b8 in ScopedXPCOMStartup::Initialize() (this=0x7f8d90bdd550) at /home/alex/codaz/Mozilla/gecko-cinnabar/toolkit/xre/nsAppRunner.cpp:1527
>#20 0x00007f8d95a9ebc4 in XREMain::XRE_main(int, char**, nsXREAppData const*) (this=this@entry=0x7ffeb90a2b48, argc=argc@entry=5, argv=argv@entry=0x7ffeb90a4078, aAppData=aAppData@entry=0x7ffeb90a2d58)
>    at /home/alex/codaz/Mozilla/gecko-cinnabar/toolkit/xre/nsAppRunner.cpp:4433
>#21 0x00007f8d95a9eee0 in XRE_main(int, char**, nsXREAppData const*, uint32_t) (argc=5, argv=0x7ffeb90a4078, aAppData=0x7ffeb90a2d58, aFlags=<optimized out>) at /home/alex/codaz/Mozilla/gecko-cinnabar/toolkit/xre/nsAppRunner.cpp:4543
>#22 0x00000000004059a0 in do_main(int, char**, char**, nsIFile*) (argc=argc@entry=5, argv=argv@entry=0x7ffeb90a4078, envp=envp@entry=0x7ffeb90a40a8, xreDirectory=0x7f8da2b6c780) at /home/alex/codaz/Mozilla/gecko-cinnabar/browser/app/nsBrowserApp.cpp:220
>#23 0x0000000000404dc5 in main(int, char**, char**) (argc=5, argv=0x7ffeb90a4078, envp=0x7ffeb90a40a8) at /home/alex/codaz/Mozilla/gecko-cinnabar/browser/app/nsBrowserApp.cpp:360

Comment 18

[:gerard-majax]

Attachment: rr backtrace of matching channel

Previous one was wrong

Comment 19

[:gerard-majax]

We are building loadInfo here: https://dxr.mozilla.org/mozilla-central/rev/1da1937a9e03154ae7c60089f2dcf5ad9ee20fa3/netwerk/base/nsIOService.cpp#878

Comment 20

[:gerard-majax]

Attachment: segfault trying to print content of loadingNode

Comment 21

[:gerard-majax]

We are entering the creation of loadInfo with aLoadingPrincipal=0x7f8d90bfde20 aTriggeringPrincipal=0x7f8d90bfde20

And at the end of the LoadInfo constructor, we are inheritating the origin attributes: |InheritOriginAttributes(mLoadingPrincipal, mOriginAttributes);|

So does it makes sense we have the same principal as "loading" and "triggering" ? And could we be manipulating the wrong loading principal?

Comment 22

[Christoph Kerschbaumer [:ckerschb]]

(In reply to Alexandre LISSY :gerard-majax from comment #21)
> So does it makes sense we have the same principal as "loading" and
> "triggering" ? And could we be manipulating the wrong loading principal?

Yes, it makes sense (actually most of the time) the loadingPrincipal and the TrigginerPrincipal are identical. Where do we call NS_NewChannel()? Can you post the whole stacktrace? Most likely the loadingPricnipal is the systemPricnipal so that might already provide a hint why the assertion is triggered.

Comment 23

[:gerard-majax]

Isn't the stack in attachment 8742304 [details] good?

Comment 24

[:gerard-majax]

(In reply to Christoph Kerschbaumer [:ckerschb] from comment #22)
> (In reply to Alexandre LISSY :gerard-majax from comment #21)
> > So does it makes sense we have the same principal as "loading" and
> > "triggering" ? And could we be manipulating the wrong loading principal?
> 
> Yes, it makes sense (actually most of the time) the loadingPrincipal and the
> TrigginerPrincipal are identical. Where do we call NS_NewChannel()? Can you
> post the whole stacktrace? Most likely the loadingPricnipal is the
> systemPricnipal so that might already provide a hint why the assertion is
> triggered.

In the stack linked above, the call would come from https://dxr.mozilla.org/mozilla-central/rev/1da1937a9e03154ae7c60089f2dcf5ad9ee20fa3/layout/style/Loader.cpp#1636 |NS_NewChannelWithTriggeringPrincipal()|

Comment 25

[:gerard-majax]

So, after Christoph's suggestion, I checked the call path of LoadSheet(): if I add a call |NS_CompareLoadInfoAndLoadContext(channel);| right after the channel's creation, the assertion gets hit also.

Comment 26

[:gerard-majax]

Marking as fixed-in-pine thanks to workaround in bug 1266064

Comment 27

[Jonas Sicking (:sicking) No longer reading bugmail consistently]

I suggest working with Dragana to figure out why we hit these assertions. They are intended to catch real bugs so just removing them is not a great solution.

Dragana was quite good at tracking down the source of other places where we assert, so deferring to her.

Comment 28

[:gerard-majax]

Might be fixed by bug 1266022, we'll know after m-c => pine merge

Comment 29

[:gerard-majax]

Attachment: gdb stacktrace current m-c merged on pine

I am still hitting this ...

Comment 30

[Reuben Morais [:reuben]]

(In reply to Christoph Kerschbaumer [:ckerschb] from comment #22)
> (In reply to Alexandre LISSY :gerard-majax from comment #21)
> > So does it makes sense we have the same principal as "loading" and
> > "triggering" ? And could we be manipulating the wrong loading principal?
> 
> Yes, it makes sense (actually most of the time) the loadingPrincipal and the
> TrigginerPrincipal are identical. Where do we call NS_NewChannel()? Can you
> post the whole stacktrace? Most likely the loadingPricnipal is the
> systemPricnipal so that might already provide a hint why the assertion is
> triggered.

Yes, the loading principal is the system principal. The document creating the XHR is chrome://gaia/system/index.html. Like Alexandre said, we create the channel passing that document, and in the LoadInfo constructor we inherit the attributes from the system principal.

The loadContext seems to be correct. It's being created back when we create the system app frame here: https://dxr.mozilla.org/mozilla-central/source/b2g/chrome/content/shell.js#367-373

Comment 31

[Reuben Morais [:reuben]]

I'm mentioning XHR because in my tests the assertion is hit from web_manifest_helper.js trying to load https://m.facebook.com/manifest.webapp via XHR.

Comment 32

[:gerard-majax]

Bug 1264231 is about to land, we should check what it gives on a debug build