Print more info when processing moz.build files

RESOLVED FIXED in mozilla22

Status

()

Core
Build Config
RESOLVED FIXED
5 years ago
5 years ago

People

(Reporter: gps, Assigned: gps)

Tracking

(Blocks: 1 bug)

unspecified
mozilla22
Points:
---
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment)

(Assignee)

Description

5 years ago
Currently we don't print any info when processing moz.build files and generating the build backend. I think people would appreciate having some feedback here. If nothing else, it will make useful debugging info.

e.g.

creating ./config.status
reading tree definition from moz.build files and generating RecursiveMake build files
moz.build backend generation complete. 1200 files read in 2.45 seconds. 1400 files created. 4 updated.
(Assignee)

Comment 1

5 years ago
Created attachment 720320 [details] [diff] [review]
Print build summary, v1

This touched a few more files than I thought it would. But, it's very comprehensive, informative, and gets the job done.

Sample output from a fresh configure:

---
updating cache ./config.cache
creating ./config.status
Reticulating splines...
Finished reading 1100 moz.build files into 1103 descriptors in 1.33s
Backend executed in 1.13s
2196 total backend files. 2196 created; 0 updated; 0 unchanged
Total wall time: 2.65s; CPU time: 2.64s; Efficiency: 100%
generating WebRTC Makefiles...
Updating projects from gyp files...
---

If we reconfigure on the same tree:

---
creating ./config.status
Reticulating splines...
Finished reading 1100 moz.build files into 1103 descriptors in 1.30s
Backend executed in 0.99s
2196 total backend files. 0 created; 1 updated; 2195 unchanged
Total wall time: 2.48s; CPU time: 2.48s; Efficiency: 100%
generating WebRTC Makefiles...
---

If we update a moz.build file:

---
creating ./config.status
Reticulating splines...
Finished reading 1100 moz.build files into 1104 descriptors in 1.31s
Backend executed in 0.92s
2197 total backend files. 0 created; 2 updated; 2195 unchanged
Total wall time: 2.42s; CPU time: 2.43s; Efficiency: 101%
generating WebRTC Makefiles..
---

I think this will be pretty useful!

FWIW, I have bit rotted the patches from bug 844635. However, I need to back those out since they are causing failures on b-s :(
Assignee: nobody → gps
Status: NEW → ASSIGNED
Attachment #720320 - Flags: review?(mh+mozilla)
Comment on attachment 720320 [details] [diff] [review]
Print build summary, v1

>diff --git a/python/mozbuild/mozbuild/backend/base.py b/python/mozbuild/mozbuild/backend/base.py
>--- a/python/mozbuild/mozbuild/backend/base.py
>+++ b/python/mozbuild/mozbuild/backend/base.py
>+        # The total wall time spent this backend spent consuming objects. If

s/time spent/time/
Comment on attachment 720320 [details] [diff] [review]
Print build summary, v1

Review of attachment 720320 [details] [diff] [review]:
-----------------------------------------------------------------

::: build/ConfigStatus.py
@@ +117,5 @@
>      log_manager.add_terminal_logging(level=log_level)
>      log_manager.enable_unstructured()
>  
>      if not options.files and not options.headers:
> +        print('Reticulating splines...', file=sys.stderr)

Why not use logging?

::: python/mozbuild/mozbuild/backend/base.py
@@ +54,5 @@
> +        # How much wall time the system spent doing other things. This is
> +        # wall_time - mozbuild_execution_time - backend_execution_time.
> +        self.other_time = 0.0
> +
> +    def reader_summary(self):

@property?

::: python/mozbuild/mozbuild/frontend/reader.py
@@ +618,4 @@
>          sandbox = MozbuildSandbox(self.config, path)
>          sandbox.exec_file(path, filesystem_absolute=filesystem_absolute)
> +        with sandbox._globals.allow_all_writes() as d:
> +            d['EXECUTION_TIME'] = time.time() - time_start

why expose in the sandbox?
Attachment #720320 - Flags: review?(mh+mozilla) → review+
(Assignee)

Comment 4

5 years ago
(In reply to Mike Hommey [:glandium] from comment #3)
> ::: build/ConfigStatus.py
> @@ +117,5 @@
> >      log_manager.add_terminal_logging(level=log_level)
> >      log_manager.enable_unstructured()
> >  
> >      if not options.files and not options.headers:
> > +        print('Reticulating splines...', file=sys.stderr)
> 
> Why not use logging?

If we use logging currently, it gets caught up in mach's logging manager which prepends elapsed times. This looks ugly when building with mach (you get double printed times). The reason is purely cosmetic.

We will change to use logging eventually.

> ::: python/mozbuild/mozbuild/backend/base.py
> @@ +54,5 @@
> > +        # How much wall time the system spent doing other things. This is
> > +        # wall_time - mozbuild_execution_time - backend_execution_time.
> > +        self.other_time = 0.0
> > +
> > +    def reader_summary(self):
> 
> @property?
> 
> ::: python/mozbuild/mozbuild/frontend/reader.py
> @@ +618,4 @@
> >          sandbox = MozbuildSandbox(self.config, path)
> >          sandbox.exec_file(path, filesystem_absolute=filesystem_absolute)
> > +        with sandbox._globals.allow_all_writes() as d:
> > +            d['EXECUTION_TIME'] = time.time() - time_start
> 
> why expose in the sandbox?

That's just how I implemented it. Thinking about this on a new day, I'll change this to a regular attribute outside of the sandbox.
(Assignee)

Comment 5

5 years ago
https://hg.mozilla.org/integration/mozilla-inbound/rev/cc1e0568c96a

With minor nits addressed.
Target Milestone: --- → mozilla22
https://hg.mozilla.org/mozilla-central/rev/cc1e0568c96a
Status: ASSIGNED → RESOLVED
Last Resolved: 5 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
(Assignee)

Updated

5 years ago
Blocks: 848097
You need to log in before you can comment on or make changes to this bug.