949875 - Touching Codegen.py seems to force regeneration of the build backend

Status: RESOLVED FIXED

(Firefox Build System :: General, defect)

Description

[Boris Zbarsky [:bzbarsky]]

STEPS TO REPRODUCE:

1)  Edit Codegen.py
2)  mach build dom/bindings/export

EXPECTED RESULTS:  Regenerates the bindings.

ACTUAL RESULTS: "Build configuration changed. Regenerating backend." and then regenerates the bindings.

The result is that what used to be a 9s operation (already getting way too slow) is now closer to 20s.

Anything I can do locally in the meantime to get back to the much shorter change/build cycle?

Comment 1

[Gregory Szorc [:gps]]

This is a leaking import from mozwebidlcodegen/__init__.py, which is imported from recursivemake.py. This time has come for us to write a lazy importer. This was on the plate anyway. Might as well do a preliminary stab at it.

FWIW, recent config.status time increased are likely due to bug 778236.

Comment 2

[Boris Zbarsky [:bzbarsky]]

gps asked for the timings here.  It seems to be pretty variable depending on what all else the system is doing.  The best I've seen so far is:

0:00.27 /usr/bin/make -C /Users/bzbarsky/mozilla/inbound/obj-firefox -j8 -s backend.RecursiveMakeBackend
 0:00.42 Build configuration changed. Regenerating backend.
 0:00.73 Reticulating splines...
 0:07.77 Finished reading 2950 moz.build files in 2.28s
 0:07.77 Processed into 6534 build config descriptors in 2.03s
 0:07.77 Backend executed in 2.56s
 0:07.77 2769 total backend files. 0 created; 0 updated; 2769 unchanged
 0:07.77 Total wall time: 7.03s; CPU time: 6.48s; Efficiency: 92%; Untracked: 0.16s

when everything is in cache and nothing else was really going on.  The worst I've seen is:

 0:00.40 /usr/bin/make -C /Users/bzbarsky/mozilla/inbound/obj-firefox -j8 -s backend.RecursiveMakeBackend
 0:00.64 Build configuration changed. Regenerating backend.
 0:01.20 Reticulating splines...
 0:18.45 Finished reading 2950 moz.build files in 5.14s
 0:18.45 Processed into 6534 build config descriptors in 4.87s
 0:18.45 Backend executed in 6.90s
 0:18.45 2769 total backend files. 0 created; 0 updated; 2769 unchanged
 0:18.45 Total wall time: 17.25s; CPU time: 12.62s; Efficiency: 73%; Untracked: 0.34s

with most falling around the 10s total wall time mark.

Comment 3

[Gregory Szorc [:gps]]

Choices are to roll our own or import a 3rd party module.

https://pypi.python.org/pypi/Importing/1.10 seems decent. Although it doesn't support magical lazy importing, which is something we'll want to pursue for mach. I guess we can cross that bridge later.

Comment 4

[Gregory Szorc [:gps]]

(In reply to Boris Zbarsky [:bz] from comment #2)
> 0:00.27 /usr/bin/make -C /Users/bzbarsky/mozilla/inbound/obj-firefox -j8 -s
> backend.RecursiveMakeBackend
>  0:00.42 Build configuration changed. Regenerating backend.
>  0:00.73 Reticulating splines...
>  0:07.77 Finished reading 2950 moz.build files in 2.28s
>  0:07.77 Processed into 6534 build config descriptors in 2.03s
>  0:07.77 Backend executed in 2.56s
>  0:07.77 2769 total backend files. 0 created; 0 updated; 2769 unchanged
>  0:07.77 Total wall time: 7.03s; CPU time: 6.48s; Efficiency: 92%;
> Untracked: 0.16s
> 
> when everything is in cache and nothing else was really going on.  The worst
> I've seen is:
> 
>  0:00.40 /usr/bin/make -C /Users/bzbarsky/mozilla/inbound/obj-firefox -j8 -s
> backend.RecursiveMakeBackend
>  0:00.64 Build configuration changed. Regenerating backend.
>  0:01.20 Reticulating splines...
>  0:18.45 Finished reading 2950 moz.build files in 5.14s
>  0:18.45 Processed into 6534 build config descriptors in 4.87s
>  0:18.45 Backend executed in 6.90s
>  0:18.45 2769 total backend files. 0 created; 0 updated; 2769 unchanged
>  0:18.45 Total wall time: 17.25s; CPU time: 12.62s; Efficiency: 73%;
> Untracked: 0.34s

The 73% efficiency implies things are stalling in I/O wait. If you aren't running an SSD, please expense one.

By comparison, my 2013 Haswell MBP:

Finished reading 2946 moz.build files in 1.74s
Processed into 6521 build config descriptors in 1.45s
Backend executed in 1.80s
2760 total backend files. 0 created; 0 updated; 2760 unchanged
Total wall time: 5.11s; CPU time: 4.68s; Efficiency: 91%; Untracked: 0.13s

From your ~7s "best" time (which has decent efficiency in terms of CPU), I'm guessing you are on Ivy Bridge or older or aren't clocked as fast as me (2.6 GHz).

glandium: it also looks like GYP reduced our maximum achievable CPU efficiency from 100% to ~91%. I wonder if GYP is doing a sleep() or something nonsensical.

Comment 5

[Boris Zbarsky [:bzbarsky]]

> If you aren't running an SSD, please expense one.

It's an SSD, in a 2012 MBP.  So yes, Ivy Bridge, clocked at 2.7.

The 73% case was when there was something else slightly disk-intensive happening at the same time.

I just did several runs on a totally quiet system, and they all come in at 92% efficiency and right about 7.05s wall clock time, fwiw.

Comment 6

[Gregory Szorc [:gps]]

OK. The Importing package I found on PyPI doesn't appear to work in Python 2.7.6. I'm getting an exception coming from C lang. It doesn't really do what I want anyway (complete lazy importing). The only package I found that does complete lazy importing is Mercurial's mercurial.demandimport. But it's under GPL, so we can't use it. We may have to roll our own.

Perhaps one of the Python gurus I'm CCing knows something I don't.

Comment 7

[Gregory Szorc [:gps]]

Attachment: Delay import some WebIDL modules to avoid dependency on config.status

This should do it.

Comment 8

[Boris Zbarsky [:bzbarsky]]

Could we get away with breaking up WebIDLCodegenManager into two classes?  One would have the bits that recursivemake depends on, the other would inherit from it and have the bits that actually depend on WebIDL and Codegen and Configuration.  The recursivemake would only need to import the parent class, which wouldn't pull in the others.

Comment 9

[Boris Zbarsky [:bzbarsky]]

Oh, nice.  So that would make recursivemake only depend on those files if it calls one of the methods that actually use them?

Comment 10

[Gregory Szorc [:gps]]

(In reply to Boris Zbarsky [:bz] from comment #9)
> Oh, nice.  So that would make recursivemake only depend on those files if it
> calls one of the methods that actually use them?

That's how it works, yes. Function level imports are generally considered a bad practice in Python, which is why I didn't want to use them. Perfect is the enemy of good.

The problem with 2 classes is config.status needs to know about which files it expects to generate. Those functions are on the class that does codegen. We could split it all up, but IMO that just makes the code harder to read. It's all self-contained now, which I like for readability.

Comment 11

[Gregory Szorc [:gps]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/203e2bcc575d

Comment 12

[Carsten Book [:Tomcat]]

backed this out as part of https://tbpl.mozilla.org/?tree=Mozilla-Inbound&rev=94fcc19a0765 for a windows bustage like https://tbpl.mozilla.org/php/getParsedLog.php?id=31926047&tree=Mozilla-Inbound

Comment 13

[Gregory Szorc [:gps]]

This is, uh, weird.

The error implies dom/bindings/parser isn't in the Python module path. This is all pymake, so it should be using the virtualenv's site-packages, which should have this path installed.

Only thing I can think of is dom/bindings/parser doesn't have an __init__.py. But I didn't think you needed __init__.py in root directories. Linux and OS X are happy without it.

https://tbpl.mozilla.org/?tree=Try&rev=e01846654aef tests my __init__.py theory. If that doesn't fix it, will need to diagnose this on a Windows machine.

Comment 14

[Mike Hommey [:glandium]]

(In reply to Carsten Book [:Tomcat] from comment #12)
> backed this out as part of
> https://tbpl.mozilla.org/?tree=Mozilla-Inbound&rev=94fcc19a0765 for a
> windows bustage like
> https://tbpl.mozilla.org/php/getParsedLog.php?id=31926047&tree=Mozilla-
> Inbound

Note this log shows no configure has run. Which potentially means the virtualenv was not updated.

Comment 15

[Gregory Szorc [:gps]]

I continue to attempt to debug this.

https://tbpl.mozilla.org/?tree=Try&rev=4463a2c9f2f6

Comment 16

[Gregory Szorc [:gps]]

FTR, I'm unable to reproduce this locally on Windows 7 in MozillaBuild 1.9.0pre.

Comment 17

[Gregory Szorc [:gps]]

My latest try dumps sys.path before running WebIDL code. The failure at https://tbpl.mozilla.org/php/getParsedLog.php?id=32138217&tree=Try&full=1#error0 reveals that the virtualenv paths are *not* activated when this script is invoked. This doesn't make any sense because the failure is in a module that is in the virtualenv (mozwebidlcodegen)! There must be an additional variable to sys.path on Windows. I'll keep poking around.

Comment 18

[Mike Hommey [:glandium]]

pymake native commands screwing things up?

Comment 19

[Gregory Szorc [:gps]]

(In reply to Mike Hommey [:glandium] from comment #18)
> pymake native commands screwing things up?

That's my suspicion. However, I built with pymake yesterday and was unable to repro. Maybe it's a native command specific to the tree's mozconfig. I'm working from home today and have access to my fast Windows machine.

Comment 20

[Gregory Szorc [:gps]]

My Windows machine at home can repro this!

Comment 21

[Gregory Szorc [:gps]]

Ugh. This is a pymake limitation, dare I say bug. I'll file a new bug to track the issue.

Comment 22

[Gregory Szorc [:gps]]

Patch up in bug 951736. Fixes issue locally. But I'll try anyway.

https://tbpl.mozilla.org/?tree=Try&rev=62ea254bb159

Comment 23

[Gregory Szorc [:gps]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/3a015ec9a7be

Comment 24

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/3a015ec9a7be