Changes

Jump to: navigation, search

Profile the build system

7,414 bytes added, 14:26, 11 November 2008
m
November 2008
Resources: ted
=== Bugzilla ===
A bug has been submitted for enhancement on [[https://bugzilla.mozilla.org/show_bug.cgi?id=459891 Bugzilla]].
== Project Details ==
 
* Get where time is spent during the build
** 1 set of data from scratch builds and 1 set of data from rebuilds
 
* Collect Data
== Releases ==
=== Release 0.1 - Oct 13 ===
==== Goal ====
* Try out different build options
** See how they affect built
** Time how long it takes on each file/directory during the build
[[Image==== Results for Rebuilds with No Changes====* Looking at the breakdown of the time, it can be seen that dom, browser, content, toolkit, netwerk, and xpcom take up a large portion of the build time* The remaining 39.3% of the build time is divided into layout, intl, embedding and other 23 different directories ===== Charts =====''Data from 10 Rebuilds were used to create the following charts:TimeChart.jpg]]''
[[Image:TimeChartCondensed.jpg]][[Image:TimeChartAll.jpg]] ===== Data ====={| class="mediawiki sortable" border="1" cellpadding="5" cellspacing="0"|+ Rebuild Profile Data|-| style="background:#DDDDDD;" align="center" | Folders| style="background:#DDDDDD;" align="center" | 1 (sec)| style="background:#DDDDDD;" align="center" | 2 (sec)| style="background:#DDDDDD;" align="center" | 3 (sec)| style="background:#DDDDDD;" align="center" | 4 (sec)| style="background:#DDDDDD;" align="center" | 5 (sec)| style="background:#DDDDDD;" align="center" | 6 (sec)| style="background:#DDDDDD;" align="center" | 7 (sec)| style="background:#DDDDDD;" align="center" | 8 (sec)| style="background:#DDDDDD;" align="center" | 9 (sec)| style="background:#DDDDDD;" align="center" | 10 (sec)| style="background:#DDDDDD;" align="center" | AVG (sec)| style="background:#DDDDDD;" align="center" | %|-| dom| 100.359 | 78.483 | 78.530 | 83.454 | 85.608 | 105.346 | 121.647 | 94.457 | 86.579 | 81.220 | 91.568 | 12.46%|-| content| 107.504 | 72.521 | 76.064 | 72.693 | 72.175 | 84.936 | 101.252 | 75.230 | 76.487 | 70.748 | 80.961 | 11.02%|-| browser| 79.352 | 78.662 | 85.827 | 73.574 | 75.665 | 79.911 | 82.024 | 71.726 | 72.534 | 71.356 | 77.063 | 10.49%|-| netwerk| 73.646 | 58.749 | 68.171 | 61.736 | 61.747 | 77.301 | 89.820 | 66.909 | 65.089 | 59.837 | 68.301 | 9.30%|-| toolkit| 67.833 | 63.092 | 70.699 | 64.975 | 66.265 | 72.723 | 76.762 | 67.938 | 67.456 | 63.604 | 68.135 | 9.27%|-| xpcom| 63.494 | 57.616 | 54.563 | 50.040 | 51.008 | 71.673 | 77.560 | 61.735 | 63.407 | 48.072 | 59.917 | 8.16%|-| layout| 67.544 | 41.636 | 43.673 | 43.222 | 44.494 | 49.144 | 76.850 | 45.768 | 43.555 | 42.665 | 49.855 | 6.79%|-| intl| 50.631 | 40.152 | 42.585 | 40.364 | 40.779 | 52.670 | 59.998 | 44.475 | 40.644 | 38.891 | 45.119 | 6.14%|-| embedding| 39.713 | 33.534 | 33.525 | 34.321 | 35.067 | 39.370 | 44.234 | 36.592 | 34.942 | 33.886 | 36.518 | 4.97%|-| editor| 26.544 | 20.365 | 23.146 | 20.031 | 20.868 | 22.450 | 26.921 | 21.583 | 22.397 | 19.463 | 22.377 | 3.05%|-| gfx | 22.279 | 14.212 | 14.587 | 14.673 | 16.167 | 17.449 | 26.159 | 15.635 | 14.128 | 14.231 | 16.952 | 2.31%|-| docshell | 15.935 | 12.512 | 13.759 | 13.092 | 13.857 | 15.978 | 19.985 | 14.177 | 12.954 | 12.567 | 14.482 | 1.97%|-| rdf | 15.287 | 12.746 | 12.636 | 13.285 | 13.497 | 15.735 | 19.098 | 14.593 | 13.312 | 12.964 | 14.315 | 1.95%|-| xpfe | 11.707 | 10.972 | 11.337 | 11.267 | 11.531 | 12.907 | 13.344 | 11.754 | 11.429 | 10.915 | 11.716 | 1.59%|-| widget | 14.399 | 9.812 | 10.078 | 10.383 | 10.472 | 12.203 | 14.493 | 10.947 | 12.513 | 10.354 | 11.565 | 1.57%|-| nsprpub | 9.411 | 8.017 | 7.098 | 7.356 | 7.802 | 16.656 | 10.980 | 7.587 | 7.347 | 7.373 | 8.963 | 1.22%|-| uriloader | 8.707 | 7.224 | 7.098 | 7.859 | 8.264 | 10.349 | 11.157 | 8.413 | 7.926 | 7.313 | 8.431 | 1.15%|-| storage | 7.811 | 6.412 | 6.708 | 6.909 | 6.848 | 7.746 | 9.900 | 7.387 | 6.413 | 6.513 | 7.265 | 0.99%|-| caps | 6.484 | 5.304 | 5.288 | 5.663 | 6.321 | 6.668 | 6.985 | 6.335 | 5.529 | 5.406 | 5.998 | 0.82%|-| profile | 5.775 | 5.461 | 5.897 | 5.449 | 5.604 | 6.239 | 6.266 | 5.755 | 5.404 | 5.317 | 5.717 | 0.78%|-| xpinstall | 4.772 | 4.072 | 4.570 | 4.243 | 4.264 | 5.161 | 5.592 | 4.349 | 4.183 | 4.068 | 4.527 | 0.62%|-| sun-java | 3.528 | 3.307 | 3.214 | 3.353 | 3.557 | 4.090 | 5.230 | 3.630 | 3.271 | 3.332 | 3.651 | 0.50%|-| extensions | 3.212 | 3.358 | 4.555 | 3.236 | 3.209 | 3.381 | 3.321 | 2.930 | 3.218 | 3.225 | 3.365 | 0.46%|-| chrome | 3.428 | 3.121 | 3.026 | 3.268 | 3.209 | 3.412 | 3.733 | 3.284 | 3.113 | 3.047 | 3.264 | 0.44%|-| db | 2.898 | 2.558 | 2.543 | 2.613 | 2.672 | 2.915 | 3.232 | 2.978 | 2.554 | 2.642 | 2.761 | 0.38%|-| view | 2.768 | 2.497 | 2.434 | 2.609 | 2.570 | 2.926 | 3.120 | 2.626 | 2.832 | 2.538 | 2.692 | 0.37%|-| webshell | 2.585 | 2.477 | 2.709 | 2.541 | 2.565 | 2.946 | 3.311 | 2.745 | 2.601 | 2.437 | 2.692 | 0.37%|-| build | 2.252 | 2.066 | 2.162 | 2.139 | 2.191 | 2.201 | 3.217 | 2.232 | 2.486 | 2.054 | 2.300 | 0.31%|-| jpeg | 3.053 | 1.529 | 2.110 | 1.651 | 1.617 | 2.396 | 2.641 | 1.647 | 1.526 | 1.573 | 1.974 | 0.27%|-| config | 2.131 | 1.373 | 1.466 | 1.489 | 1.422 | 2.659 | 2.424 | 1.425 | 2.003 | 1.364 | 1.776 | 0.24%|-| probes | 0.423 | 0.426 | 0.437 | 0.455 | 0.447 | 0.422 | 0.543 | 0.435 | 0.468 | 0.412 | 0.447 | 0.06%|-|}  * File with data used to generate charts and the charts can be found here: [[Media:RebuildAnalysis.zip| Rebuild Analysis xls]] * A copy of all the logs I used or generated for the results can be found here: [[Media:BuildLogs1.zip | Build Logs Part 1]] and [[Media:BuildLogs2.zip | Build Logs Part 2]] * A copy of the rules.mk I've edited from the config folder can be found here: [[Media:rules.zip | config/rules.mk]] * An interesting and note worthy point in the analysis, is that most of these folders are visited multiple times during the build
=== Release 0.2 - Nov 10 ===
TBA==== Goal ====* Capture the processes being spawned during build along with its pid, ppid, time, duration, and working directory* Try identifying the cause for slow Windows build
=== Release 0.3 - Dec 1 ===
== Project Data ==
=== Contribution Instructions ===* Ideas on how to log the following during build time: pid, ppid, start time, end time, process name, current working directory* <strike>Please feel free to fill in the table to help me collect more data</strike>* <strike>YOU WILL BE CONSIDERED AS A PROJECT CONTRIBUTOR FOR PROVIDING DATA</strike>
* you can time your build by adding the "time" command in front of your build command like so:
** time make -f client.mk build
=== Sample Build Data ===
{| class="mediawiki sortable" border="1" cellpadding="5" cellspacing="0"
|+'''Build Time Data'''
| 1 GB
| 1.6 Duo
|-
| XP Media
| [[User:twlai1|Tony]]
|-
| 0:58:40
|-
| N/A
| 1 GB
| 1.6 Duo
|-
| Ubuntu (VirtualBox)
| [[User:twlai1|Tony]]
|-
| 0:55:00
|-
| 4
| 2.5 GB
| 1.6 AMD TurionX2
|-
| XP Professional
| [[User:zghansar|Zaid]]
| 2.5 GB
| 1.6 AMD TurionX2
|-
| XP Professional
| [[User:zghansar|Zaid]]
| 2.5 GB
| 1.6 AMD TurionX2
|-
| XP Professional
| [[User:zghansar|Zaid]]
ac_add_options --disable-optimize
ac_add_options --disable-static --enable-shared
 
</pre>
|-
|real 0:18:16<br />user 0:10:34<br />sys 0:03:0|real 0:02:59<br />user 0:04:15<br />sys 0:01:23|5|2 GB (Upgraded to more/faster rame)|2.0 Duo ( OC'd to 2.41 )|7200 (src) to External (dest) - speed bump doing this|Windows XP Professional ( 32-bit) - Visual Studio 2005|[[User:cbishop2 | Chris Bishop]]
<!-- I hope this is ok since the mozconfig can also affect performance -->
|<pre> . $topsrcdir/browser/config/mozconfig
mk_add_options MOZ_OBJDIR=/i/mozilla/ff-opt
mk_add_options MOZ_MAKE_FLAGS=-j5
</pre>
|-
 |-|real 0:29:13<br />user 0:11:26<br />sys 0:03:47|real 0:05:8<br />user 0:04:47<br />sys 0:01:43|5|1 GB|2.0 Duo ( OC'd to 2.41 )|7200|Windows XP Professional ( 32-bit)|[[User:cbishop2 | Chris Bishop]]
<!-- I hope this is ok since the mozconfig can also affect performance -->
|<pre>. $topsrcdir/browser/config/mozconfig
mk_add_options MOZ_OBJDIR=@TOPSRCDIR@/ff-opt
mk_add_options MOZ_MAKE_FLAGS=-j5
ac_add_options --disable-tests
</pre>
|-
 
|-
|real 0:36:50<br />user 0:10:44<br />sys 0:03:30
</pre>
|-
 </pre>|-|Didn't note the time.
|
'''FireFox:'''<br />real 16m12.402s<br />user 2m23.381s<br />sys 5m11.815s <br />
ac_add_options --enable-debug
mk_add_options MOZ_MAKE_FLAGS=-j5
</pre>
|-
 
</pre>
|-
ac_add_options --enable-tests
ac_add_options --enable-application=browser
</pre>
|-
 
</pre>
|-
== Project News / Updates ==
=== November 2008 ===<i>11/11/2008 -</i>* Managed to get process duration<i>11/06/2008 -</i>* Captured processes from a "do-nothing rebuild"* Posted description of CSV log on [[https://bugzilla.mozilla.org/show_bug.cgi?id=459891 Bugzilla]]* Trying to get more accurate data for Benjamin<i>11/05/2008 -</i>* Found a similar app to [[http://technet.microsoft.com/en-us/sysinternals/bb896653.aspx Process Explorer]] called [[http://technet.microsoft.com/en-us/sysinternals/bb896645.aspx Process Monitor]]** Captures: pid, ppid, start time, end time, process name** Can build log file* Posted finding on [[https://bugzilla.mozilla.org/show_bug.cgi?id=459891 Bugzilla]]* Asking for further directions/hints for project<i>11/04/2008 -</i>* Played with [[http://technet.microsoft.com/en-us/sysinternals/bb896653.aspx Process Explorer]]** Captured: pid, ppid, start time, end time, process name** Finding ways to log it === October 2008 ===<i>10/20/2008 -</i>* Redo Pie Chart** Used all 10 Rebuild Data* Changed the app to generate better extractions from logs<i>10/17/2008 -</i>
* Finished making app to extract times from log
** App breaks down log into 3 files
*** File with just level 1 directory times
* Adding times up for amount spent in each level 1 directory
* Created diagram to illustrate time breakdown<i>10/15/2008 -</i>
* Creating app to extract time from log
* Timing the build multiple times for both scratch and rebuilds (aiming for 10 builds each)
<i>10/13/2008 -</i>
* Timed time spent in each directory
* Working on extracting the data from log
<i>10/02/2008 -</i>
* Talked with Ted, guided me to look into rules.mk
* Continuing testing for timing the build
 === September 2008 ===<i>09/30/2008 -</i>
* Looked through many files and still haven't found where code for timing can go
* Suspect most options don't affect build speed, except -j and optimize
<i>09/25/2008 -</i>
* After couple more testing with the build options, starting to notice they don't make a big difference
<i>09/18/2008 -</i>
* Use time command to time build time
** ie. time make -f client.mk build
* Start collecting data
<i>09/17/2008 -</i>
* Built the first time in 1h 20m
* Rebuilt second time in 35m with all apps off
** Understand what each part of the build is taking
** Collect win32 build times from colleagues
<i>09/16/2008 -</i>
* Talked with Ted Mielczarek, briefly discussed about where to start and how to approach this project.
** Start by timing how long each make file is
** Identify which make file takes a long time
<i>09/15/2008 -</i>
* Created Project page for this project.
----
1
edit

Navigation menu