bitwiseworks / qtwebengine-chromium-os2

Port of Chromium and related tools to OS/2
9 stars 2 forks source link

High CPU usage #25

Closed dmik closed 3 years ago

dmik commented 3 years ago

The simple web browser example works but it shows pretty high CPU load. It's around 30-40% in idle and on some web sites (e.g. cnn.com) it gets so high (100%) that eventually blocks the GUI thread completely (the app is killable but not usable, and web page update completely freezes).

The 100% CPU load is most likely caused by extensive JS usage (advertising, heavy SEO etc). But those 30-40% are also not normal even though the browser is pretty much usable like that. My guess is that we are failing too much when running the event loop. Perhaps those failing bits is some missing platform-specific code or functionality. Needs deeper debugging.

Also, while YouTube generally works not that bad I must say (w/o sound so far, see #24), playback is jumpy. It periodically freezes then continues. I also connect it to the event loop issues for now, so no separate ticket for that one.

Needed for https://github.com/bitwiseworks/qtwebengine-os2/issues/6.

dmik commented 3 years ago

This is not that easy to find out because Chromium uses around 25 threads in single-process mode when there's just one tab.

Chromium has a quite powerful built-in tracing facility, check https://www.chromium.org/developers/how-tos/trace-event-profiling-tool. It can trace function calls too and could reveal high CPU load (but that requires that trace statements are in the right places of Chromium code, of course). Chromium per se doesn't support about:tracing but Qt provides access to Chrome DevTools via Qt WebEngine Developer Tools, look here: https://doc.qt.io/qt-5/qtwebengine-debugging.html.

In order to access DevTools, it's needed to set QTWEBENGINE_REMOTE_DEBUGGING=NNN before running a Qt WebEngine application where NNN is the port number. After that, one should open http://localhost:NNN within the application to get to DevTools including the profiler. I'm not yet sure that this is the same as about:tracing will give you but it's a good start. Anyway, the profiler doesn't work ATM. It starts collecting data but no data appears when it stops.

There are also command-line options to collect tracing to a JSON file on startup (and on shutdown) as described at https://www.chromium.org/developers/how-tos/trace-event-profiling-tool/recording-tracing-runs (command line options should end up in the QTWEBENGINE_CHROMIUM_FLAGS environment variable) But for some reason this does not work either on OS/2. It creates a .json file but it's empty. This needs debugging. Both problems may have the same cause.

An alternative way is to just identify all Chromium threads and debug each of them to see which one gives the most load. This is quite time consuming, obviously. But there are some hints. I.e. I see several threads doing select and it might be that this goes wild for some reason. I will look there too.

StevenLevine commented 3 years ago

You might want to see what my monitorthreads utility reveals. The most recent versions are at:

<http:/www.warpcave.com/betas>

dmik commented 3 years ago

@StevenLevine thanks for the tool, I was actually just thinking about if there is anything like that around. It's showing me that TID 1 on top of all threads but I still need to check if it's the cause. However, attempting to interrupt the tool under heavy load with Ctrl-C resulted in the following trap screen twice already:

image

I guess you should add support for a graceful exit with pressing ESC or q (common for programs like top).

StevenLevine commented 3 years ago

If TID 1 is is anything like TID 1 on the Mozilla apps, it's almost surely the cause. As you know with the Mozilla code basde TID 1 is doing the vast majority of the PM and JavaScript work.

It's unlikely that monitorthreads has much, if anything, to do with SSES.SYS trap. The only APIs that monitorthreads uses directly are DosQuerySysState, DosSleep and DosSetPriority. I'd need a system dump to say much about what really happened to trigger the trap.

I'm somewhat surprised that SSES.SYS is even active on your setup.

Monitorthreads does no console input and Ctrl-Break should be sufficient to shut it down cleanly. Ctrl-C seems to work fine too, although there's no specific signal handler implemented.

dmik commented 3 years ago

Yes, further investigation revealed that TID 1 was the one generating a full load of one core (more details on that later, once I figure out the exact reason). Its not JS, it's just spinning the main event loop w/o ever waiting for new messages. Something is flooding the event queue.

Anyway, the tool proves to be useful to some extent — in case of such greedy CPU eaters at least. Together with the ability to halt the app from the debugger and look at stack traces of suspicious threads it's not that difficult to check their call chains and find bottlenecks, no profiling is actually necessary (and profiling may be misleading as it requires good support from both the compiler and the system which we apparently lack and it also cannot provide adequate measurements in some scenarios, especially those including multiple threads; and more complex and powerful things like Valrgind we simply lack as well).

BTW, do you know a tool to quickly sample call stacks of all threads of a given process from the command line? I guess something like that could be done using EXCEPTQ internals and some magic of DosDebug...

dmik commented 3 years ago

Re SESS.SYS, it is used by the SSH server in order to provide some ACL support at Dos API level IIRC. And at least one of the traps was triggered by Ctrl-C over SSH. BTW, in this scenario Ctrl-Break is not an option at all as there is no (easy) way to send Ctrl-Break over SSH. And even Ctrl-C does not always works. So, something like ESC is really wanted.

StevenLevine commented 3 years ago

I sorta guessed you were using the SSH server. FWIW, the OS2Voice HelpDesk package uses an older version of SSH that does not require SSES. The bad news is it needs a patch to support more than 4 CPUs.

Security Enablement Services and thus SSES.SYS can be pretty intrusive. SES intercepts almost every OS/2 API. The good news is that it does not seem to trap all that often.

You might want to give Monitorthreads v0.4 a try. I now handles Ctrl-C the same as Ctrl-Break.

dmik commented 3 years ago

I will try the new version, thanks.

Re the subject of the issue. I now know what it is, it's a qtbase issue, will create a ticket there.

dmik commented 3 years ago

The problem has gone with the above issue fixed. Closing.

dmik commented 3 years ago

@StevenLevine Using Ctrl-C in monitorthreads v4 still produces an immediate SESS.SYS trap as on the screenshot.

StevenLevine commented 3 years ago

The fact that the trap is still present is not unexpected. Please capture a system dump and I will see if I can come up with a workaround for you. Use the memlimit command to reduce the size of the dump file.

StevenLevine commented 3 years ago

I don't have a tool that can capture all stacks for given process. What you can do, if a one shot capture is good enough, is use my pdumpctl utility to force a process dump. Then pmdf's Analyze->All threads->Dump Ring3 stacks will get you what you are looking for. It should be sufficient to configure pdumpctl for an "Instance" style dump, so the dump file should be relatively small. I've not tried this, but you should be able to capture the dump while the debugger has your app paused, if that is what you need.

dmik commented 3 years ago

Thanks for the hints, but I guess I'm fine with monitorthreads + halting the app in the debugger for now. More over, even monitorthreads is not strictly needed. I've just realized (thanks to monitorthreads though) that when you halt the app execution from the debugger, it seems to always pop up the thread that was the busiest one. In my case this always matches to a TID that monitorthreads is showing as the top one. JFYI.