mozlog.structured.commandline imports a lot of modules, slows down mach

NEW
Unassigned

Status

Testing
Mozbase
3 years ago
3 years ago

People

(Reporter: gps, Unassigned)

Tracking

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(2 attachments)

(Reporter)

Description

3 years ago
mozlog.structured imports a lot of modules and slows down mach as a result.

Here are the mozlog modules loaded after all mach_commands.py files have been loaded:

mozlog from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.SocketServer from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.json from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.logger from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.logging from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.loggingmixin from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.loglistener from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.mozlog from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.socket from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.__future__ from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.collections from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.commandline from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.base from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.blessings from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.collections from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.html from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.html.base64 from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.html.cgi from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.html.collections from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.html.datetime from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.html.html from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.html.os from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.json from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.machformatter from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.tbplformatter from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.time from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.types from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.unittest from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.xml from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.formatters.xunit from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.handlers from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.handlers.base from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.handlers.bufferhandler from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.handlers.codecs from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.handlers.collections from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.handlers.mozlog from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.handlers.statushandler from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.handlers.threading from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.json from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.logging from testing/web-platform/mach_commands.py
mozlog.structured.logtypes from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.multiprocessing from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.optparse from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.os from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.reader from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.stdadapter from testing/web-platform/mach_commands.py
mozlog.structured.structuredlog from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.sys from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.threading from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.time from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
mozlog.structured.traceback from testing/web-platform/mach_commands.py, testing/marionette/mach_commands.py, testing/xpcshell/mach_commands.py
update.mozlog from testing/web-platform/mach_commands.py
wptrunner.mozlog from testing/web-platform/mach_commands.py
wptrunner.update.mozlog from testing/web-platform/mach_commands.py

mozlog.structured.commandline pulls in many of them. If we could reduce the number of modules needed to populate mach's argument parser, that would be swell.

I reckon most of these are coming from the "formatters" import.
So, I started to look at it. I found that this is not the real bottleneck for the speed execution of mach.
There is one bigger that I think can be addressed, in python/mozbuild/mozbuild/backend/configenvironment.py.

To show some data, I ran "./mach help" 30 times, on an ubuntu machine.

So first, the results. I attach the patches just after that.

Without any patch (current code):

Total: 10.989715
Mean: 0.366324


with improve_mach.patch:

Total: 9.153914
Mean: 0.305130


With improve_mach_full.patch:

Total: 9.069059
Mean: 0.302302


improve_mach_full.patch contains the same fix as in improve_mach.patch, and also tries to do some dynamic module loading in mozlog. We can see that results are not obviously better (it probably can be improved though).

So the real improvement is in improve_mach.patch, which speed up mach by more than 16%. As you'll see in the patch, it is a trade off with memory; but I think it is ok.
Created attachment 8629288 [details] [diff] [review]
improve_mach_full.patch
:gps, tell me if this is applicable, or if I made a mistake somewhere. :)
Flags: needinfo?(gps)
(Reporter)

Comment 5

3 years ago
So, it turns out that `mach help` isn't a great benchmark. For whatever reason (I suspect argparse slowness), `mach help` is several hundred milliseconds faster than say `mach uuid`.

We want to optimize for reducing the number of imported modules for mach to perform command dispatch. And I still think refactoring the mozlog imports will make this better.

The patch to address BuildConfig caching should be considered. I believe I've seen that code show up in certain profiles before as well, especially on Windows. Can you file a new bug in Core :: Build Config so we can look at caching that instance?
Flags: needinfo?(gps)
Thanks Gregory for the explanation. I just created bug 1180813.

I will have a look at `mach uuid` when I got the time.
You need to log in before you can comment on or make changes to this bug.