1424740 - console.log of an object graph in a worker is very slow

Status: NEW

(Core :: DOM: Core & HTML, enhancement, P2)

Description

[Boris Zbarsky [:bzbarsky]]

Attachment: Testcase

See attached testcase.  It's 1000x slower in Firefox than in Chrome or Safari....

Profile says that we spend all our time in structured clone serialization and deserialization.

This came up in a somewhat real-life situation in https://discourse.mozilla.org/t/webworker-behaves-very-slow-in-firefox/22563

Comment 1

[Andrea Marchesini [:baku]]

This issue is connected to how devtools receives console messages. Currently, this happens on the main-thread. Console API, in workers, needs to serialize data and send all to the main-thread each time. This is extremely slow.

But there are 2 good news:

1. This doesn't happen when debugging workers from about:debugging page. Here, we have a console JS actor running on the worker thread and that doesn't require serialization.

2. For fission, I know that, console communication protocol must be fully converted to JS actors. This will make the devtools console panel similar to about:debugging.

This means that, after fission, we can get rid of the console message serialization.

Brian, can you confirm this?

Comment 2

[Olli Pettay [:smaug][[e-mail]]]

https://perfht.ml/2MimXw3

Comment 3

[Brian Grinstead [:bgrins]]

(In reply to Andrea Marchesini [:baku] from comment #1)

This issue is connected to how devtools receives console messages. Currently, this happens on the main-thread. Console API, in workers, needs to serialize data and send all to the main-thread each time. This is extremely slow.

But there are 2 good news:

1. This doesn't happen when debugging workers from about:debugging page. Here, we have a console JS actor running on the worker thread and that doesn't require serialization.

2. For fission, I know that, console communication protocol must be fully converted to JS actors. This will make the devtools console panel similar to about:debugging.

This means that, after fission, we can get rid of the console message serialization.

Brian, can you confirm this?

For Fission, the architecture will be in place for the console to directly connect to multiple processes (Bug 1441711, Bug 1485664) which will have the behavior you describe when connecting to out of process frames. I expect this could be extended to workers as well, although I don't know they will be hooked up that way as a result of the initial Fission work. Yulia or Alex, do you have any more details?

Comment 4

[Yulia Startsev [:yulia] OOO until July 2026]

Alex has more details on this as he has been working on this, but workers are being updated to be treated the same way as all other targets (https://bugzilla.mozilla.org/show_bug.cgi?id=1465635). We don't have a clear timeline for the console work but we are aiming for this first half of the year. For how the console attaches to multiple processes, this is the most recent experimental patch: (https://phabricator.services.mozilla.com/D15834)

Comment 5

[Alexandre Poirot [:ochameau] [PTO back August 21]]

It is unfortunate that we didn't finished the DevTools enabling page (bug 1408969), which would have made devtools.enable preference actually useful. I originaly introduced this pref in bug 1382377 to at least remove any console overhead when the tools aren't used.

Other yes, for fission, we will be able to start actors in all the threads/processes/contexts (page, remote frames, workers). So that we should be able to drop this serialization to the main process when the tools are opened.

Am I following Console.cpp correctly, if I say we would drop this particular code if we want to remove the automatic serialization from work to main thread?
https://searchfox.org/mozilla-central/rev/60c4067b1cbb0f94d7dc2d7cdfa27ed579817fee/dom/console/Console.cpp#1549-1551
RefPtr<ConsoleCallDataWorkerRunnable> runnable =
new ConsoleCallDataWorkerRunnable(this, callData);
Unused << NS_WARN_IF(!runnable->Dispatch(aCx));
And only rely on:
https://searchfox.org/mozilla-central/rev/60c4067b1cbb0f94d7dc2d7cdfa27ed579817fee/dom/console/Console.cpp#1546-1547
// We do this only in workers for now.
NotifyHandler(aCx, aData, callData);
?

The thing is that we would no longer be able to cache the worker logs and would only be able to display the logs that happens after the tools are opened. We can probably craft some code dedicated to do that in the workers, but that require some substantial work in Console.cpp.

Comment 6

[Andrea Marchesini [:baku]]

The thing is that we would no longer be able to cache the worker logs and would only be able to display the logs that happens after the tools are opened. We can probably craft some code dedicated to do that in the workers, but that require some substantial work in Console.cpp.

This is not correct. The console class stores ConsoleData objects and exposes them via Console::RetrieveConsoleEvents(), which can be called from the WorkerDebuggerGlobalScope.

https://searchfox.org/mozilla-central/rev/60c4067b1cbb0f94d7dc2d7cdfa27ed579817fee/dom/console/Console.h#120-122
https://searchfox.org/mozilla-central/rev/60c4067b1cbb0f94d7dc2d7cdfa27ed579817fee/dom/webidl/WorkerDebuggerGlobalScope.webidl#31

There is a max size which is STORAGE_MAX_EVENTS, currently set to 1000.

Comment 7

[Alexandre Poirot [:ochameau] [PTO back August 21]]

Oh I wasn't aware of this code. For some reason, I was conviced it was reusing the Cache API used in the main thread...

So it means that our work on fission should address such perf issue, to the cost of additional actor overhead in exchange (we will have to run a DebuggerServer and Actors in each worker). Which, hopefully, will be smaller than the current serialization and at least be only triggered when the tools are opened!

Andrea, was I also wrong about the code to be removed that I mentioned in comment 5?

Comment 8

[Andrea Marchesini [:baku]]

Andrea, was I also wrong about the code to be removed that I mentioned in comment 5?

No, that part was correct.

Actually, at the moment, we use 'Console::RetrieveConsoleEvents()' just in workers. If we change that and we use it also for main-thread, we can get rid of ConsoleAPIStorage: https://searchfox.org/mozilla-central/rev/60c4067b1cbb0f94d7dc2d7cdfa27ed579817fee/dom/console/ConsoleAPIStorage.js

... and have 1 single way to retrieve console events. We could have console actors connected to the different globals (1 per document, workers, sharedWorkers, etc...) in different processes (for fission) and send the console events to the parent process where they can be shown in the UI.