Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Debugging with IPC logging #43

Closed
kenz-gelsoft opened this issue Aug 28, 2024 · 41 comments
Closed

Debugging with IPC logging #43

kenz-gelsoft opened this issue Aug 28, 2024 · 41 comments

Comments

@kenz-gelsoft
Copy link
Owner

kenz-gelsoft commented Aug 28, 2024 •
edited
Loading

Whole log of startup crash without local_hacks to prevent early crash.

export MOZ_IPC_MESSAGE_LOG=1

whole_ipc_log.txt

it's too large to investigate, so I need to identify crash or misbehaviour related actors first.

then I'll re-run with IPC logging specifying to log those actors only.
@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Aug 28, 2024 •
edited
Loading

crash related communication

too long to read on phones 
(/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/firefox:34297): GLib-GIO-WARNING **: 05:58:05.638: Failed to create file monitor for /boot/home/config/settings/glib-2.0/settings/keyfile: Unable to find default local file monitor type
[time: 1724878685657322][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685657381][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685657920][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685657948][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685658676][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685658755][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685659048][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685659244][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685659794][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685659857][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685660027][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685660146][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685660236][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685660338][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685660726][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685661384][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685661588][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685661726][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685661963][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685662073][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685662617][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685663253][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685664443][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685665171][34297->34128] [PContentChild] Sending  PContent::Msg_InitCrashReporter
[time: 1724878685665263][34128->34200] [PContentParent] Sending  PContent::Msg_BlobURLRegistration
[time: 1724878685665291][34128->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_Clone
[time: 1724878685665342][34128<--1] [PRemoteLazyInputStreamParent] Received  PRemoteLazyInputStream::Msg_Clone
[time: 1724878685665367][34128->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_Goodbye
[time: 1724878685665456][34200<-34128] [PContentChild] Received  PContent::Msg_BlobURLRegistration
[time: 1724878685665489][34128<--1] [PRemoteLazyInputStreamParent] Received  PRemoteLazyInputStream::Msg_Goodbye
[default 34128] NOTE: PRemoteLazyInputStreamChild actor received `Goodbye' message.  Closing channel.
[time: 1724878685665715][34128->34297] [PContentParent] Sending  PContent::Msg_BlobURLRegistration
[time: 1724878685665752][34128->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_Clone
[time: 1724878685665803][34128->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_Goodbye
[time: 1724878685665841][34128<--1] [PRemoteLazyInputStreamParent] Received  PRemoteLazyInputStream::Msg_Clone
[time: 1724878685666009][34128<--1] [PRemoteLazyInputStreamParent] Received  PRemoteLazyInputStream::Msg_Goodbye
[default 34128] NOTE: PRemoteLazyInputStreamChild actor received `Goodbye' message.  Closing channel.
[time: 1724878685666288][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685666321][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685667643][34128<-34297] [PContentParent] Received  PContent::Msg_InitCrashReporter
[time: 1724878685667995][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685668026][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685669550][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685669773][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685671138][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685671407][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685672383][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685672557][34297->34128] [PContentChild] Sending  PContent::Msg_PNeckoConstructor
[time: 1724878685673533][34128->34200] [PWindowGlobalParent] Sending  PWindowGlobal::Msg_RawMessage
[time: 1724878685673613][34200<-34128] [PWindowGlobalChild] Received  PWindowGlobal::Msg_RawMessage
[time: 1724878685674200][34128->34200] [PWindowGlobalParent] Sending  PWindowGlobal::Msg_RawMessage
[time: 1724878685674830][34200->34128] [PContentChild] Sending  PContent::Msg_StoreAndBroadcastBlobURLRegistration
[time: 1724878685674988][34200->34128] [PVsyncChild] Sending  PVsync::Msg_Observe
[time: 1724878685675341][34128<-34297] [PContentParent] Received  PContent::Msg_PNeckoConstructor
[time: 1724878685676407][34128<-34200] [PContentParent] Received  PContent::Msg_StoreAndBroadcastBlobURLRegistration
[time: 1724878685676757][34128<-34200] [PVsyncParent] Received  PVsync::Msg_Observe
[time: 1724878685678206][34297->34128] [PContentChild] Sending  PContent::Msg_PExtensionsConstructor
[time: 1724878685678420][34297->34128] [PContentChild] Sending  PContent::Msg_InitBackground
[time: 1724878685678804][34200->34128] [PWindowGlobalChild] Sending  PWindowGlobal::Msg_SetSingleChannelId
[time: 1724878685679583][34297<-34128] [PContentChild] Received  PContent::Msg_RefreshScreens
[time: 1724878685679622][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685679647][34297<-34128] [PContentChild] Received  PContent::Msg_SetXPCOMProcessAttributes
[time: 1724878685679944][34297->34128] [PBackgroundStarterChild] Sending  PBackgroundStarter::Msg_InitBackground
[time: 1724878685680292][34128<-34297] [PContentParent] Received  PContent::Msg_PExtensionsConstructor
[time: 1724878685680500][34297->34128] [PBackgroundStarterChild] Sending  PBackgroundStarter::Msg_InitBackground
[time: 1724878685680520][34128<-34297] [PContentParent] Received  PContent::Msg_InitBackground
[time: 1724878685680582][34128<-34297] [PBackgroundStarterParent] Received  PBackgroundStarter::Msg_InitBackground
[time: 1724878685680698][34128<-34297] [PBackgroundStarterParent] Received  PBackgroundStarter::Msg_InitBackground
[time: 1724878685680783][34128<-34200] [PWindowGlobalParent] Received  PWindowGlobal::Msg_SetSingleChannelId
[time: 1724878685680940][34200->34128] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDisplayList
[time: 1724878685680981][34200->34128] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetFocusTarget
[time: 1724878685681119][34128<-34200] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetDisplayList
[time: 1724878685681386][34128<-34200] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetFocusTarget
[time: 1724878685681512][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685682045][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685684401][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685684861][34200->34128] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDisplayList
[time: 1724878685684906][34200->34128] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetFocusTarget
[time: 1724878685685022][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685685044][34200<-34128] [PWindowGlobalChild] Received  PWindowGlobal::Msg_RawMessage
[time: 1724878685685048][34128<-34200] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetDisplayList
[time: 1724878685685514][34128<-34200] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetFocusTarget
[time: 1724878685685854][34200->34128] [PWindowGlobalChild] Sending  PWindowGlobal::Msg_SetSingleChannelId
[time: 1724878685685894][34200->34128] [PNeckoChild] Sending  PNecko::Msg_RemoveRequestContext
Fontconfig warning: ignoring en_US_POSIX.UTF-8: not a valid region tag
[time: 1724878685686040][34200->34128] [PCompositorManagerChild] Sending  PCompositorManager::Msg_AddSharedSurface
[time: 1724878685686131][34128<-34200] [PCompositorManagerParent] Received  PCompositorManager::Msg_AddSharedSurface
[time: 1724878685686337][34297<-34128] [PContentChild] Received  PContent::Msg_UpdateSharedData
[time: 1724878685686372][34297<-34128] [PContentChild] Received  PContent::Msg_UpdateSharedData
[time: 1724878685686465][34297<-34128] [PContentChild] Received  PContent::Msg_RegisterChrome
[time: 1724878685686842][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685686931][34297<-34128] [PContentChild] Received  PContent::Msg_RegisterStringBundles
[time: 1724878685686933][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685686961][34297<-34128] [PContentChild] Received  PContent::Msg_AppInfo
[time: 1724878685686979][34297<-34128] [PContentChild] Received  PContent::Msg_RemoteType
[time: 1724878685687028][34297<-34128] [PContentChild] Received  PContent::Msg_PScriptCacheConstructor
[time: 1724878685687068][34297->34128] [PScriptCacheChild] Sending  PScriptCache::Msg___delete__
[time: 1724878685687400][34297->34128] [PBackgroundStarterChild] Sending  PBackgroundStarter::Msg_InitBackground
[time: 1724878685687420][34297->34128] [PBackgroundChild] Sending  PBackground::Msg_PRemoteWorkerServiceConstructor
[34128] Hit MOZ_CRASH(adding native font failed: file=/boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular. err=1) at gfx/wr/wr_glyph_rasterizer/src/platform/unix/font.rs:399
[time: 1724878685687822][34128<-34297] [PBackgroundStarterParent] Received  PBackgroundStarter::Msg_InitBackground
[time: 1724878685687873][34128<-34297] [PBackgroundParent] Received  PBackground::Msg_PRemoteWorkerServiceConstructor
[time: 1724878685688200][34128<-34200] [PWindowGlobalParent] Received  PWindowGlobal::Msg_SetSingleChannelId
[time: 1724878685688242][34128<-34200] [PNeckoParent] Received  PNecko::Msg_RemoveRequestContext
[time: 1724878685688832][34128<-34297] [PScriptCacheParent] Received  PScriptCache::Msg___delete__
[time: 1724878685689468][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685689572][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685690285][34128->34200] [PCompositorBridgeParent] Sending  PCompositorBridge::Msg_DidComposite
[time: 1724878685690387][34200<-34128] [PCompositorBridgeChild] Received  PCompositorBridge::Msg_DidComposite
[time: 1724878685691431][34200->34128] [PCompositorManagerChild] Sending  PCompositorManager::Msg_AddSharedSurface
[time: 1724878685691528][34128<-34200] [PCompositorManagerParent] Received  PCompositorManager::Msg_AddSharedSurface
[time: 1724878685691844][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685692182][34200->34128] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDisplayList
[time: 1724878685692223][34200->34128] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetFocusTarget
[time: 1724878685692312][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685692367][34128<-34200] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetDisplayList
[time: 1724878685692777][34128<-34200] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetFocusTarget
[time: 1724878685694094][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685694309][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685696569][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685696644][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685696789][34297<-34128] [PContentChild] Received  PContent::Msg_LoadProcessScript
[time: 1724878685698162][34297<-34128] [PContentChild] Received  PContent::Msg_LoadProcessScript
[time: 1724878685698895][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685698970][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685701273][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685701396][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685703683][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685703807][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685706028][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685706159][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685706867][34297<-34128] [PContentChild] Received  PContent::Msg_NotifyProcessPriorityChanged
[time: 1724878685706909][34297<-34128] [PContentChild] Received  PContent::Msg_InitRendering
[time: 1724878685706952][34297->34128] [PCompositorManagerChild] Sending  PCompositorManager::Msg_PCompositorBridgeConstructor
[time: 1724878685707079][34128<-34297] [PCompositorManagerParent] Received  PCompositorManager::Msg_PCompositorBridgeConstructor
[time: 1724878685707184][34297<-34128] [PContentChild] Received  PContent::Msg_SetPermissionsWithKey
[time: 1724878685707421][34297<-34128] [PContentChild] Received  PContent::Msg_InitBlobURLs
[time: 1724878685707639][34297<-34128] [PContentChild] Received  PContent::Msg_InitJSActorInfos
[time: 1724878685707865][34297<-34128] [PContentChild] Received  PContent::Msg_RegisterBrowsingContextGroup
[time: 1724878685707926][34297<-34128] [PContentChild] Received  PContent::Msg_SetInputEventQueueEnabled
[time: 1724878685707942][34297<-34128] [PContentChild] Received  PContent::Msg_SuspendInputEventQueue
[time: 1724878685707951][34297<-34128] [PContentChild] Received  PContent::Msg_FlushInputEventQueue
[time: 1724878685707960][34297<-34128] [PContentChild] Received  PContent::Msg_ResumeInputEventQueue
[time: 1724878685707969][34297<-34128] [PContentChild] Received  PContent::Msg_InitProcessHangMonitor
[time: 1724878685708019][34297<-34128] [PContentChild] Received  PContent::Msg_InitProfiler
[time: 1724878685708029][34297<-34128] [PContentChild] Received  PContent::Msg_GMPsChanged
[time: 1724878685708195][34297<-34128] [PContentChild] Received  PContent::Msg_InitNextGenLocalStorageEnabled
[time: 1724878685708238][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685708386][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685708415][34297<-34128] [PContentChild] Received  PContent::Msg_ConstructBrowser
[time: 1724878685708518][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685708972][34297->34128] [PBackgroundChild] Sending  PBackground::Msg_PClientManagerConstructor
[time: 1724878685709037][34128<-34297] [PBackgroundParent] Received  PBackground::Msg_PClientManagerConstructor
[time: 1724878685709116][34297->34128] [PClientManagerChild] Sending  PClientManager::Msg_PClientSourceConstructor
[time: 1724878685709162][34128<-34297] [PClientManagerParent] Received  PClientManager::Msg_PClientSourceConstructor
[time: 1724878685709191][34297->34128] [PClientSourceChild] Sending  PClientSource::Msg_ExecutionReady
[time: 1724878685709236][34128<-34297] [PClientSourceParent] Received  PClientSource::Msg_ExecutionReady
[time: 1724878685709469][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685709501][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685709656][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685709938][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685710719][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685710816][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685710932][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685710949][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685711062][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685711187][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685711232][34128->34128] [PBackgroundIDBTransactionChild] Sending  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685711258][34128<-34128] [PBackgroundIDBTransactionParent] Received  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685711285][34128->34128] [PBackgroundIDBTransactionParent] Sending  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685711403][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685711428][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685711455][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685711523][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685711696][34297->34128] [PWindowGlobalChild] Sending  PWindowGlobal::Msg_UpdateCookieJarSettings
[time: 1724878685712066][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685712103][34128->34128] [PBackgroundIDBTransactionChild] Sending  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685712128][34128<-34128] [PBackgroundIDBTransactionParent] Received  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685712149][34128->34128] [PBackgroundIDBTransactionParent] Sending  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685712288][34128<-34128] [PBackgroundIDBTransactionChild] Received  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685712939][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685712982][34128->34128] [PBackgroundIDBTransactionChild] Sending  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685713056][34128<-34128] [PBackgroundIDBTransactionParent] Received  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685713142][34128->34128] [PBackgroundIDBTransactionParent] Sending  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685713325][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685713427][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685713820][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685713848][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685713898][34297->34128] [PContentChild] Sending  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685713961][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685713982][34297->34128] [PContentChild] Sending  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685714042][34297->34128] [PWindowGlobalChild] Sending  PWindowGlobal::Msg_SetClientInfo
[time: 1724878685714059][34297->34128] [PClientSourceChild] Sending  PClientSource::Msg_ExecutionReady
[time: 1724878685714068][34128<-34128] [PBackgroundIDBTransactionChild] Received  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685714084][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685714106][34128<-34297] [PClientSourceParent] Received  PClientSource::Msg_ExecutionReady
[time: 1724878685714751][34128<-34128] [PBackgroundIDBTransactionChild] Received  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685714953][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_PVsyncConstructor
[time: 1724878685714993][34297->34128] [PVsyncChild] Sending  PVsync::Msg_Observe
[time: 1724878685715269][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_PSessionStoreConstructor
[time: 1724878685715299][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_RemoteIsReadyToHandleInputEvents
[time: 1724878685715339][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685715361][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685715383][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_InitRendering
[time: 1724878685715432][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_UpdateContentCache
[time: 1724878685715537][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_SafeAreaInsetsChanged
[time: 1724878685715623][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685715730][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_Show
[time: 1724878685715757][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685715779][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685715787][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685715791][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_LoadURL
[time: 1724878685715880][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685715899][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685715895][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685715930][34297->34128] [PContentChild] Sending  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685715988][34128<-34297] [PWindowGlobalParent] Received  PWindowGlobal::Msg_UpdateCookieJarSettings
[time: 1724878685716000][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685716027][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685716073][34128->34128] [PBackgroundIDBTransactionChild] Sending  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685716099][34128<-34128] [PBackgroundIDBTransactionParent] Received  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685716121][34128<-34297] [PContentParent] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685716125][34128->34128] [PBackgroundIDBTransactionParent] Sending  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685716162][34297->34128] [PWindowGlobalChild] Sending  PWindowGlobal::Msg_SetSingleChannelId
[time: 1724878685716223][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_OnStateChange
[time: 1724878685716249][34297->34128] [PExtensionsChild] Sending  PExtensions::Msg_StateChange
[time: 1724878685716302][34128<-34297] [PContentParent] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685716305][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685716329][34128<-34297] [PWindowGlobalParent] Received  PWindowGlobal::Msg_SetClientInfo
[time: 1724878685716368][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685716387][34297->34128] [PNeckoChild] Sending  PNecko::Msg_PDocumentChannelConstructor
[time: 1724878685716429][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_UpdateDimensions
[time: 1724878685716454][34297<-34128] [PContentChild] Received  PContent::Msg_RegisterBrowsingContextGroup
[time: 1724878685716483][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685716496][34297<-34128] [PContentChild] Received  PContent::Msg_ConstructBrowser
[time: 1724878685716550][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_PVsyncConstructor
[time: 1724878685716589][34128<-34297] [PVsyncParent] Received  PVsync::Msg_Observe
[time: 1724878685716673][34128->34297] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685716730][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_PSessionStoreConstructor
[time: 1724878685716768][34297->34128] [PClientManagerChild] Sending  PClientManager::Msg_PClientSourceConstructor
[time: 1724878685716793][34297->34128] [PClientSourceChild] Sending  PClientSource::Msg_ExecutionReady
[time: 1724878685716820][34128<-34297] [PClientManagerParent] Received  PClientManager::Msg_PClientSourceConstructor
[time: 1724878685716838][34128<-34297] [PClientSourceParent] Received  PClientSource::Msg_ExecutionReady
[time: 1724878685716904][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685716930][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685716959][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_RemoteIsReadyToHandleInputEvents
[time: 1724878685717003][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_UpdateContentCache
[time: 1724878685717024][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685717031][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685717042][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685717061][34128->34128] [PBackgroundIDBTransactionChild] Sending  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685717084][34128<-34128] [PBackgroundIDBTransactionParent] Received  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685717110][34128->34128] [PBackgroundIDBTransactionParent] Sending  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685717111][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685717147][34128<-34297] [PContentParent] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685717167][34128<-34128] [PBackgroundIDBTransactionChild] Received  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685717657][34128<-34297] [PWindowGlobalParent] Received  PWindowGlobal::Msg_SetSingleChannelId
[time: 1724878685717680][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_OnStateChange
[time: 1724878685718413][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685718484][34128<-34297] [PExtensionsParent] Received  PExtensions::Msg_StateChange
[time: 1724878685718524][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685718555][34297->34128] [PWindowGlobalChild] Sending  PWindowGlobal::Msg_UpdateCookieJarSettings
[time: 1724878685718687][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685718717][34128<-34297] [PNeckoParent] Received  PNecko::Msg_PDocumentChannelConstructor
[time: 1724878685718938][34128->34128] [PClientManagerChild] Sending  PClientManager::Msg_ExpectFutureClientSource
[time: 1724878685718967][34128<-34128] [PClientManagerParent] Received  PClientManager::Msg_ExpectFutureClientSource
[time: 1724878685718989][34128->34297] [PContentParent] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685719318][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685719345][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685719404][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685719444][34128->34128] [PBackgroundIDBTransactionChild] Sending  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685719468][34128<-34128] [PBackgroundIDBTransactionParent] Received  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685719479][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685719489][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685719504][34128->34128] [PBackgroundIDBTransactionParent] Sending  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685719517][34128<-34128] [PBackgroundIDBTransactionChild] Received  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685719956][34297->34128] [PContentChild] Sending  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685720024][34297->34128] [PContentChild] Sending  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685720071][34297->34128] [PWindowGlobalChild] Sending  PWindowGlobal::Msg_SetClientInfo
[time: 1724878685720089][34297->34128] [PClientSourceChild] Sending  PClientSource::Msg_ExecutionReady
[time: 1724878685720111][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685720130][34128->34128] [PBackgroundIDBCursorChild] Sending  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685720134][34128<-34297] [PClientSourceParent] Received  PClientSource::Msg_ExecutionReady
[time: 1724878685720167][34128<-34128] [PBackgroundIDBCursorParent] Received  PBackgroundIDBCursor::Msg_Continue
[time: 1724878685720194][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_PVsyncConstructor
[time: 1724878685720215][34297->34128] [PVsyncChild] Sending  PVsync::Msg_Observe
[time: 1724878685720263][34128->34128] [PBackgroundIDBCursorParent] Sending  PBackgroundIDBCursor::Msg_Response
[time: 1724878685720357][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_PSessionStoreConstructor
[time: 1724878685720379][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_RemoteIsReadyToHandleInputEvents
[time: 1724878685720467][34297<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685720855][34128->34297] [PDocumentChannelParent] Sending  PDocumentChannel::Msg_RedirectToRealChannel
[time: 1724878685720964][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685721037][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685721080][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685721087][34128->34128] [PBackgroundIDBTransactionChild] Sending  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685721123][34128<-34128] [PBackgroundIDBTransactionParent] Received  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685721160][34128<-34128] [PBackgroundIDBTransactionChild] Received  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685721164][34128->34128] [PBackgroundIDBTransactionParent] Sending  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685721435][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685721451][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685721463][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_InitRendering
[time: 1724878685721471][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_UpdateContentCache
[time: 1724878685721497][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_SafeAreaInsetsChanged
[time: 1724878685721516][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685721542][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_Show
[time: 1724878685721559][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685721570][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_LoadURL
[time: 1724878685721639][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685721653][34128<-34297] [PWindowGlobalParent] Received  PWindowGlobal::Msg_UpdateCookieJarSettings
[time: 1724878685721664][34297->34128] [PContentChild] Sending  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685721693][34128<-34297] [PContentParent] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685721723][34128<-34297] [PContentParent] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685721742][34128<-34297] [PWindowGlobalParent] Received  PWindowGlobal::Msg_SetClientInfo
[time: 1724878685721763][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685721791][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_PVsyncConstructor
[time: 1724878685721794][34297->34128] [PWindowGlobalChild] Sending  PWindowGlobal::Msg_SetSingleChannelId
[time: 1724878685721816][34128<-34297] [PVsyncParent] Received  PVsync::Msg_Observe
[time: 1724878685721836][34128<-34128] [PBackgroundIDBCursorChild] Received  PBackgroundIDBCursor::Msg_Response
[time: 1724878685721842][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_OnStateChange
[time: 1724878685721870][34297->34128] [PExtensionsChild] Sending  PExtensions::Msg_StateChange
[time: 1724878685721875][34128->34128] [PBackgroundIDBTransactionChild] Sending  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685721902][34128<-34128] [PBackgroundIDBTransactionParent] Received  PBackgroundIDBTransaction::Msg_Commit
[time: 1724878685721916][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685721924][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_PSessionStoreConstructor
[time: 1724878685721931][34128->34128] [PBackgroundIDBTransactionParent] Sending  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685721950][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_RemoteIsReadyToHandleInputEvents
[time: 1724878685721973][34128<-34128] [PBackgroundIDBTransactionChild] Received  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685721972][34297->34128] [PNeckoChild] Sending  PNecko::Msg_PDocumentChannelConstructor
[time: 1724878685722012][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_UpdateDimensions
[time: 1724878685722032][34297<-34128] [PContentChild] Received  PContent::Msg_RegisterBrowsingContextGroup
[time: 1724878685722053][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685722064][34297<-34128] [PContentChild] Received  PContent::Msg_ConstructBrowser
[time: 1724878685722370][34297->34128] [PClientManagerChild] Sending  PClientManager::Msg_PClientSourceConstructor
[time: 1724878685722396][34297->34128] [PClientSourceChild] Sending  PClientSource::Msg_ExecutionReady
[time: 1724878685722422][34128<-34297] [PClientManagerParent] Received  PClientManager::Msg_PClientSourceConstructor
[time: 1724878685722428][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_UpdateContentCache
[time: 1724878685722441][34128<-34297] [PClientSourceParent] Received  PClientSource::Msg_ExecutionReady
[time: 1724878685722459][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685722484][34128<-34297] [PContentParent] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685722505][34128<-34297] [PWindowGlobalParent] Received  PWindowGlobal::Msg_SetSingleChannelId
[time: 1724878685722523][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_OnStateChange
[time: 1724878685722673][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685722798][34128<-34297] [PExtensionsParent] Received  PExtensions::Msg_StateChange
[time: 1724878685722884][34128<-34128] [PBackgroundIDBTransactionChild] Received  PBackgroundIDBTransaction::Msg_Complete
[time: 1724878685723692][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685723798][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685723805][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685723836][34128<-34297] [PNeckoParent] Received  PNecko::Msg_PDocumentChannelConstructor
[time: 1724878685724085][34128->34128] [PClientManagerChild] Sending  PClientManager::Msg_ExpectFutureClientSource
[time: 1724878685724117][34128<-34128] [PClientManagerParent] Received  PClientManager::Msg_ExpectFutureClientSource
[time: 1724878685724270][34297->34128] [PWindowGlobalChild] Sending  PWindowGlobal::Msg_UpdateCookieJarSettings
[time: 1724878685724486][34128->34297] [PContentParent] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685724652][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685725012][34128->34297] [PDocumentChannelParent] Sending  PDocumentChannel::Msg_RedirectToRealChannel
[time: 1724878685725699][34297->34128] [PContentChild] Sending  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685725797][34297->34128] [PContentChild] Sending  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685725940][34297->34128] [PWindowGlobalChild] Sending  PWindowGlobal::Msg_SetClientInfo
[time: 1724878685725985][34297->34128] [PClientSourceChild] Sending  PClientSource::Msg_ExecutionReady
[time: 1724878685726045][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685726103][34128<-34297] [PClientSourceParent] Received  PClientSource::Msg_ExecutionReady
[time: 1724878685726151][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_PVsyncConstructor
[time: 1724878685726177][34297->34128] [PVsyncChild] Sending  PVsync::Msg_Observe
[time: 1724878685726303][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685726315][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_PSessionStoreConstructor
[time: 1724878685726339][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_RemoteIsReadyToHandleInputEvents
[time: 1724878685726376][34128<-34297] [PWindowGlobalParent] Received  PWindowGlobal::Msg_UpdateCookieJarSettings
[time: 1724878685726378][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685726397][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685726410][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_InitRendering
[time: 1724878685726411][34128<-34297] [PContentParent] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685726417][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_UpdateContentCache
[time: 1724878685726414][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685726445][34128<-34297] [PContentParent] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685726455][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_SafeAreaInsetsChanged
[time: 1724878685726472][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685726500][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_Show
[time: 1724878685726502][34128<-34297] [PWindowGlobalParent] Received  PWindowGlobal::Msg_SetClientInfo
[time: 1724878685726523][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685726531][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685726534][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_LoadURL
[time: 1724878685726559][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_PVsyncConstructor
[time: 1724878685726584][34128<-34297] [PVsyncParent] Received  PVsync::Msg_Observe
[time: 1724878685726602][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_PSessionStoreConstructor
[time: 1724878685726603][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685726624][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_RemoteIsReadyToHandleInputEvents
[time: 1724878685726626][34297->34128] [PContentChild] Sending  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685726642][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_UpdateContentCache
[time: 1724878685726673][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685726699][34128<-34297] [PContentParent] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685726793][34297->34128] [PWindowGlobalChild] Sending  PWindowGlobal::Msg_SetSingleChannelId
[time: 1724878685726835][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_OnStateChange
[time: 1724878685726861][34297->34128] [PExtensionsChild] Sending  PExtensions::Msg_StateChange
[time: 1724878685726902][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685726951][34297->34128] [PNeckoChild] Sending  PNecko::Msg_PDocumentChannelConstructor
[time: 1724878685726981][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_UpdateDimensions
[time: 1724878685727001][34297<-34128] [PContentChild] Received  PContent::Msg_RegisterBrowsingContextGroup
[time: 1724878685727030][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685727041][34297<-34128] [PContentChild] Received  PContent::Msg_ConstructBrowser
[time: 1724878685727138][34128->34200] [PContentParent] Sending  PContent::Msg_RegisterStringBundles
[time: 1724878685727180][34128->34297] [PContentParent] Sending  PContent::Msg_RegisterStringBundles
[time: 1724878685727223][34200<-34128] [PContentChild] Received  PContent::Msg_RegisterStringBundles
[time: 1724878685727249][34128<-34297] [PWindowGlobalParent] Received  PWindowGlobal::Msg_SetSingleChannelId
[time: 1724878685727278][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_OnStateChange
[time: 1724878685727325][34297->34128] [PClientManagerChild] Sending  PClientManager::Msg_PClientSourceConstructor
[time: 1724878685727350][34297->34128] [PClientSourceChild] Sending  PClientSource::Msg_ExecutionReady
[time: 1724878685727377][34128<-34297] [PClientManagerParent] Received  PClientManager::Msg_PClientSourceConstructor
[time: 1724878685727396][34128<-34297] [PClientSourceParent] Received  PClientSource::Msg_ExecutionReady
[time: 1724878685727617][34128<-34297] [PExtensionsParent] Received  PExtensions::Msg_StateChange
[time: 1724878685727622][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685727710][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685727737][34128<-34297] [PNeckoParent] Received  PNecko::Msg_PDocumentChannelConstructor
[time: 1724878685727933][34128->34128] [PClientManagerChild] Sending  PClientManager::Msg_ExpectFutureClientSource
[time: 1724878685727965][34128<-34128] [PClientManagerParent] Received  PClientManager::Msg_ExpectFutureClientSource
[time: 1724878685727987][34128->34297] [PContentParent] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685728201][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685728814][34128->34297] [PDocumentChannelParent] Sending  PDocumentChannel::Msg_RedirectToRealChannel
[time: 1724878685728926][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685729053][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685729194][34297->34128] [PWindowGlobalChild] Sending  PWindowGlobal::Msg_UpdateCookieJarSettings
[time: 1724878685729306][34128->34200] [PContentParent] Sending  PContent::Msg_RegisterStringBundles
[time: 1724878685729363][34128->34297] [PContentParent] Sending  PContent::Msg_RegisterStringBundles
[time: 1724878685729373][34200<-34128] [PContentChild] Received  PContent::Msg_RegisterStringBundles
[time: 1724878685729711][34128->34200] [PContentParent] Sending  PContent::Msg_RegisterStringBundles
[time: 1724878685729748][34128->34297] [PContentParent] Sending  PContent::Msg_RegisterStringBundles
[time: 1724878685729820][34200<-34128] [PContentChild] Received  PContent::Msg_RegisterStringBundles
[time: 1724878685730017][34128->34200] [PContentParent] Sending  PContent::Msg_RegisterStringBundles
[time: 1724878685730054][34128->34297] [PContentParent] Sending  PContent::Msg_RegisterStringBundles
[time: 1724878685730122][34200<-34128] [PContentChild] Received  PContent::Msg_RegisterStringBundles
[time: 1724878685730369][34128->34200] [PContentParent] Sending  PContent::Msg_RegisterStringBundles
[time: 1724878685730411][34128->34297] [PContentParent] Sending  PContent::Msg_RegisterStringBundles
[time: 1724878685730426][34200<-34128] [PContentChild] Received  PContent::Msg_RegisterStringBundles
[time: 1724878685730932][34297->34128] [PContentChild] Sending  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685731032][34297->34128] [PContentChild] Sending  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685731163][34297->34128] [PWindowGlobalChild] Sending  PWindowGlobal::Msg_SetClientInfo
[time: 1724878685731209][34297->34128] [PClientSourceChild] Sending  PClientSource::Msg_ExecutionReady
[time: 1724878685731296][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685731327][34128<-34297] [PClientSourceParent] Received  PClientSource::Msg_ExecutionReady
[time: 1724878685731380][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_PVsyncConstructor
[time: 1724878685731402][34297->34128] [PVsyncChild] Sending  PVsync::Msg_Observe
[time: 1724878685731533][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_PSessionStoreConstructor
[time: 1724878685731556][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_RemoteIsReadyToHandleInputEvents
[time: 1724878685731628][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685731643][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685731655][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_InitRendering
[time: 1724878685731662][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_UpdateContentCache
[time: 1724878685731687][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_SafeAreaInsetsChanged
[time: 1724878685731702][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685731727][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_Show
[time: 1724878685731744][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685731754][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_LoadURL
[time: 1724878685731816][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685731840][34297->34128] [PContentChild] Sending  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685731939][34297->34128] [PWindowGlobalChild] Sending  PWindowGlobal::Msg_SetSingleChannelId
[time: 1724878685731978][34297->34128] [PBrowserChild] Sending  PBrowser::Msg_OnStateChange
[time: 1724878685732005][34297->34128] [PExtensionsChild] Sending  PExtensions::Msg_StateChange
[time: 1724878685732046][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685732095][34297->34128] [PNeckoChild] Sending  PNecko::Msg_PDocumentChannelConstructor
[time: 1724878685732097][34128->34200] [PContentParent] Sending  PContent::Msg_RegisterStringBundles
[time: 1724878685732124][34297<-34128] [PBrowserChild] Received  PBrowser::Msg_UpdateDimensions
[time: 1724878685732143][34297<-34128] [PContentChild] Received  PContent::Msg_RegisterBrowsingContextGroup
[time: 1724878685732153][34128->34297] [PContentParent] Sending  PContent::Msg_RegisterStringBundles
[time: 1724878685732168][34297<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685732165][34200<-34128] [PContentChild] Received  PContent::Msg_RegisterStringBundles
[time: 1724878685732180][34297<-34128] [PContentChild] Received  PContent::Msg_ConstructBrowser
[time: 1724878685732304][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685732375][34128<-34297] [PWindowGlobalParent] Received  PWindowGlobal::Msg_UpdateCookieJarSettings
[time: 1724878685732377][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685732410][34128<-34297] [PContentParent] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685732436][34128<-34297] [PContentParent] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685732459][34128<-34297] [PWindowGlobalParent] Received  PWindowGlobal::Msg_SetClientInfo
[time: 1724878685732482][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685732491][34297->34128] [PClientManagerChild] Sending  PClientManager::Msg_PClientSourceConstructor
[time: 1724878685732513][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_PVsyncConstructor
[time: 1724878685732514][34297->34128] [PClientSourceChild] Sending  PClientSource::Msg_ExecutionReady
[time: 1724878685732550][34128<-34297] [PVsyncParent] Received  PVsync::Msg_Observe
[time: 1724878685732587][34128<-34297] [PClientManagerParent] Received  PClientManager::Msg_PClientSourceConstructor
[time: 1724878685732591][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_PSessionStoreConstructor
[time: 1724878685732614][34128<-34297] [PClientSourceParent] Received  PClientSource::Msg_ExecutionReady
[time: 1724878685732636][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_RemoteIsReadyToHandleInputEvents
[time: 1724878685732686][34128->34297] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685732778][34128->34297] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685732778][34297->34128] [PContentChild] Sending  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685732853][34128->34297] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685732936][34128->34297] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685732986][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_UpdateContentCache
[time: 1724878685733009][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878685733031][34128<-34297] [PContentParent] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878685733051][34128<-34297] [PWindowGlobalParent] Received  PWindowGlobal::Msg_SetSingleChannelId
[time: 1724878685733068][34128<-34297] [PBrowserParent] Received  PBrowser::Msg_OnStateChange
[time: 1724878685733359][34128<-34297] [PExtensionsParent] Received  PExtensions::Msg_StateChange
#01: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa956d46]
#02: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa956b3f]
#03: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa95679c]
#04: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb2687c3]
#05: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb25a254]
#06: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb25a049]
#07: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb268367]
[time: 1724878685733444][34128<-34297] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
#08: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb28e5b3]
#09: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa7430b5]
#10: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa740c58]
[time: 1724878685733472][34128<-34297] [PNeckoParent] Received  PNecko::Msg_PDocumentChannelConstructor
#11: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa73519e]
#12: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb1f2815]
#13: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb1f012d]
#14: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb1edfda]
#15: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb1ee781]
#16: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb26ad2b]
#17: pthread_exit[/boot/system/lib/libroot.so +0x4e528]
#18: ??? (???:???)

@kenz-gelsoft
Copy link
Owner Author

communicate with pid=-1???

[time: 1724878683762591][34128->34254] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878683762636][34128->34254] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878683762680][34128->34254] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878683762724][34128->34254] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878683762769][34128->34254] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878683765088][34128->34200] [PContentParent] Sending  PContent::Msg_BlobURLRegistration
[time: 1724878683765109][34128->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_Clone
[time: 1724878683765202][34128<--1] [PRemoteLazyInputStreamParent] Received  PRemoteLazyInputStream::Msg_Clone
[time: 1724878683765225][34128->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_Goodbye
[time: 1724878683765294][34200<-34128] [PContentChild] Received  PContent::Msg_BlobURLRegistration
[time: 1724878683765482][34128<--1] [PRemoteLazyInputStreamParent] Received  PRemoteLazyInputStream::Msg_Goodbye
[default 34128] NOTE: PRemoteLazyInputStreamChild actor received `Goodbye' message.  Closing channel.
[time: 1724878683765716][34128->34254] [PContentParent] Sending  PContent::Msg_BlobURLRegistration
[time: 1724878683765755][34128->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_Clone
[time: 1724878683765872][34128<--1] [PRemoteLazyInputStreamParent] Received  PRemoteLazyInputStream::Msg_Clone
[time: 1724878683765972][34128->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_Goodbye
[time: 1724878683766010][34128<--1] [PRemoteLazyInputStreamParent] Received  PRemoteLazyInputStream::Msg_Goodbye
[default 34128] NOTE: PRemoteLazyInputStreamChild actor received `Goodbye' message.  Closing channel.
[time: 1724878683769941][34128<-34200] [PVsyncParent] Received  PVsync::Msg_Observe
[time: 1724878683770001][34128<-34200] [PWindowGlobalParent] Received  PWindowGlobal::Msg_RawMessage
[time: 1724878683774607][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878683774689][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878683774729][34128->34254] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878683774836][34128->34254] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878683774924][34128->34254] [PVsyncParent] Sending  PVsync::Msg_Notify

@kenz-gelsoft
Copy link
Owner Author

Child process 34254 starting communication with pid=-1 around here

[time: 1724878683802898][34254<-34128] [PWindowGlobalChild] Received  PWindowGlobal::Msg___delete__
[time: 1724878683802904][34254<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878683802912][34254<-34128] [PContentChild] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878683802918][34254<-34128] [PContentChild] Received  PContent::Msg_HistoryCommitIndexAndLength
[time: 1724878683802926][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683802964][34254->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_StreamNeeded
[time: 1724878683802968][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683802998][34254<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878683803008][34254<-34128] [PWindowGlobalChild] Received  PWindowGlobal::Msg___delete__
[time: 1724878683803016][34254<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878683803015][34254->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_StreamNeeded
[time: 1724878683803028][34254<-34128] [PContentChild] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878683803036][34254<-34128] [PContentChild] Received  PContent::Msg_HistoryCommitIndexAndLength
[time: 1724878683803046][34254<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878683803054][34254<-34128] [PWindowGlobalChild] Received  PWindowGlobal::Msg___delete__
[time: 1724878683803061][34254<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878683803069][34254<-34128] [PContentChild] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878683803076][34254<-34128] [PContentChild] Received  PContent::Msg_HistoryCommitIndexAndLength
[time: 1724878683803082][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803101][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803117][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803133][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803129][34128<--1] [PRemoteLazyInputStreamParent] Received  PRemoteLazyInputStream::Msg_StreamNeeded
[time: 1724878683803153][34254<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878683803162][34254<-34128] [PWindowGlobalChild] Received  PWindowGlobal::Msg___delete__
[time: 1724878683803170][34254<-34128] [PContentChild] Received  PContent::Msg_CommitBrowsingContextTransaction
[time: 1724878683803178][34254<-34128] [PContentChild] Received  PContent::Msg_CommitWindowContextTransaction
[time: 1724878683803185][34254<-34128] [PContentChild] Received  PContent::Msg_HistoryCommitIndexAndLength
[time: 1724878683803192][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803208][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803211][34128->-1] [PRemoteLazyInputStreamParent] Sending reply  PRemoteLazyInputStream::Reply_StreamNeeded
[time: 1724878683803222][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803237][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803253][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803257][34128<--1] [PRemoteLazyInputStreamParent] Received  PRemoteLazyInputStream::Msg_StreamNeeded
[time: 1724878683803277][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803294][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803298][34128->-1] [PRemoteLazyInputStreamParent] Sending reply  PRemoteLazyInputStream::Reply_StreamNeeded
[time: 1724878683803309][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803323][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803338][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803352][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803352][34254->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_StreamNeeded
[time: 1724878683803370][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803386][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream

especially request pid=-1 more data(stream) but, maybe it no data there (as invalid pid)

[time: 1724878683803441][34128<--1] [PRemoteLazyInputStreamParent] Received  PRemoteLazyInputStream::Msg_StreamNeeded
[time: 1724878683803488][34128->-1] [PRemoteLazyInputStreamParent] Sending reply  PRemoteLazyInputStream::Reply_StreamNeeded
[time: 1724878683803388][34254->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_StreamNeeded
[time: 1724878683803402][34254<-34128] [PNeckoChild] Received  PNecko::Reply_GetExtensionStream
[time: 1724878683803581][34254->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_StreamNeeded
[time: 1724878683803672][34128<--1] [PRemoteLazyInputStreamParent] Received  PRemoteLazyInputStream::Msg_StreamNeeded
[time: 1724878683803719][34128->-1] [PRemoteLazyInputStreamParent] Sending reply  PRemoteLazyInputStream::Reply_StreamNeeded
[time: 1724878683803755][34128<--1] [PRemoteLazyInputStreamParent] Received  PRemoteLazyInputStream::Msg_StreamNeeded
[time: 1724878683803784][34128->-1] [PRemoteLazyInputStreamParent] Sending reply  PRemoteLazyInputStream::Reply_StreamNeeded
[time: 1724878683803829][34254->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_StreamNeeded

finally we got Message needs unreceived descriptors message here

[Child 34254, IPC I/O Child] WARNING: Message needs unreceived descriptors channel:1189bbb54b60 message-type:8126467 header()->num_handles:1 num_fds:1 fds_i:1: file /boot/home/src/gecko-dev/ipc/chromium/src/chrome/common/ipc_channel_posix.cc:467
[Parent 34128, IPC I/O Parent] WARNING: [1.1]: Dropping message '<null>'; no connection to unknown peer CBE651AE7B8C6872.A93413533EA9ED56: file /boot/home/src/gecko-dev/ipc/glue/NodeController.cpp:365
[Parent 34128, BackgroundThreadPool #1] WARNING: IPC Connection Error: [Parent][PRemoteLazyInputStreamParent] RunMessage(msgname=PRemoteLazyInputStream::Msg_StreamNeeded) Channel error: cannot send/recv: file /boot/home/src/gecko-dev/ipc/glue/MessageChannel.cpp:1943
[time: 1724878683804351][34254->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_StreamNeeded
[Child 34254, IPC I/O Child] WARNING: [CBE651AE7B8C6872.A93413533EA9ED56]: Dropping message '<null>'; no connection to unknown peer 1.1: file /boot/home/src/gecko-dev/ipc/glue/NodeController.cpp:365
[time: 1724878683804378][34254->34128] [PBrowserChild] Sending  PBrowser::Msg_DidUnsuppressPainting

after that, IPC errors starting with this child

[Child 34254, RemoteLzyStream] WARNING: IPC Connection Error: [Child][PRemoteLazyInputStreamChild] Send(msgname=PRemoteLazyInputStream::Msg_StreamNeeded) Channel error: cannot send/recv: file /boot/home/src/gecko-dev/ipc/glue/MessageChannel.cpp:1943
[Child 34254, RemoteLzyStream] WARNING: SendStreamNeeded rejected: file /boot/home/src/gecko-dev/dom/file/ipc/RemoteLazyInputStream.cpp:876
[time: 1724878683804428][34254->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_StreamNeeded
[time: 1724878683804484][34254->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_StreamNeeded
[time: 1724878683804523][34254->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_StreamNeeded
[Child 34254, RemoteLzyStream] WARNING: IPC Connection Error: [Child][PRemoteLazyInputStreamChild] RunMessage(msgname=PRemoteLazyInputStream::Reply_StreamNeeded) Channel error: cannot send/recv: file /boot/home/src/gecko-dev/ipc/glue/MessageChannel.cpp:1943
[time: 1724878683804551][34254->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_StreamNeeded
[time: 1724878683804624][34254->34128] [PBrowserChild] Sending  PBrowser::Msg_DidUnsuppressPainting
[time: 1724878683804707][34254->-1] [PRemoteLazyInputStreamChild] Sending  PRemoteLazyInputStream::Msg_StreamNeeded
[Child 34254, RemoteLzyStream] WARNING: IPC Connection Error: [Child][PRemoteLazyInputStreamChild] Send(msgname=PRemoteLazyInputStream::Msg_StreamNeeded) Channel error: cannot send/recv: file /boot/home/src/gecko-dev/ipc/glue/MessageChannel.cpp:1943
Exiting due to channel error.
[Child 34254, RemoteLzyStream] WARNING: SendStreamNeeded rejected: file /boot/home/src/gecko-dev/dom/file/ipc/RemoteLazyInputStream.cpp:876
[time: 1724878685228239][34200->34128] [PNeckoChild] Sending  PNecko::Msg_HTMLDNSPrefetch
[time: 1724878685228306][34200->34128] [PNeckoChild] Sending  PNecko::Msg_HTMLDNSPrefetch
[time: 1724878685386637][34128->34254] [PContentParent] Sending  PContent::Msg_PreferenceUpdate
[Parent 34128, Main Thread] WARNING: IPC Connection Error: [Parent][PContentParent] Send(msgname=PContent::Msg_PreferenceUpdate) Channel error: cannot send/recv: file /boot/home/src/gecko-dev/ipc/glue/MessageChannel.cpp:1943
[time: 1724878685386726][34128->34200] [PContentParent] Sending  PContent::Msg_PreferenceUpdate
[time: 1724878685386844][34200<-34128] [PContentChild] Received  PContent::Msg_PreferenceUpdate
[time: 1724878685387548][34128->34128] [PBackgroundIDBFactoryChild] Sending  PBackgroundIDBFactory::Msg_PBackgroundIDBFactoryRequestConstructor
[time: 1724878685387620][34128<-34128] [PBackgroundIDBFactoryParent] Received  PBackgroundIDBFactory::Msg_PBackgroundIDBFactoryRequestConstructor
[time: 1724878685387866][34128->34200] [PVsyncParent] Sending  PVsync::Msg_Notify
[time: 1724878685387970][34200<-34128] [PVsyncChild] Received  PVsync::Msg_Notify
[time: 1724878685388088][34128->34254] [PVsyncParent] Sending  PVsync::Msg_Notify
[Parent 34128, Main Thread] WARNING: IPC Connection Error: [Parent][PContentParent] Send(msgname=PVsync::Msg_Notify) Channel error: cannot send/recv: file /boot/home/src/gecko-dev/ipc/glue/MessageChannel.cpp:1943
[time: 1724878685388246][34128->34254] [PVsyncParent] Sending  PVsync::Msg_Notify
[Parent 34128, Main Thread] WARNING: IPC Connection Error: [Parent][PContentParent] Send(msgname=PVsync::Msg_Notify) Channel error: cannot send/recv: file /boot/home/src/gecko-dev/ipc/glue/MessageChannel.cpp:1943
[time: 1724878685388321][34128->34254] [PVsyncParent] Sending  PVsync::Msg_Notify
[Parent 34128, Main Thread] WARNING: IPC Connection Error: [Parent][PContentParent] Send(msgname=PVsync::Msg_Notify) Channel error: cannot send/recv: file /boot/home/src/gecko-dev/ipc/glue/MessageChannel.cpp:1943
[time: 1724878685388407][34128->34254] [PVsyncParent] Sending  PVsync::Msg_Notify
[Parent 34128, Main Thread] WARNING: IPC Connection Error: [Parent][PContentParent] Send(msgname=PVsync::Msg_Notify) Channel error: cannot send/recv: file /boot/home/src/gecko-dev/ipc/glue/MessageChannel.cpp:1943

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Aug 28, 2024 •
edited
Loading

https://searchfox.org/mozilla-esr128/source/ipc/glue/ProtocolUtils.cpp#155

IPC logging code

direction doesn't indicate parent/child

  • logging process->peer process
  • logging process<-peer process

indeed, pid=-1 didn't log

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Aug 28, 2024 •
edited
Loading

https://searchfox.org/mozilla-esr128/source/__GENERATED__/__ios__/ipc/ipdl/PDocAccessibleParent.cpp#539

callsite example.

https://searchfox.org/mozilla-esr128/source/ipc/glue/ProtocolUtils.h#539

it may be invalid from name

initalized as invalid

assignments

Read it later

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Aug 29, 2024 •
edited
Loading 

~/src/gecko-dev> export MOZ_IPC_MESSAGE_LOG=PRemoteLazyInputStream
~/src/gecko-dev> export MOZ_LOG=RemoteLazyStream:5
~/src/gecko-dev> ./mach run

ipc_message_and_moz_log.txt

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Aug 30, 2024 •
edited
Loading

It was no problem. Mozilla's IPC code may be used for inter-THREAD communication too. PRemoteLazyInputStream protocol is not tagged with NeedsOtherPid.

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Aug 30, 2024 •
edited
Loading

IPC receive font.rs data from here

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Aug 30, 2024 •
edited
Loading

Check here

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Aug 31, 2024 •
edited
Loading 

[time: 1725069654769452][11489<-11417] [PWebRenderBridgeChild] Received reply  PWebRenderBridge::Reply_EnsureConnected
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/otfonts/NotoSansCJKjp-Regular.otf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/otfonts/NotoSansCJKjp-Regular.otf
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf
[time: 1725069654821618][11489->11417] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDisplayList
[time: 1725069654821642][11489->11417] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetFocusTarget
[time: 1725069654821862][11417<-11489] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetDisplayList
[time: 1725069654822330][11417<-11489] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetFocusTarget
[time: 1725069654871609][11417->11417] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDefaultClearColor
[time: 1725069654871646][11417->11417] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_InvalidateRenderedFrame
[time: 1725069654871646][11417<-11417] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetDefaultClearColor
[time: 1725069654871676][11417<-11417] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_InvalidateRenderedFrame
[time: 1725069654872642][11417->11417] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDefaultClearColor
[time: 1725069654872675][11417<-11417] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetDefaultClearColor
[time: 1725069654872766][11417->11417] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_NewCompositable
[time: 1725069654872791][11417<-11417] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_NewCompositable
WriteFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf(59)
[time: 1725069654879510][11417->11417] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDisplayList

[time: 1725069656040500][11417<-11417] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetFocusTarget
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/otfonts/NotoSansCJKjp-Regular.otf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/otfonts/NotoSansCJKjp-Regular.otf
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf
[time: 1725069656182129][11417->11417] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDisplayList
[time: 1725069656182180][11417<-11417] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetDisplayList
[time: 1725069656182198][11417->11417] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetFocusTarget
[time: 1725069656182601][11417<-11417] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetFocusTarget
WriteFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
[time: 1725069656243776][11417->11417] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDisplayList
[time: 1725069656243822][11417<-11417] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetDisplayList
[time: 1725069656243853][11417->11417] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetFocusTarget
[time: 1725069656244410][11417<-11417] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetFocusTarget
[11417] Hit MOZ_CRASH(called `Result::unwrap()` on an `Err` value: NulError(59, [47, 98, 111, 111, 116, 47, 115, 121, 115, 116, 101, 109, 47, 100, 97, 116, 97, 47, 102, 111, 110, 116, 115, 47, 116, 116, 102, 111, 110, 116, 115, 47, 78, 111, 116, 111, 83, 97, 110, 115, 68, 105, 115, 112, 108, 97, 121, 45, 82, 101, 103, 117, 108, 97, 114, 46, 116, 116, 102, 0])) at gfx/wr/wr_glyph_rasterizer/src/platform/unix/font.rs:225
[time: 1725069656268848][11417->11417] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDisplayList

>>> s = ""
>>> for c in [47, 98, 111, 111, 116, 47, 115, 121, 115, 116, 101, 109, 47, 100, 97, 116, 97, 47, 102, 111, 110, 116, 115, 47, 116, 116, 102, 111, 110, 116, 115, 47, 78, 111, 116, 111, 83, 97, 110, 115, 68, 105, 115, 112, 108, 97, 121, 45, 82, 101, 103, 117, 108, 97, 114, 46, 116, 116, 102, 0]:
...   s += chr(c)
... 
>>> s
'/boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf\x00'

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Aug 31, 2024 •
edited
Loading

Hmm, second write seems not transfered correctly.

[time: 1725078180147054][35794<-35794] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_NewCompositable
WriteFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf(59)
ShmSegmentsWriter::Write: /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf(59)
IpcResourceUpdateQueue::AddFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf(59)
ShmSegmentsWriter::Write: (0)
ShmSegmentsWriter::Write: (0)
[time: 1725078180153937][35794->35794] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDisplayList
[time: 1725078180153964][35794<-35794] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetDisplayList
[time: 1725078180153970][35794->35794] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetFocusTarget
ShmSegmentsReader::Read(ing): remaining=59, { data=/boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf, length=59, capacity=59 }
ShmSegmentsReader::Read:{ data=/boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf, length=59, capacity=59 }
TransactionBuilder::AddFontDescriptor:{ data=/boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf, length=59, capacity=59 }
[time: 1725078180154487][35794<-35794] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetFocusTarget

[time: 1725078181435254][35794<-35794] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetFocusTarget
WriteFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
ShmSegmentsWriter::Write: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
IpcResourceUpdateQueue::AddFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
ShmSegmentsWriter::Write: (0)
ShmSegmentsWriter::Write: (0)
ShmSegmentsWriter::Write: (0)
[time: 1725078181454407][35794->35794] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDisplayList
[time: 1725078181454457][35794->35794] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetFocusTarget
[time: 1725078181454454][35794<-35794] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetDisplayList
ShmSegmentsReader::Read(ing): remaining=60, { data=/boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf, length=60, capacity=60 }
ShmSegmentsReader::Read:{ data=/boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf, length=60, capacity=60 }
TransactionBuilder::AddFontDescriptor:{ data=/boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf, length=60, capacity=60 }
[time: 1725078181455062][35794<-35794] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetFocusTarget
[35794] Hit MOZ_CRASH(called `Result::unwrap()` on an `Err` value: NulError(59, [47, 98, 111, 111, 116, 47, 115, 121, 115, 116, 101, 109, 47, 100, 97, 116, 97, 47, 102, 111, 110, 116, 115, 47, 116, 116, 102, 111, 110, 116, 115, 47, 78, 111, 116, 111, 83, 97, 110, 115, 68, 105, 115, 112, 108, 97, 121, 45, 82, 101, 103, 117, 108, 97, 114, 46, 116, 116, 102, 0])) at gfx/wr/wr_glyph_rasterizer/src/platform/unix/font.rs:225
#01: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa9587c6]

@kenz-gelsoft
Copy link
Owner Author

About ShMem

https://searchfox.org/mozilla-esr128/source/ipc/glue/Shmem.h#22

@kenz-gelsoft
Copy link
Owner Author

Sharing font list from parent to content child process has nothing to do with this issue.

https://searchfox.org/mozilla-esr128/source/gfx/thebes/gfxPlatformFontList.cpp#3059

  • content process is isolated per site, it needs pre-collected font list to determine layout with available fonts and font metrics.

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Aug 31, 2024 •
edited
Loading

By disabling shared memory chunk recycling, parent process won't crash.

diff --git a/gfx/layers/wr/WebRenderBridgeChild.cpp b/gfx/layers/wr/WebRenderBridgeChild.cpp
index 2c5868007a1c..3a2359a883ae 100644
--- a/gfx/layers/wr/WebRenderBridgeChild.cpp
+++ b/gfx/layers/wr/WebRenderBridgeChild.cpp
@@ -18,6 +18,8 @@
 #include "mozilla/webrender/WebRenderAPI.h"
 #include "PDMFactory.h"
 
+#include <iostream>
+
 namespace mozilla {
 namespace layers {
 
@@ -225,6 +227,8 @@ static void WriteFontDescriptor(const uint8_t* aData, uint32_t aLength,
 
   *sink->mFontKey = sink->mWrBridge->GetNextFontKey();
 
+  std::string s(reinterpret_cast<const char*>(aData), aLength);
+  std::cout << "WriteFontDescriptor: " << s << "(" << aLength << ")" << std::endl;
   sink->mResources->AddFontDescriptor(
       *sink->mFontKey, Range<uint8_t>(const_cast<uint8_t*>(aData), aLength),
       aIndex);
@@ -540,7 +544,7 @@ bool WebRenderBridgeChild::AllocResourceShmem(size_t aSize,
   bool alreadyAllocated = RefCountedShm::IsValid(mResourceShm);
   if (alreadyAllocated) {
     if (RefCountedShm::GetSize(mResourceShm) == aSize &&
-        RefCountedShm::GetReferenceCount(mResourceShm) <= 1) {
+        RefCountedShm::GetReferenceCount(mResourceShm) <= 1 && false) {
       MOZ_ASSERT(RefCountedShm::GetReferenceCount(mResourceShm) == 1);
       aShm = mResourceShm;
       return true;

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 1, 2024 •
edited
Loading

parent write to shm didn't sync child (thread) read.

[Parent 49536, Main Thread] WARNING: IPC Connection Error: [Parent][PContentParent] Send(msgname=PContent::Msg_PreferenceUpdate) Channel error: cannot send/recv: file /boot/home/src/gecko-dev/ipc/glue/MessageChannel.cpp:1943
WriteFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
RefCountedShm::AddRef(1): 16
ShmSegmentsWriter::Write
RefCountedShm::GetBytes: 16
IpcResourceUpdateQueue::AddFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
RefCountedShm::GetBytes: 16
ShmSegmentsReader::Read
RefCountedShm::GetBytes: 16
TransactionBuilder::AddFontDescriptor:{ data=/boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf, length=60, capacity=60 }
RefCountedShm::Release(1): 16
[49536] Hit MOZ_CRASH(called `Result::unwrap()` on an `Err` value: NulError(59, [47, 98, 111, 111, 116, 47, 115, 121, 115, 116, 101, 109, 47, 100, 97, 116, 97, 47, 102, 111, 110, 116, 115, 47, 116, 116, 102, 111, 110, 116, 115, 47, 78, 111, 116, 111, 83, 97, 110, 115, 68, 105, 115, 112, 108, 97, 121, 45, 82, 101, 103, 117, 108, 97, 114, 46, 116, 116, 102, 0])) at gfx/wr/wr_glyph_rasterizer/src/platform/unix/font.rs:225
[Parent 49536, Main Thread] WARNING: IPC Connection Error: [Parent][PContentParent] RunMessage(msgname=PVsync::Msg_Observe) Channel error: cannot send/recv: file /boot/home/src/gecko-dev/ipc/glue/MessageChannel.cpp:1943

@kenz-gelsoft
Copy link
Owner Author 

[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.46", O_RDWR|O_EXCL|O_CREAT|O_CLOEXEC, 0x180) = 0x45 (61 us)
[ 47552] unlink(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.46") = 0x0 No error (26 us)

@kenz-gelsoft
Copy link
Owner Author 

[ 47552] read_stat(0xffffffff, "/var/shared_memory", true, 0x7f4bb498db40, 0x80) = 0x0 No error (21 us)
[ 47552] open(0xffffffff, "/var/shared_memory/wayland-cursor-shared-jt7xEV", O_RDWR|O_EXCL|O_CREAT, 0x180) = 0xc (34 us)

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 1, 2024 •
edited
Loading 

[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.0", O_RDWR|O_EXCL|O_CREAT|O_CLOEXEC, 0x180) = 0x1b (44 us)
[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.0", O_CLOEXEC, 0x0) = 0x1d (23 us)
[ 47552] unlink(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.0") = 0x0 No error (23 us)
[ 47552] preallocate(0x1b, 0x0, 0x44c28) = 0x8000600e Operation not supported (13 us)
[ 47552] write_stat(0x1b, (nil), false, 0x7f4bb498d830, 0x80, 0x8) = 0x0 No error (16 us)

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 1, 2024 •
edited
Loading

strace doesn't reveal problem

Syscalls look working sane on creating shared memory.

[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.1", O_RDWR|O_EXCL|O_CREAT|O_CLOEXEC, 0x180) = 0x1b (40 us)
[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.1", O_CLOEXEC, 0x0) = 0x1e (21 us)
[ 47552] unlink(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.1") = 0x0 No error (23 us)
[ 47552] preallocate(0x1b, 0x0, 0x3b228) = 0x8000600e Operation not supported (12 us)
[ 47552] write_stat(0x1b, (nil), false, 0x7f4bb4989220, 0x80, 0x8) = 0x0 No error (15 us)
[ 47552] map_file("libxul.so mmap area", [0x0], B_RANDOMIZED_ANY_ADDRESS, 0x3b228, B_READ_AREA|B_WRITE_AREA, 0x0, true, 0x1b, 0x0) = 0x26fb7d ([0xe150b67000]) (30 us)
[ 47552] unmap_memory(0xe150b67000, 0x3b228) = 0x0 No error (22 us)

[ 47552] dup(0x1b) = 0x1e (17 us)
[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.2", O_RDWR|O_EXCL|O_CREAT|O_CLOEXEC, 0x180) = 0x1f (34 us)
[ 47552] unlink(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.2") = 0x0 No error (22 us)
[ 47552] preallocate(0x1f, 0x0, 0x736f) = 0x8000600e Operation not supported (12 us)
[ 47552] write_stat(0x1f, (nil), false, 0x7f4bb498b5c0, 0x80, 0x8) = 0x0 No error (14 us)

[ 47552] resize_area(0x26f8f5, 0x1050000) = 0x0 No error (15 us)
[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.3", O_RDWR|O_EXCL|O_CREAT|O_CLOEXEC, 0x180) = 0x1e (44 us)
[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.3", O_CLOEXEC, 0x0) = 0x1f (21 us)
[ 47552] unlink(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.3") = 0x0 No error (23 us)
[ 47552] preallocate(0x1e, 0x0, 0x8) = 0x8000600e Operation not supported (13 us)
[ 47552] write_stat(0x1e, (nil), false, 0x7f4bb4989c30, 0x80, 0x8) = 0x0 No error (15 us)

[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.4", O_RDWR|O_EXCL|O_CREAT|O_CLOEXEC, 0x180) = 0x11 (39 us)
[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.4", O_CLOEXEC, 0x0) = 0x21 (16 us)
[ 47552] unlink(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.4") = 0x0 No error (16 us)
[ 47552] preallocate(0x11, 0x0, 0x40000) = 0x8000600e Operation not supported (10 us)
[ 47552] write_stat(0x11, (nil), false, 0x7f4bb498b2b0, 0x80, 0x8) = 0x0 No error (14 us)

[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.5", O_RDWR|O_EXCL|O_CREAT|O_CLOEXEC, 0x180) = 0x23 (46 us)
[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.5", O_CLOEXEC, 0x0) = 0x24 (22 us)
[ 47552] unlink(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.5") = 0x0 No error (244 us)
[ 47552] preallocate(0x23, 0x0, 0x96) = 0x8000600e Operation not supported (13 us)
[ 47552] write_stat(0x23, (nil), false, 0x7f4bb498bc60, 0x80, 0x8) = 0x0 No error (16 us)

[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.46", O_RDWR|O_EXCL|O_CREAT|O_CLOEXEC, 0x180) = 0x45 (61 us)
[ 47552] unlink(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.46") = 0x0 No error (26 us)
[ 47552] preallocate(0x45, 0x0, 0x1000) = 0x8000600e Operation not supported (12 us)
[ 47552] write_stat(0x45, (nil), false, 0x7f4bb4989230, 0x80, 0x8) = 0x0 No error (17 us)
[ 47552] map_file("libxul.so mmap area", [0x0], B_RANDOMIZED_ANY_ADDRESS, 0x1000, B_READ_AREA|B_WRITE_AREA, 0x0, true, 0x45, 0x0) = 0x27052b ([0xfc23cc3000]) (37 us)
[ 47552] close(0x45) = 0x0 No error (13 us)

[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.45", O_RDWR|O_EXCL|O_CREAT|O_CLOEXEC, 0x180) = 0x45 (45 us)
[ 47552] unlink(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.45") = 0x0 No error (21 us)
[ 47552] preallocate(0x45, 0x0, 0x13d18) = 0x8000600e Operation not supported (11 us)
[ 47552] write_stat(0x45, (nil), false, 0x7f4bb4989f70, 0x80, 0x8) = 0x0 No error (15 us)
[ 47552] map_file("libxul.so mmap area", [0x0], B_RANDOMIZED_ANY_ADDRESS, 0x13d18, B_READ_AREA|B_WRITE_AREA, 0x0, true, 0x45, 0x0) = 0x270514 ([0xfb6e574000]) (30 us)
[ 47552] dup(0x45) = 0x4d (10 us)
[ 47552] unmap_memory(0xfb6e574000, 0x13d18) = 0x0 No error (19 us)
[ 47552] close(0x45) = 0x0 No error (30 us)
[ 47552] sendmsg(0x2d, {name = (nil), name_len = 0x0, iov = [{iov_base=0x11f110b3eae0, iov_len=0x40}, {iov_base=0x11f110742c90, iov_len=0x100}], control = 0x7f4bb49898c0, control_len = 0x14, flags = 0x0}, MSG_DONTWAIT) = 0x140 (108 us)
[ 47552] close(0x4d) = 0x0 No error (39 us)

[ 47552] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.44", O_RDWR|O_EXCL|O_CREAT|O_CLOEXEC, 0x180) = 0x4e (47 us)
[ 47552] unlink(0xffffffff, "/var/shared_memory/org.mozilla.ipc.47552.44") = 0x0 No error (22 us)
[ 47552] preallocate(0x4e, 0x0, 0x13cf8) = 0x8000600e Operation not supported (11 us)
[ 47552] write_stat(0x4e, (nil), false, 0x7f4bb4989f70, 0x80, 0x8) = 0x0 No error (16 us)
[ 47552] map_file("libxul.so mmap area", [0x0], B_RANDOMIZED_ANY_ADDRESS, 0x13cf8, B_READ_AREA|B_WRITE_AREA, 0x0, true, 0x4e, 0x0) = 0x270510 ([0xf83e7ed000]) (31 us)
[ 47552] dup(0x4e) = 0x50 (10 us)
[ 47552] unmap_memory(0xf83e7ed000, 0x13cf8) = 0x0 No error (15 us)
[ 47552] close(0x4e) = 0x0 No error (10 us)
[ 47552] sendmsg(0x2d, {name = (nil), name_len = 0x0, iov = [{iov_base=0x11f110aa9ee0, iov_len=0x40}, {iov_base=0x11f110adc6e0, iov_len=0x100}], control = 0x7f4bb49898c0, control_len = 0x14, flags = 0x0}, MSG_DONTWAIT) = 0x140 (31 us)
[ 47552] close(0x50) = 0x0 No error (10 us)

@kenz-gelsoft
Copy link
Owner Author

possibilities

  • branch point was broken
  • atomic access to refcnt doesnt work
  • failed low level write to shm underlying buffer

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 1, 2024 •
edited
Loading

branch point was broken

unlikely. possible ones, but not obvious

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 1, 2024 •
edited
Loading

atomic access to refcnt doesnt work

It relies on C++ standard implementation and seems supported

https://searchfox.org/mozilla-esr128/source/gfx/layers/ipc/RefCountedShmem.cpp#48

https://searchfox.org/mozilla-esr128/source/mfbt/Atomics.h#352

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 2, 2024 •
edited
Loading

It looks semibold font descriptor written to shmem, its handle flashed to pipe, and read correct order, but read invalid older content from shmem

WriteFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf(59)
RefCountedShm::AddRef(0): 32
RefCountedShm::AddRef(1): 32
ShmSegmentsWriter::Write: Allocated
ShmSegmentsWriter::Write
RefCountedShm::GetBytes: 32
ShmSegmentsWriter::Write: /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf(59)
IpcResourceUpdateQueue::AddFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf(59)
ShmSegmentsWriter::Flush
RefCountedShm::GetBytes: 32
ShmSegmentsReader::Read
RefCountedShm::GetBytes: 32
TransactionBuilder::AddFontDescriptor:{ data=/boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf, length=59, capacity=59 }
RefCountedShm::Release(1): 32
WriteFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
RefCountedShm::AddRef(1): 16
ShmSegmentsWriter::Write: Allocated
ShmSegmentsWriter::Write
RefCountedShm::GetBytes: 16
ShmSegmentsWriter::Write: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
IpcResourceUpdateQueue::AddFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
ShmSegmentsWriter::Flush
RefCountedShm::GetBytes: 16
ShmSegmentsReader::Read
RefCountedShm::GetBytes: 16
TransactionBuilder::AddFontDescriptor:{ data=/boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf, length=60, capacity=60 }
RefCountedShm::Release(1): 16
[61293] Hit MOZ_CRASH(called `Result::unwrap()` on an `Err` value: NulError(59, [47, 98, 111, 111, 116, 47, 115, 121, 115, 116, 101, 109, 47, 100, 97, 116, 97, 47, 102, 111, 110, 116, 115, 47, 116, 116, 102, 111, 110, 116, 115, 47, 78, 111, 116, 111, 83, 97, 110, 115, 68, 105, 115, 112, 108, 97, 121, 45, 82, 101, 103, 117, 108, 97, 114, 46, 116, 116, 102, 0])) at gfx/wr/wr_glyph_rasterizer/src/platform/unix/font.rs:225
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansMono-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansMono-Regular.ttf
[Child 61365, Main Thread] WARNING: 'presShell->NeedLayoutFlush()', file /boot/home/src/gecko-dev/layout/base/nsRefreshDriver.cpp:2244
ShmSegmentsWriter::Flush
#01: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa958406]

~/src/gecko-dev> git diff ipc
diff --git a/ipc/glue/Shmem.cpp b/ipc/glue/Shmem.cpp
index 442c6fb73c02..eca351917166 100644
--- a/ipc/glue/Shmem.cpp
+++ b/ipc/glue/Shmem.cpp
@@ -115,9 +115,11 @@ static already_AddRefed<SharedMemory> ReadSegment(
 #if defined(DEBUG)
 
 static void Protect(SharedMemory* aSegment) {
+/*
   MOZ_ASSERT(aSegment, "null segment");
   aSegment->Protect(reinterpret_cast<char*>(aSegment->memory()),
                     aSegment->Size(), RightsNone);
+*/
 }
 
 static void Unprotect(SharedMemory* aSegment) {
diff --git a/ipc/glue/Shmem.h b/ipc/glue/Shmem.h
index 657d5efbdd8a..3270358ad327 100644
--- a/ipc/glue/Shmem.h
+++ b/ipc/glue/Shmem.h
@@ -124,7 +124,9 @@ class Shmem final {
 
   Shmem(SharedMemory* aSegment, id_t aId, size_t aSize, bool aUnsafe);
 
+ public:
   id_t Id() const { return mId; }
+ private:
 
   SharedMemory* Segment() const { return mSegment; }

@kenz-gelsoft
Copy link
Owner Author

  • log with thread ids, timestamps
  • see with IPC log again

@kenz-gelsoft
Copy link
Owner Author

see with IPC log again

PWebRenderBridge_IPC_log.txt

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 3, 2024 •
edited
Loading

log with thread ids, timestamps

PWebRenderBridge_IPC_log2.txt

gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf
[time: 1725379258378561][10360] ShmSegmentsWriter::Flush
[time: 1725379258378600][10360->10360] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDisplayList
[time: 1725379258378660][10360->10360] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetFocusTarget
[time: 1725379258378658][10360<-10360] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetDisplayList
[time: 1725379258378906][10360<-10360] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetFocusTarget
[time: 1725379258403143][10360] WriteFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
[time: 1725379258403171][10360] RefCountedShm::AddRef(1): 16
[time: 1725379258403175][10360] ShmSegmentsWriter::Write: Allocated
[time: 1725379258403176][10360] ShmSegmentsWriter::Write
[time: 1725379258403182][10360] RefCountedShm::GetBytes: 16
[time: 1725379258403189][10360] ShmSegmentsWriter::Write: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
[time: 1725379258403203][10360] IpcResourceUpdateQueue::AddFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
[time: 1725379258404043][10360] ShmSegmentsWriter::Flush
[time: 1725379258404072][10360->10360] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDisplayList
[time: 1725379258404107][10360->10360] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetFocusTarget
[time: 1725379258404107][10360<-10360] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetDisplayList
[time: 1725379258404173][10360] RefCountedShm::GetBytes: 16
[time: 1725379258404185][10360] ShmSegmentsReader::Read
[time: 1725379258404189][10360] RefCountedShm::GetBytes: 16
[time: 1725379258404206][10360] TransactionBuilder::AddFontDescriptor:{ data=/boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf, length=60, capacity=60 }
[time: 1725379258404355][10360] RefCountedShm::Release(1): 16
[time: 1725379258404595][10360<-10360] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetFocusTarget
[10360] Hit MOZ_CRASH(called `Result::unwrap()` on an `Err` value: NulError(59, [47, 98, 111, 111, 116, 47, 115, 121, 115, 116, 101, 109, 47, 100, 97, 116, 97, 47, 102, 111, 110, 116, 115, 47, 116, 116, 102, 111, 110, 116, 115, 47, 78, 111, 116, 111, 83, 97, 110, 115, 68, 105, 115, 112, 108, 97, 121, 45, 82, 101, 103, 117, 108, 97, 114, 46, 116, 116, 102, 0])) at gfx/wr/wr_glyph_rasterizer/src/platform/unix/font.rs:225
[time: 1725379258431696][10360] ShmSegmentsWriter::Flush
[time: 1725379258431743][10360->10360] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDisplayList
[time: 1725379258431792][10360<-10360] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetDisplayList
[time: 1725379258431830][10360->10360] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetFocusTarget
[time: 1725379258432180][10360<-10360] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetFocusTarget
[Parent 10360, IPC I/O Parent] WARNING: [1.1]: GetUserData call for port 'FD294CC03D3465AB.1C2C6133E7A6DF5A' failed: file /boot/home/src/gecko-dev/ipc/glue/NodeController.cpp:425
#01: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa9585c6]
#02: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa9583bf]
#03: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa95801c]
#04: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb26a043]
#05: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb25bad4]
#06: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb25b8c9]
#07: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb269be7]
#08: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb28fe33]
#09: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb28a566]
#10: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa743154]
#11: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa744732]
#12: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa7424d8]
#13: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xa736a1e]
#14: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb1f4095]
#15: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb1f19ad]
#16: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb1ef85a]
#17: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb1f0001]
#18: XRE_GetBootstrap[/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/libxul.so +0xb26c5ab]
#19: pthread_exit[/boot/system/lib/libroot.so +0x4e578]
#20: ??? (???:???)
[Socket 10384, IPC I/O Child] WARNING: [14998C02C4ADED3E.90920266C6242BEC]: Dropping message '<null>'; no connection to unknown peer 1.1: file /boot/home/src/gecko-dev/ipc/glue/NodeController.cpp:365

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 3, 2024 •
edited
Loading

After write, read(0x1a) in another session with strace

[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd[time: 1725398899427853][10922] WriteFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
[time: 1725398899428085][10922] RefCountedShm::AddRef(1): 16
[time: 1725398899428112][10922] ShmSegmentsWriter::Write: Allocated
[time: 1725398899428136][10922] ShmSegmentsWriter::Write
[time: 1725398899428161][10922] RefCountedShm::GetBytes: 16
[time: 1725398899428185][10922] ShmSegmentsWriter::Write: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
[time: 1725398899428233][10922] IpcResourceUpdateQueue::AddFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-SemiBold.ttf(60)
=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x1 ([{fd=0x1a, revents=POLLIN}]) (34 us)
[ 10922] read(0x1a, 0xffffffffffffffff, 0x7f7a734895f7, 0x1) = 0x1 (12 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x0 No error ([]) (26 us)
[ 10922] write(0x1b, 0xffffffffffffffff, 0x8d0e280504, 0x1) = 0x1 (14 us)
[ 10922] mutex_unblock(0x1134bef4cd6c [B_USER_MUTEX_WAITING], 0x0) = 0x0 No error (21 us)
[ 10922] mutex_unblock(0x1134bef4cd04 [B_USER_MUTEX_WAITING], 0x0) = 0x0 No error (20 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x1 ([{fd=0x1a, revents=POLLIN}]) (28 us)
[ 10922] read(0x1a, 0xffffffffffffffff, 0x7f7a734895f7, 0x1) = 0x1 (13 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x0 No error ([]) (27 us)
[ 10922] write(0x1b, 0xffffffffffffffff, 0x8d0e280504, 0x1) = 0x1 (13 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x1 ([{fd=0x1a, revents=POLLIN}]) (22 us)
[ 10922] read(0x1a, 0xffffffffffffffff, 0x7f7a734895f7, 0x1) = 0x1 (12 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x0 No error ([]) (27 us)
[ 10922] write(0x1b, 0xffffffffffffffff, 0x8d0e280504, 0x1) = 0x1 (12 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x1 ([{fd=0x1a, revents=POLLIN}]) (22 us)
[ 10922] read(0x1a, 0xffffffffffffffff, 0x7f7a734895f7, 0x1) = 0x1 (13 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x0 No error ([]) (27 us)
[ 10922] write(0x1b, 0xffffffffffffffff, 0x8d0e280504, 0x1) = 0x1 (14 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x1 ([{fd=0x1a, revents=POLLIN}]) (22 us)
[ 10922] read(0x1a, 0xffffffffffffffff, 0x7f7a734895f7, 0x1) = 0x1 (11 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x0 No error ([]) (26 us)
[ 10922] write(0x1b, 0xffffffffffffffff, 0x8d0e280504, 0x1) = 0x1 (12 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x1 ([{fd=0x1a, revents=POLLIN}]) (23 us)
[ 10922] read(0x1a, 0xffffffffffffffff, 0x7f7a734895f7, 0x1) = 0x1 (12 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x0 No error ([]) (26 us)
[ 10922] write(0x1b, 0xffffffffffffffff, 0x8d0e280504, 0x1) = 0x1 (13 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x1 ([{fd=0x1a, revents=POLLIN}]) (22 us)
[ 10922] read(0x1a, 0xffffffffffffffff, 0x7f7a734895f7, 0x1) = 0x1 (12 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x0 No error ([]) (25 us)
[ 10922] write(0x1b, 0xffffffffffffffff, 0x8d0e280504, 0x1) = 0x1 (11 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x1 ([{fd=0x1a, revents=POLLIN}]) (20 us)
[ 10922] read(0x1a, 0xffffffffffffffff, 0x7f7a734895f7, 0x1) = 0x1 (11 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x0 No error ([]) (25 us)
[ 10922] write(0x1b, 0xffffffffffffffff, 0x8d0e280504, 0x1) = 0x1 (14 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x1 ([{fd=0x1a, revents=POLLIN}]) (21 us)
[ 10922] read(0x1a, 0xffffffffffffffff, 0x7f7a734895f7, 0x1) = 0x1 (11 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x0 No error ([]) (24 us)
[ 10922] write(0x1b, 0xffffffffffffffff, 0x8d0e280504, 0x1) = 0x1 (11 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x1 ([{fd=0x1a, revents=POLLIN}]) (20 us)
[ 10922] read(0x1a, 0xffffffffffffffff, 0x7f7a734895f7, 0x1) = 0x1 (10 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x0 No error ([]) (24 us)
[ 10922] write(0x1b, 0xffffffffffffffff, 0x8d0e280504, 0x1) = 0x1 (11 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x1 ([{fd=0x1a, revents=POLLIN}]) (19 us)
[ 10922] read(0x1a, 0xffffffffffffffff, 0x7f7a734895f7, 0x1) = 0x1 (11 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x0 No error ([]) (24 us)
[ 10922] write(0x1b, 0xffffffffffffffff, 0x8d0e280504, 0x1) = 0x1 (11 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x1 ([{fd=0x1a, revents=POLLIN}]) (20 us)
[ 10922] read(0x1a, 0xffffffffffffffff, 0x7f7a734895f7, 0x1) = 0x1 (12 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x0 No error ([]) (24 us)
[ 10922] write(0x1b, 0xffffffffffffffff, 0x8d0e280504, 0x1) = 0x1 (13 us)
[ 10922] port_count(0x5ef) = 0x0 (11 us)
[ 10922] write_port_etc(0x5ef, 0x0, (nil), 0x0, 0x8, 0x0) = 0x0 No error (13 us)
[ 10922] port_count(0x5ef) = 0x0 (10 us)
[ 10922] write_port_etc(0x5ef, 0x0, (nil), 0x0, 0x8, 0x0) = 0x0 No error (12 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x1 ([{fd=0x1a, revents=POLLIN}]) (25 us)
[ 10922] read(0x1a, 0xffffffffffffffff, 0x7f7a734895f7, 0x1) = 0x1 (11 us)
[ 10922] poll([{fd=0x6, events=POLLIN}, {fd=0xa, events=POLLIN}, {fd=0x1a, events=POLLIN}], 0x3, 0x0, (nil)) = 0x0 No error ([]) (25 us)
[ 10922] port_count(0x5ef) = 0x0 (14 us)
[ 10922] write_port_etc(0x5ef, 0x0, (nil), 0x0, 0x8, 0x0) = 0x0 No error (13 us)
[ 10922] port_count(0x5ef) = 0x0 (11 us)
[ 10922] write_port_etc(0x5ef, 0x0, (nil), 0x0, 0x8, 0x0) = 0x0 No error (12 us)
[ 10922] mutex_unblock(0x1134b13d9790 [B_USER_MUTEX_WAITING], 0x0) = 0x0 No error (24 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x8d0c814ead, 0x7) = 0x7 (31 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x7f7a73483368, 0x10) = 0x10 (14 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x8d0cda7d88, 0x2) = 0x2 (14 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x7f7a73483373, 0x5) = 0x5 (13 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x8d0cc7c532, 0x17) = 0x17 (14 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x1134be474b28, 0x3c) = 0x3c (14 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x8d0cc28b6b, 0x1) = 0x1 (14 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x7f7a73483376, 0x2) = 0x2 (14 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x8d0cae8ec7, 0x1) = 0x1 (14 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x6ca54d16c3, 0x1) = 0x1 (12 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x7f7a73481020, 0x3d) = 0x3d (13 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x7f7a73481220, 0x44) = 0x44 (13 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x7f7a73481220, 0x39) = 0x39 (13 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x7f7a734811f0, 0x3c) = 0x3c (13 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x7f7a73481220, 0x7b) = 0x7b (12 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x8d0c814ead, 0x7) = 0x7 (13 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x7f7a734832b8, 0x10) = 0x10 (13 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x8d0cda7d88, 0x2) = 0x2 (13 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x7f7a734832c3, 0x5) = 0x5 (13 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x8d0cb96ad7, 0x2d) = 0x2d (13 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x1134be474ab8, 0x3c) = 0x3c (13 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x8d0cc28b6b, 0x1) = 0x1 (12 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x7f7a734832c6, 0x2) = 0x2 (13 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x8d0cae8ec7, 0x1) = 0x1 (13 us)
[ 10922] write(0x1, 0xffffffffffffffff, 0x6ca54d16c3, 0x1) = 0x1 (14 [time: 1725398899429370][10922] ShmSegmentsWriter::Flush
[time: 1725398899429435][10922->10922] [PWebRenderBridgeChild] Sending  PWebRenderBridge::Msg_SetDisplayList
[time: 1725398899429575][10922<-10922] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetDisplayList
[time: 1725398899429691][10922] RefCountedShm::GetBytes: 16
[time: 1725398899429702][10922] ShmSegmentsReader::Read
[time: 1725398899429705][10922] RefCountedShm::GetBytes: 16
[time: 1725398899429743][10922] TransactionBuilder::AddFontDescriptor:{ data=/boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf, length=60, capacity=60 }
[time: 1725398899429788][10922] RefCountedShm::Release(1): 16
[time: 1725398899429877][10922<-10922] [PWebRenderBridgeParent] Received  PWebRenderBridge::Msg_SetFocusTarget
[10922] Hit MOZ_CRASH(called `Result::unwrap()` on an `Err` value: NulError(59, [47, 98, 111, 111, 116, 47, 115, 121, 115, 116, 101, 109, 47, 100, 97, 116, 97, 47, 102, 111, 110, 116, 115, 47, 116, 116, 102, 111, 110, 116, 115, 47, 78, 111, 116, 111, 83, 97, 110, 115, 68, 105, 115, 112, 108, 97, 121, 45, 82, 101, 103, 117, 108, 97, 114, 46, 116, 116, 102, 0])) at gfx/wr/wr_glyph_rasterizer/src/platform/unix/font.rs:225
us)
[ 10922] open(0xffffffff, "/var/shared_memory/org.mozilla.ipc.10922.42", O_RDWR|O_EXCL|O_CREAT|O_CLOEXEC, 0x180) = 0x43 (61 us)

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 3, 2024 •
edited
Loading

0x1a was not a shm, but a pipe connected 0x1b which used for communication between parent and child thread.

0x1a_1b_was_pipe.txt

let's dig again...

strace3.txt

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 4, 2024 •
edited
Loading

I want to know which shm region is source of this inconsistent read/write.

But couldn't strace child process by replacing firefox to following script:

#!/bin/sh
strace /boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/firefox-bin

maybe because locating executable with proc info of firefox-bin

add more precise logging?

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 4, 2024 •
edited
Loading

Revisit these with current knowledge

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 5, 2024 •
edited
Loading

Using large chunk always may work relatively well (stable) if recycling small chunk of shared memory is broken.

This should be easy if it is just changing the threashold.

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 5, 2024 •
edited
Loading

log_with_large_chunk.txt

diff --git a/gfx/layers/wr/IpcResourceUpdateQueue.cpp b/gfx/layers/wr/IpcResourceUpdateQueue.cpp
index d19dc7f2f9ca..b75e66cb04e3 100644
--- a/gfx/layers/wr/IpcResourceUpdateQueue.cpp
+++ b/gfx/layers/wr/IpcResourceUpdateQueue.cpp
@@ -12,6 +12,8 @@
 #include "mozilla/layers/PTextureChild.h"
 #include "mozilla/layers/WebRenderBridgeChild.h"
 
+#include <iostream>
+
 namespace mozilla {
 namespace wr {
 
@@ -51,12 +53,18 @@ layers::OffsetRange ShmSegmentsWriter::Write(Range<uint8_t> aBytes) {
   const size_t start = mCursor;
   const size_t length = aBytes.length();
 
-  if (length >= mChunkSize * 4) {
+//  if (length >= mChunkSize * 4) {
+  if (length > 0) {
     auto range = AllocLargeChunk(length);
     if (range.length()) {
       // Allocation was successful
       uint8_t* dstPtr = mLargeAllocs.LastElement().get<uint8_t>();
       memcpy(dstPtr, aBytes.begin().get(), length);
+      
+      std::string s(reinterpret_cast<const char *>(aBytes.begin().get()), length);
+      std::cout << "[time: " << PR_Now()
+          << "][" << base::GetCurrentProcId()
+          << "] ShmSegmentsWriter::Write: " << s << "(" << length << ")" << std::endl;
     }
     return range;
   }

and some more logging on read/write in ShmSegmentReader/Writer

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 5, 2024 •
edited
Loading

log with PContent IPC messages

~/src/gecko-dev> export MOZ_IPC_MESSAGE_LOG=PContent
~/src/gecko-dev> ./mach run > PContent_msg.txt 2>&1

PContent_msg.txt

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 5, 2024 •
edited
Loading

Enabled all type of error level logging

~/src/gecko-dev> export MOZ_LOG=all:1
~/src/gecko-dev> ./mach run > PContent_msg2.txt 2>&1

and extracted part about crashing child process

PContent_msg2_part.txt

Direct tab/content/child process crash reason here is first sending IPC message child=>parent direction to broken pipe/channel/connection

[time: 1725570381611351][45440->45568] [PContentParent] Sending  PContent::Msg_LoadURI
[Child 45568, IPC I/O Child] WARNING: Message needs unreceived descriptors channel:1055a140b0a0 message-type:3670042 header()->num_handles:1 num_fds:0 fds_i:0: file /boot/home/src/gecko-dev/ipc/chromium/src/chrome/common/ipc_channel_posix.cc:467
[Child 45568, IPC I/O Child] WARNING: [B9BC2721F759A1ED.9377D2FA5FC2DC1C]: Trying to broadcast event, but no connection to broker: file /boot/home/src/gecko-dev/ipc/glue/NodeController.cpp:416
[Parent 45440, IPC I/O Parent] WARNING: pipe error: Socket is not connected: file /boot/home/src/gecko-dev/ipc/chromium/src/chrome/common/ipc_channel_posix.cc:702
[Parent 45440, IPC I/O Parent] WARNING: Call to Send() failed: file /boot/home/src/gecko-dev/ipc/glue/NodeChannel.cpp:199
[Parent 45440, IPC I/O Parent] WARNING: Dropping message as channel has been closed: file /boot/home/src/gecko-dev/ipc/glue/NodeChannel.cpp:191
(snip)
[Parent 45440, IPC I/O Parent] WARNING: Dropping message as channel has been closed: file /boot/home/src/gecko-dev/ipc/glue/NodeChannel.cpp:191
[Parent 45440, IPC I/O Parent] WARNING: [1.1]: Dropping message '<null>'; no connection to unknown peer B9BC2721F759A1ED.9377D2FA5FC2DC1C: file /boot/home/src/gecko-dev/ipc/glue/NodeController.cpp:365
[time: 1725570381649328][45440<-45512] [PContentParent] Received  PContent::Msg_ScriptError
[time: 1725570381664007][45440<-45512] [PContentParent] Received  PContent::Msg_SetCharacterMap
[time: 1725570381664091][45440<-45512] [PContentParent] Received  PContent::Msg_SetCharacterMap
[time: 1725570381666635][45440<-45512] [PContentParent] Received  PContent::Msg_SetURITitle
[time: 1725570381666685][45440<-45512] [PContentParent] Received  PContent::Msg_SessionHistoryEntryTitle
[time: 1725570381667012][45440<-45512] [PContentParent] Received  PContent::Msg_CommitBrowsingContextTransaction
console.error: (new ReferenceError("WebAssembly is not defined", "resource://gre/actors/TranslationsParent.sys.mjs", 2737))
Error parsing B_ARGV_RECEIVED message. Message:
BMessage('_ARG') {
        argc = int32(0x12 or 18)
        argv[0] = string("/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/firefox", 53 bytes)
        argv[1] = string("-contentproc", 13 bytes)
        argv[2] = string("{0e8a5694-6de1-49a0-a350-f2f0d64b22b2}", 39 bytes)
        argv[3] = string("45440", 6 bytes)
        argv[4] = string("tab", 4 bytes)
        cwd = string("/boot/home/src/gecko-dev", 25 bytes)
}
wl_ips_client_connected
display: 0x1055a13ee520
client: 0x1055a13ad360
[Child 45568, Main Thread] WARNING: Failed to create file monitor for /boot/home/config/settings/glib-2.0/settings/keyfile: Unable to find default local file monitor type: 'glib warning', file /boot/home/src/gecko-dev/toolkit/xre/nsSigHandlers.cpp:187

(/boot/home/src/gecko-dev/obj-ff-dbg/dist/bin/firefox:45568): GLib-GIO-WARNING **: 06:06:21.690: Failed to create file monitor for /boot/home/config/settings/glib-2.0/settings/keyfile: Unable to find default local file monitor type
[time: 1725570381713328][45440<-45512] [PContentParent] Received  PContent::Msg_StartVisitedQueries
[Parent 45440, Main Thread] WARNING: IPC message 'PBrowser::Msg_Destroy' discarded: actor cannot send: file /boot/home/src/gecko-dev/ipc/glue/ProtocolUtils.cpp:551
[Parent 45440, Main Thread] WARNING: build ID mismatch false alarm: file /boot/home/src/gecko-dev/dom/base/nsFrameLoader.cpp:3735
[Parent 45440, Main Thread] WARNING: IPC message 'PBrowser::Msg_Destroy' discarded: actor cannot send: file /boot/home/src/gecko-dev/ipc/glue/ProtocolUtils.cpp:551
[Parent 45440, Main Thread] WARNING: build ID mismatch false alarm: file /boot/home/src/gecko-dev/dom/base/nsFrameLoader.cpp:3735
[Parent 45440, Main Thread] WARNING: IPC message 'PBrowser::Msg_Destroy' discarded: actor cannot send: file /boot/home/src/gecko-dev/ipc/glue/ProtocolUtils.cpp:551
[Parent 45440, Main Thread] WARNING: build ID mismatch false alarm: file /boot/home/src/gecko-dev/dom/base/nsFrameLoader.cpp:3735
[Parent 45440, Main Thread] WARNING: IPC message 'PBrowser::Msg_Destroy' discarded: actor cannot send: file /boot/home/src/gecko-dev/ipc/glue/ProtocolUtils.cpp:551
[Parent 45440, Main Thread] WARNING: build ID mismatch false alarm: file /boot/home/src/gecko-dev/dom/base/nsFrameLoader.cpp:3735
[Parent 45440, Main Thread] WARNING: IPC message 'PBrowser::Msg_Destroy' discarded: actor cannot send: file /boot/home/src/gecko-dev/ipc/glue/ProtocolUtils.cpp:551
[Parent 45440, ProcessHangMon] WARNING: IPC message 'PProcessHangMonitor::Msg_RequestContentJSInterrupt' discarded: actor cannot send: file /boot/home/src/gecko-dev/ipc/glue/ProtocolUtils.cpp:551
[Parent 45440, Main Thread] WARNING: build ID mismatch false alarm: file /boot/home/src/gecko-dev/dom/base/nsFrameLoader.cpp:3735
[Parent 45440, Main Thread] WARNING: content process pid = 45568 crashed without leaving a minidump behind: file /boot/home/src/gecko-dev/dom/ipc/ContentParent.cpp:4571
[time: 1725570381717977][45440->45568] [PContentParent] Sending  PContent::Msg_CommitBrowsingContextTransaction
[Parent 45440, Main Thread] WARNING: IPC message 'PContent::Msg_CommitBrowsingContextTransaction' discarded: actor cannot send: file /boot/home/src/gecko-dev/ipc/glue/ProtocolUtils.cpp:551
[time: 1725570381718014][45440->45568] [PContentParent] Sending  PContent::Msg_DiscardBrowsingContext
[Parent 45440, Main Thread] WARNING: IPC message 'PContent::Msg_DiscardBrowsingContext' discarded: actor cannot send: file /boot/home/src/gecko-dev/ipc/glue/ProtocolUtils.cpp:551
[time: 1725570381719677][45440->45568] [PContentParent] Sending  PContent::Msg_CommitBrowsingContextTransaction
[Parent 45440, Main Thread] WARNING: IPC message 'PContent::Msg_CommitBrowsingContextTransaction' discarded: actor cannot send: file /boot/home/src/gecko-dev/ipc/glue/ProtocolUtils.cpp:551
[time: 1725570381719709][45440->45568] [PContentParent] Sending  PContent::Msg_DiscardBrowsingContext
[Parent 45440, Main Thread] WARNING: IPC message 'PContent::Msg_DiscardBrowsingContext' discarded: actor cannot send: file /boot/home/src/gecko-dev/ipc/glue/ProtocolUtils.cpp:551
[time: 1725570381720218][45568->45440] [PContentChild] Sending  PContent::Msg_InitCrashReporter
Exiting due to channel error.

@kenz-gelsoft
Copy link
Owner Author

In this session, channel between parent 48297 and child 48584 was established, and succeeded for a while, but

[time: 1725572552195651][48584->48297] [PContentChild] Sending reply  PContent::Reply_FlushFOGData
[time: 1725572552195746][48513->48297] [PContentChild] Sending reply  PContent::Reply_FlushFOGData
[time: 1725572552229803][48297<-48507] [PContentParent] Received  PContent::Reply_FlushFOGData
[time: 1725572552229853][48297<-48509] [PContentParent] Received  PContent::Reply_FlushFOGData
[time: 1725572552229910][48297<-48584] [PContentParent] Received  PContent::Reply_FlushFOGData
[time: 1725572552229934][48297<-48513] [PContentParent] Received  PContent::Reply_FlushFOGData
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansMono-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansMono-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansMono-ExtraLight.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansMono-ExtraLight.ttf
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansMono-ExtraLight.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansMono-ExtraLight.ttf
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansMono-SemiBold.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansMono-SemiBold.ttf
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansMono-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansMono-Regular.ttf
[time: 1725572552339354][48584] WriteFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf(59)
[time: 1725572552339495][48584] ShmSegmentsWriter::Write: /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf(59)
[time: 1725572552339537][48584] IpcResourceUpdateQueue::AddFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf(59)
[time: 1725572552339718][48584] ShmSegmentsWriter::Flush
[time: 1725572552340169][48297] ShmSegmentsReader::ReadLarge
[time: 1725572552340199][48297] ShmSegmentsReader::ReadLarge2
[time: 1725572552340206][48297] ShmSegmentsReader::ReadLarge3
[time: 1725572552340247][48297] ShmSegmentsReader::ReadLarge4: /boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf(59)
[time: 1725572552340286][48297] TransactionBuilder::AddFontDescriptor:{ data=/boot/system/data/fonts/ttfonts/NotoSansDisplay-Regular.ttf, length=59, capacity=59 }
[time: 1725572552351679][48584->48297] [PContentChild] Sending  PContent::Msg_SetCharacterMap
[time: 1725572552351801][48297<-48584] [PContentParent] Received  PContent::Msg_SetCharacterMap
[time: 1725572552352184][48584->48297] [PContentChild] Sending  PContent::Msg_SetCharacterMap
[time: 1725572552352344][48297<-48584] [PContentParent] Received  PContent::Msg_SetCharacterMap
gfxFontconfigFontEntry::CreateFontInstance(fcc): /boot/system/data/fonts/ttfonts/NotoSansMono-Regular.ttf
gfxFontconfigFontEntry::CreateFontInstance(str): /boot/system/data/fonts/ttfonts/NotoSansMono-Regular.ttf
[Child 48584, Main Thread] WARNING: 'presShell->NeedLayoutFlush()', file /boot/home/src/gecko-dev/layout/base/nsRefreshDriver.cpp:2244
[time: 1725572552356961][48584] ShmSegmentsWriter::Flush
[time: 1725572552360702][48584] ShmSegmentsWriter::Flush
[time: 1725572552363293][48584->48297] [PContentChild] Sending  PContent::Msg_StoreAndBroadcastBlobURLRegistration
[time: 1725572552363392][48297<-48584] [PContentParent] Received  PContent::Msg_StoreAndBroadcastBlobURLRegistration
[time: 1725572552367963][48584] ShmSegmentsWriter::Flush

start failing around here

[time: 1725572552374069][48584] WriteFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansMono-Regular.ttf(56)
[time: 1725572552374180][48584] ShmSegmentsWriter::Write: /boot/system/data/fonts/ttfonts/NotoSansMono-Regular.ttf(56)
[time: 1725572552374207][48584] IpcResourceUpdateQueue::AddFontDescriptor: /boot/system/data/fonts/ttfonts/NotoSansMono-Regular.ttf(56)
[time: 1725572552374491][48584] ShmSegmentsWriter::Flush
[Parent 48297, IPC I/O Parent] WARNING: Message needs unreceived descriptors channel:10515a950140 message-type:3538947 header()->num_handles:1 num_fds:1 fds_i:1: file /boot/home/src/gecko-dev/ipc/chromium/src/chrome/common/ipc_channel_posix.cc:467
[Child 48584, IPC I/O Child] WARNING: [36E880164270421C.CC36C8FD561A46BC]: Dropping message '<null>'; no connection to unknown peer 1.1: file /boot/home/src/gecko-dev/ipc/glue/NodeController.cpp:365
[Parent 48297, IPC I/O Parent] WARNING: [1.1]: Dropping message '<null>'; no connection to unknown peer 36E880164270421C.CC36C8FD561A46BC: file /boot/home/src/gecko-dev/ipc/glue/NodeController.cpp:365
Exiting due to channel error.
[time: 1725572552378440][48297] ShmSegmentsWriter::Flush
[Parent 48297, Main Thread] WARNING: IPC Connection Error: [Parent][PContentParent] Send(msgname=PVsync::Msg_Notify) Channel error: cannot send/recv: file /boot/home/src/gecko-dev/ipc/glue/MessageChannel.cpp:1943
[Parent 48297, Main Thread] WARNING: IPC message 'PBrowser::Msg_Destroy' discarded: actor cannot send: file /boot/home/src/gecko-dev/ipc/glue/ProtocolUtils.cpp:551
[Parent 48297, Main Thread] WARNING: No build ID mismatch: file /boot/home/src/gecko-dev/dom/base/nsFrameLoader.cpp:3743
[time: 1725572552381231][48297->48584] [PContentParent] Sending  PContent::Msg_CommitBrowsingContextTransaction
[Parent 48297, Main Thread] WARNING: IPC message 'PContent::Msg_CommitBrowsingContextTransaction' discarded: actor cannot send: file /boot/home/src/gecko-dev/ipc/glue/ProtocolUtils.cpp:551
[time: 1725572552381352][48297->48584] [PContentParent] Sending  PContent::Msg_DiscardBrowsingContext
[Parent 48297, Main Thread] WARNING: IPC message 'PContent::Msg_DiscardBrowsingContext' discarded: actor cannot send: file /boot/home/src/gecko-dev/ipc/glue/ProtocolUtils.cpp:551
[time: 1725572552386815][48297] ShmSegmentsWriter::Flush

all log:
PContent_msg3.txt

@kenz-gelsoft
Copy link
Owner Author

send/recvmsg with fd logging

log3.txt

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 8, 2024 •
edited
Loading

detailed_log_tabprocess_crash.txt

detailed_log_tabprocess_crash2.txt

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 8, 2024 •
edited
Loading

ipc/glue/CrossProcessMutex.h

#if defined(XP_WIN)
typedef mozilla::UniqueFileHandle CrossProcessMutexHandle;
#elif !defined(XP_NETBSD) && !defined(XP_OPENBSD)
typedef mozilla::ipc::SharedMemoryBasic::Handle CrossProcessMutexHandle;
#else
// Stub for other platforms. We can't use uintptr_t here since different
// processes could disagree on its size.
typedef uintptr_t CrossProcessMutexHandle;
#endif

(omit)

#if defined(XP_WIN)
  HANDLE mMutex;
#elif !defined(XP_NETBSD) && !defined(XP_OPENBSD)
  RefPtr<mozilla::ipc::SharedMemoryBasic> mSharedBuffer;
  pthread_mutex_t* mMutex;
  mozilla::Atomic<int32_t>* mCount;
#endif
};

is not related. this is used only for codecoverage.

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 8, 2024 •
edited
Loading

libevent misinplementation is last resort

lets rework porting in-tree version.

@kenz-gelsoft
Copy link
Owner Author

kenz-gelsoft commented Sep 8, 2024 •
edited
Loading

https://searchfox.org/mozilla-esr128/source/ipc/chromium/src/base/dir_reader_posix.h

dirreader is also platform specific

used only from

https://searchfox.org/mozilla-esr128/source/ipc/chromium/src/base/process_util_posix.cc#119

@kenz-gelsoft
Copy link
Owner Author

Done for hard debugging scenario for this time.

closing.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@kenz-gelsoft