[SERVER-21336] Should be possible to use CacheDir and the MD5-Timestamp Decider together Created: 06/Nov/15  Updated: 21/Mar/19  Resolved: 13/Nov/18

Status: Closed
Project: Core Server
Component/s: Build
Affects Version/s: None
Fix Version/s: None

Type: Improvement Priority: Major - P3
Reporter: Andrew Morrow (Inactive) Assignee: bdbaddog#1
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Depends
is depended on by SERVER-33661 Make /Zi default over /Z7 on msvc Closed
Duplicate
is duplicated by SERVER-28174 make scons --cache work with --build-... Closed
Problem/Incident
causes SERVER-39467 Regression in MD5-Timestamp decider Closed
Related
is related to SERVER-33111 SCons split_dwarf tool can cause spur... Closed
Sprint: Platforms 2017-04-17, Platforms 2017-05-08, Platforms 2017-05-29, Platforms 2018-06-04, Platforms 2018-06-18, Platforms 2018-07-02, Platforms 2018-07-16, Platforms 2018-07-30, Platforms 2018-08-13, Platforms 2018-08-27, Platforms 2018-09-10, Dev Tools 2018-10-08, Dev Tools 2018-10-22, Dev Tools 2018-11-05, Dev Tools 2018-11-19
Participants:

 Description   

Currently impossible due to http://scons.tigris.org/issues/show_bug.cgi?id=2980, this ticket is here to track progress on resolving the upstream ticket.

The practical effect of this is that if you want to use CacheDir, you need to use more expensive up-to-date detection, removing some of the win of the cache.



 Comments   
Comment by Andrew Morrow (Inactive) [ 25/Jan/19 ]

I forgot to add my conclusions:

  • It is too soon to say with certainty whether the SCons 3.0.4 upgrade has fixed the ABA branch issue because we may not have accumulated enough state on the post-3.0.4 upgrade branch to trigger the bug. I will run some experiments.
  • It appears that the fixes made in SCons 3.0.4 to the MD5-Timestamp decider have a fairly seriously deleterious effect on its performance. It used to be a decent win, but now is an overall loss. I will file a new ticket to track work to improve its performance.
Comment by Andrew Morrow (Inactive) [ 25/Jan/19 ]

We upgraded to SCons 3.0.4 yesterday, so I re-ran these tests:

Type Build Rebuild Cache Rebuild
2.5.1, no cache, bfl=off 14:57.16 0:59.66  
2.5.1, no cache, bfl=on 14:56.98 0:48.29  
2.5.1, cache, bfl=off 14:57.56 0:58.47 2:55.26
2.5.1, cache, bfl=on 14:53.96 0:49.02 2:55.81
3.0.4, no cache, bfl=off 14:59.99 1:00.81  
3.0.4, no cache, bfl=on 14:57.76 1:08.39  
3.0.4, cache, bfl=off 14:56.26 1:01.19 3:10.36
3.0.4, cache, bfl=on 14:59.99 1:08.58 3:39.22

The following script was used:

#/bin/bash
 
set -o verbose
set -o errexit
 
_CommonArgs="--cache-dir=$(pwd)/cache VERBOSE=0 -j12 --implicit-cache --disable-warnings-as-errors --install-mode=hygienic --link-model=dynamic --allocator=system --js-engine=none --modules= --variables-files= --dbg=off --opt=size install-embedded-dev install-embedded-test"
 
# no scons patch, no cache, bfl=off
git checkout 90cd49725f41354509dece813343c62e6ee9f533
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off $_CommonArgs 2>&1 | tee ../scons_old_nocache_nobfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off $_CommonArgs 2>&1 | tee ../scons_old_nocache_nobfl_rebuild.log
 
 
 
# no scons patch, no cache, bfl=on
git checkout 90cd49725f41354509dece813343c62e6ee9f533
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on $_CommonArgs 2>&1 | tee ../scons_old_nocache_bfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on $_CommonArgs 2>&1 | tee ../scons_old_nocache_bfl_rebuild.log
 
 
 
# no scons patch, cache, bfl=off
git checkout 90cd49725f41354509dece813343c62e6ee9f533
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../scons_old_cache_nobfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../scons_old_cache_nobfl_rebuild.log
\rm -rf build
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../scons_old_cache_nobfl_cacherebuild.log
 
 
 
# no scons patch, cache, bfl=on
git checkout 90cd49725f41354509dece813343c62e6ee9f533
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on --cache $_CommonArgs 2>&1 | tee ../scons_old_cache_bfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on --cache $_CommonArgs 2>&1 | tee ../scons_old_cache_bfl_rebuild.log
\rm -rf build
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on --cache $_CommonArgs 2>&1 | tee ../scons_old_cache_bfl_cacherebuild.log
 
 
 
# scons patch, no cache, bfl=off
git checkout 3bd77b8400fd0b2a0b6820e2ecb0863bcf137040
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off $_CommonArgs 2>&1 | tee ../scons_new_nocache_nobfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off $_CommonArgs 2>&1 | tee ../scons_new_nocache_nobfl_rebuild.log
 
 
 
# scons patch, no cache, bfl=on
git checkout 3bd77b8400fd0b2a0b6820e2ecb0863bcf137040
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on $_CommonArgs 2>&1 | tee ../scons_new_nocache_bfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on $_CommonArgs 2>&1 | tee ../scons_new_nocache_bfl_rebuild.log
 
 
 
# scons patch, cache, bfl=off
git checkout 3bd77b8400fd0b2a0b6820e2ecb0863bcf137040
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../scons_new_cache_nobfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../scons_new_cache_nobfl_rebuild.log
\rm -rf build
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../scons_new_cache_nobfl_cacherebuild.log
 
 
 
# scons patch, cache, bfl=on
git checkout 3bd77b8400fd0b2a0b6820e2ecb0863bcf137040
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on --cache $_CommonArgs 2>&1 | tee ../scons_new_cache_bfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on --cache $_CommonArgs 2>&1 | tee ../scons_new_cache_bfl_rebuild.log
\rm -rf build
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on --cache $_CommonArgs 2>&1 | tee ../scons_new_cache_bfl_cacherebuild.log

Comment by Andrew Morrow (Inactive) [ 13/Nov/18 ]

The fix for this was merged into upstream SCons: https://github.com/SCons/scons/pull/3112

Comment by bdbaddog#1 [ 30/Aug/18 ]

 Results from perf rerun with fixed patch. (scons_2980_timestamp_md5_fix 10f201c099894fd6ae7139b4a9f0c9982c4655e1)

( https://github.com/bdbaddog/mongo/commit/10f201c099894fd6ae7139b4a9f0c9982c4655e1 )

Type Build Rebuild Cache Rebuild
no scons patch, no cache, bfl=off 4963.76 26.57  
no scons patch, no cache, bfl=on 4987.82 21.52  
no scons patch, cache, bfl=off 4978.48 27.94 66.74
scons patch, no cache, bfl=off 4997.72 27.64  
scons patch, no cache, bfl=on 5008.27 31.52  
scons patch, cache, bfl=off 4971.02 27.34 67.53
scons patch, cache, bfl=on 4986.78 30.61 83.40

 

 

Comment by Andrew Morrow (Inactive) [ 02/Aug/18 ]

I re-tested the latest (from commit 53348e50b8ef6359503c48d838fce28c29c20ad6)

I did a quick test of the r3.7.1, r3.7.2, r3.7.1 sequence from above, with good results: the third build was pure cache extraction with no rebuilds. But it seemed very slow.

So I made a variant of the script from May 4th above to test it out. Here, the branch

{scons_2980_timestamp_md5_fix}

is checked out to the above commit.

#/bin/bash
 
set -o verbose
set -o errexit
 
_CommonArgs="--cache-dir=$(pwd)/cache VERBOSE=0 -j12 --implicit-cache --disable-warnings-as-errors --install-mode=hygienic --link-model=dynamic --allocator=system --js-engine=none --modules= --variables-files= --dbg=off --opt=size install-mobile-dev install-mobile-test"
 
# no scons patch, no cache, bfl=off
git checkout fb8558b49b
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off $_CommonArgs 2>&1 | tee ../base_nocache_nobfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off $_CommonArgs 2>&1 | tee ../base_nocache_nobfl_rebuild.log
 
 
 
# no scons patch, no cache, bfl=on
git checkout fb8558b49b
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on $_CommonArgs 2>&1 | tee ../base_nocache_bfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on $_CommonArgs 2>&1 | tee ../base_nocache_bfl_rebuild.log
 
 
 
# no scons patch, cache, bfl=off
git checkout fb8558b49b
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../base_cache_nobfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../base_cache_nobfl_rebuild.log
\rm -rf build
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../base_cache_nobfl_cacherebuild.log
 
 
 
# scons patch, no cache, bfl=off
git checkout scons_2980_timestamp_md5_fix
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off $_CommonArgs 2>&1 | tee ../patch_nocache_nobfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off $_CommonArgs 2>&1 | tee ../patch_nocache_nobfl_rebuild.log
 
 
 
# scons patch, no cache, bfl=on
git checkout scons_2980_timestamp_md5_fix
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on $_CommonArgs 2>&1 | tee ../patch_nocache_bfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on $_CommonArgs 2>&1 | tee ../patch_nocache_bfl_rebuild.log
 
 
 
# scons patch, cache, bfl=off
git checkout scons_2980_timestamp_md5_fix
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../patch_cache_nobfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../patch_cache_nobfl_rebuild.log
\rm -rf build
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../patch_cache_nobfl_cacherebuild.log
 
 
 
# scons patch, cache, bfl=on
git checkout scons_2980_timestamp_md5_fix
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on --cache $_CommonArgs 2>&1 | tee ../patch_cache_bfl_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on --cache $_CommonArgs 2>&1 | tee ../patch_cache_bfl_rebuild.log
\rm -rf build
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on --cache $_CommonArgs 2>&1 | tee ../patch_cache_bfl_cacherebuild.log

The filenames give a good indication of the meaning of each build, but basically we are testing the build performance of each of an initial build, a no-op rebuild, and a pull from cache rebuild as we permute among the base commit vs the patch, build-fast-and-loose off and on, and whether or not the cache is enabled.

On my workstation, we get the following timings:

$ tail -n 3 base_nocache_nobfl_build.log base_nocache_nobfl_rebuild.log base_nocache_bfl_build.log base_nocache_bfl_rebuild.log base_cache_nobfl_build.log base_cache_nobfl_rebuild.log base_cache_nobfl_cacherebuild.log patch_nocache_nobfl_build.log patch_nocache_nobfl_rebuild.log patch_nocache_bfl_build.log patch_nocache_bfl_rebuild.log patch_cache_nobfl_build.log patch_cache_nobfl_rebuild.log patch_cache_nobfl_cacherebuild.log patch_cache_bfl_build.log patch_cache_bfl_rebuild.log patch_cache_bfl_cacherebuild.log
==> base_nocache_nobfl_build.log <==
scons: done building targets.
8818.74user 725.45system 13:51.34elapsed 1148%CPU (0avgtext+0avgdata 1270516maxresident)k
0inputs+16260440outputs (5008major+284133638minor)pagefaults 0swaps
 
==> base_nocache_nobfl_rebuild.log <==
scons: done building targets.
49.91user 1.64system 0:51.58elapsed 99%CPU (0avgtext+0avgdata 252240maxresident)k
0inputs+43664outputs (1major+262954minor)pagefaults 0swaps
 
==> base_nocache_bfl_build.log <==
scons: done building targets.
9002.12user 742.08system 14:10.45elapsed 1145%CPU (0avgtext+0avgdata 1270388maxresident)k
0inputs+16260440outputs (5008major+291906992minor)pagefaults 0swaps
 
==> base_nocache_bfl_rebuild.log <==
scons: done building targets.
39.84user 0.88system 0:40.74elapsed 99%CPU (0avgtext+0avgdata 248308maxresident)k
0inputs+43664outputs (1major+284760minor)pagefaults 0swaps
 
==> base_cache_nobfl_build.log <==
scons: done building targets.
8831.07user 732.31system 13:50.97elapsed 1150%CPU (0avgtext+0avgdata 1270596maxresident)k
0inputs+22286104outputs (5005major+286581993minor)pagefaults 0swaps
 
==> base_cache_nobfl_rebuild.log <==
scons: done building targets.
49.33user 1.84system 0:51.19elapsed 99%CPU (0avgtext+0avgdata 253148maxresident)k
0inputs+43624outputs (1major+204444minor)pagefaults 0swaps
 
==> base_cache_nobfl_cacherebuild.log <==
scons: done building targets.
122.81user 34.76system 2:07.09elapsed 123%CPU (0avgtext+0avgdata 349412maxresident)k
0inputs+7851952outputs (18major+1443032minor)pagefaults 0swaps
 
==> patch_nocache_nobfl_build.log <==
scons: done building targets.
8563.58user 695.00system 13:27.25elapsed 1146%CPU (0avgtext+0avgdata 1270640maxresident)k
0inputs+16260432outputs (5008major+283995154minor)pagefaults 0swaps
 
==> patch_nocache_nobfl_rebuild.log <==
scons: done building targets.
50.29user 1.92system 0:52.24elapsed 99%CPU (0avgtext+0avgdata 260320maxresident)k
0inputs+43664outputs (1major+327923minor)pagefaults 0swaps
 
==> patch_nocache_bfl_build.log <==
scons: done building targets.
8574.27user 652.59system 18:22.43elapsed 836%CPU (0avgtext+0avgdata 1270384maxresident)k
8inputs+16260448outputs (5008major+281367949minor)pagefaults 0swaps
 
==> patch_nocache_bfl_rebuild.log <==
scons: done building targets.
2037.37user 1.40system 33:58.75elapsed 100%CPU (0avgtext+0avgdata 256920maxresident)k
0inputs+43664outputs (1major+706378minor)pagefaults 0swaps
 
==> patch_cache_nobfl_build.log <==
scons: done building targets.
8402.19user 685.81system 13:11.72elapsed 1147%CPU (0avgtext+0avgdata 1270440maxresident)k
0inputs+22286112outputs (5005major+282605288minor)pagefaults 0swaps
 
==> patch_cache_nobfl_rebuild.log <==
scons: done building targets.
50.36user 1.86system 0:52.23elapsed 99%CPU (0avgtext+0avgdata 257296maxresident)k
0inputs+43632outputs (1major+273131minor)pagefaults 0swaps
 
==> patch_cache_nobfl_cacherebuild.log <==
scons: done building targets.
118.73user 37.41system 2:08.93elapsed 121%CPU (0avgtext+0avgdata 357112maxresident)k
0inputs+7851960outputs (18major+1617572minor)pagefaults 0swaps
 
==> patch_cache_bfl_build.log <==
scons: done building targets.
8884.39user 679.86system 18:41.92elapsed 852%CPU (0avgtext+0avgdata 1270324maxresident)k
0inputs+22286096outputs (5005major+282502688minor)pagefaults 0swaps
 
==> patch_cache_bfl_rebuild.log <==
scons: done building targets.
2012.64user 2.35system 33:35.01elapsed 99%CPU (0avgtext+0avgdata 258616maxresident)k
0inputs+43632outputs (1major+1027599minor)pagefaults 0swaps
 
==> patch_cache_bfl_cacherebuild.log <==
scons: done building targets.
834.71user 75.28system 13:55.51elapsed 108%CPU (0avgtext+0avgdata 356292maxresident)k
0inputs+7851952outputs (18major+1751715minor)pagefaults 0swaps

Interesting observations:

  • As known before, using --build-fast-and-loose=on is worth about 10 seconds in the no-op rebuild time.
  • With --build-fast-and-loose=off, the patch is no worse than baseline
  • Enabling --build-fast-and-loose with the patch results in huge runtimes.
Comment by Andrew Morrow (Inactive) [ 04/May/18 ]

It seems likely that the fix for this issue may have also resolved SERVER-33111. Adding CCFLAGS=-gsplit-dwarf to the repro script above resulted in unexpected rebuilds in the first experiment, but no unexpected rebuilds in any experiments that incorporated the patch.

Comment by Andrew Morrow (Inactive) [ 04/May/18 ]

#/bin/bash
 
set -o verbose
set -o errexit
 
_CommonArgs="--cache-dir=$(pwd)/cache VERBOSE=0 -j12 --implicit-cache --disable-warnings-as-errors --install-mode=hygienic --link-model=dynamic --allocator=system --js-engine=none --modules= --variables-files= --dbg=off --opt=size install-mobile-dev install-mobile-test"
 
# no scons patch, no cache, bfl=off
git checkout master
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off $_CommonArgs 2>&1 | tee ../exp_1_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off $_CommonArgs 2>&1 | tee ../exp_1_rebuild.log
 
 
 
# scons patch, no cache, bfl=off
git checkout bd-scons-deps-fix
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off $_CommonArgs 2>&1 | tee ../exp_2_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off $_CommonArgs 2>&1 | tee ../exp_2_rebuild.log
 
 
# scons patch, no cache, bfl=on
git checkout bd-scons-deps-fix
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on $_CommonArgs 2>&1 | tee ../exp_3_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on $_CommonArgs 2>&1 | tee ../exp_3_rebuild.log
 
 
 
# scons patch, cache, bfl=off
git checkout bd-scons-deps-fix
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../exp_4_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../exp_4_rebuild.log
\rm -rf build
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=off --cache $_CommonArgs 2>&1 | tee ../exp_4_cacherebuild.log
 
 
# scons patch, cache, bfl=on
git checkout bd-scons-deps-fix
git clean -xfd
mkdir cache
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on --cache $_CommonArgs 2>&1 | tee ../exp_5_build.log
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on --cache $_CommonArgs 2>&1 | tee ../exp_5_rebuild.log
\rm -rf build
/usr/bin/time python ./buildscripts/scons.py --build-fast-and-loose=on --cache $_CommonArgs 2>&1 | tee ../exp_5_cacherebuild.log

Where the gist above is on the branch bd-scons-deps-fix.

We find the following build timings:

$ tail -n 5 $(ls -1rt ../*rebuild.log)
==> ../exp_1_rebuild.log <==
scons: `install-mobile-dev' is up to date.
scons: `install-mobile-test' is up to date.
scons: done building targets.
51.51user 1.85system 0:53.38elapsed 99%CPU (0avgtext+0avgdata 256168maxresident)k
0inputs+45584outputs (1major+363232minor)pagefaults 0swaps
 
==> ../exp_2_rebuild.log <==
scons: `install-mobile-dev' is up to date.
scons: `install-mobile-test' is up to date.
scons: done building targets.
56.46user 1.96system 0:58.45elapsed 99%CPU (0avgtext+0avgdata 258872maxresident)k
0inputs+45576outputs (1major+342223minor)pagefaults 0swaps
 
==> ../exp_3_rebuild.log <==
scons: `install-mobile-dev' is up to date.
scons: `install-mobile-test' is up to date.
scons: done building targets.
47.63user 0.81system 0:48.46elapsed 99%CPU (0avgtext+0avgdata 257372maxresident)k
0inputs+45576outputs (1major+225487minor)pagefaults 0swaps
 
==> ../exp_4_rebuild.log <==
scons: `install-mobile-dev' is up to date.
scons: `install-mobile-test' is up to date.
scons: done building targets.
57.45user 1.82system 0:59.54elapsed 99%CPU (0avgtext+0avgdata 256680maxresident)k
0inputs+45536outputs (1major+261003minor)pagefaults 0swaps
 
==> ../exp_4_cacherebuild.log <==
Install file: "build/cached/mongo/client/embedded/mongo_embedded_capi_test" as "build/install/bin/mongo_embedded_capi_test"
Install file: "build/cached/mongo/client/embedded/mongoe" as "build/install/bin/mongoe"
scons: done building targets.
129.51user 37.11system 2:15.73elapsed 122%CPU (0avgtext+0avgdata 359712maxresident)k
8inputs+7725960outputs (17major+1540464minor)pagefaults 0swaps
 
==> ../exp_5_rebuild.log <==
scons: `install-mobile-dev' is up to date.
scons: `install-mobile-test' is up to date.
scons: done building targets.
46.47user 0.83system 0:47.32elapsed 99%CPU (0avgtext+0avgdata 255532maxresident)k
0inputs+45536outputs (1major+264227minor)pagefaults 0swaps
 
==> ../exp_5_cacherebuild.log <==
Install file: "build/cached/mongo/client/embedded/mongoe" as "build/install/bin/mongoe"
Install file: "build/cached/mongo/client/embedded/mongo_embedded_capi_test" as "build/install/bin/mongo_embedded_capi_test"
scons: done building targets.
129.43user 37.43system 2:17.84elapsed 121%CPU (0avgtext+0avgdata 361196maxresident)k
8inputs+7725960outputs (17major+1643534minor)pagefaults 0swaps

From this, we can draw the following conclusions:

  • The proposed patch increases no-op rebuild time by about 10%, going from 53 to 58 seconds.
  • Without the cache, enabling the MD5-Timestamp decider saves about 10 seconds, going from 58 to 48 seconds.
  • With the cache, enabling the MD5-Timestamp decider saves about 13 seconds, going from 60 seconds to 47.
  • The builds where we do no work but extract from the cache have not gotten faster, and are probably limited by some other factor.

Overall, this is still a good outcome: while the overall scan is a little slower, we gain back more time than we give up.

Comment by Andrew Morrow (Inactive) [ 04/May/18 ]

I've just confirmed that after locally applying https://gist.github.com/bdbaddog/9bb70b7e1e440f43984c68d1a2f6928f, the the re-compilations on the third build no longer occur. The third build is entirely an extraction from cache.

I will follow up with some performance numbers I gathered yesterday, but it looks like we have a path towards resolving this longstanding issue.

Comment by Andrew Morrow (Inactive) [ 04/May/18 ]

bdbaddog - I'm just documenting the repro steps for the known issue, and then I'm going to update with the link to the gist with the fix. More just ensuring that we can find this info from the ticket, rather than private email discussion.

Comment by Andrew Morrow (Inactive) [ 04/May/18 ]

Reproduction steps:

> git clean -xfd
> git checkout r3.7.1
> /usr/bin/time python ./buildscripts/scons.py --ssl --link-model=dynamic --implicit-cache -j 12 --disable-warnings-as-errors --cache --build-fast-and-loose=on --modules= --variables-files= ./mongod
> git checkout r3.7.2
> /usr/bin/time python ./buildscripts/scons.py --ssl --link-model=dynamic --implicit-cache -j 12 --disable-warnings-as-errors --cache --build-fast-and-loose=on --modules= --variables-files= ./mongod
> git checkout r3.7.1
> /usr/bin/time python ./buildscripts/scons.py --ssl --link-model=dynamic --implicit-cache -j 12 --disable-warnings-as-errors --cache --build-fast-and-loose=on --modules= --variables-files= ./mongod 

The third build should be entirely cache extraction, however, sometimes we see files get rebuilt, like this:

scons: done reading SConscript files.
scons: Building targets ...
Retrieved `build/cached/mongo/base/error_codes.h' from cache
Retrieved `build/cached/mongo/base/error_codes.cpp' from cache
Retrieved `build/cached/mongo/util/quick_exit.os' from cache
Retrieved `build/cached/third_party/gperftools-2.5/src/static_vars.os' from cache
Retrieved `build/cached/third_party/gperftools-2.5/src/common.os' from cache
Retrieved `build/cached/third_party/gperftools-2.5/src/page_heap.os' from cache
Retrieved `build/cached/third_party/gperftools-2.5/src/stack_trace_table.os' from cache
Retrieved `build/cached/third_party/gperftools-2.5/src/system-alloc.os' from cache
Retrieved `build/cached/third_party/gperftools-2.5/src/tcmalloc.os' from cache
Retrieved `build/cached/third_party/gperftools-2.5/src/malloc_hook.os' from cache
Retrieved `build/cached/third_party/gperftools-2.5/src/emergency_malloc_for_stacktrace.os' from cache
Retrieved `build/cached/third_party/gperftools-2.5/src/base/spinlock.os' from cache
Retrieved `build/cached/third_party/gperftools-2.5/src/thread_cache.os' from cache
Compiling build/cached/third_party/murmurhash3/MurmurHash3.os
Retrieved `build/cached/third_party/gperftools-2.5/src/span.os' from cache 

Comment by bdbaddog#1 [ 02/Apr/18 ]

Any luck with a reproducer from your source tree?

Comment by bdbaddog#1 [ 23/Mar/18 ]

Updating link to referenced bug to point at github as tigris' bugtracker is no longer the official bugtracker of SCons project.

https://github.com/SCons/scons/issues/2980

Generated at Thu Feb 08 03:57:03 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.