Try using precompiled headers to speed up tests

[seantalts]

Submission Checklist

• Run unit tests: ./runTests.py test/unit
• Run cpplint: make cpplint
• Declare copyright holder and open-source license: see below

Copyright and Licensing

Please list the copyright holder for the work you are submitting (this will be you or your assignee, such as a university or company): Columbia University

By submitting this pull request, the copyright holder is agreeing to license the submitted work under the following licenses:

• Code: BSD 3-clause (https://opensource.org/licenses/BSD-3-Clause)
• Documentation: CC-BY 4.0 (https://creativecommons.org/licenses/by/4.0/)

[seantalts]

In my local tests, this speeds up some of the tests with heavier includes by about 25% :)

[bob-carpenter]

That's fantastic!

…

In my local tests, this speeds up some of the tests with heavier includes by about 25% :)

[seantalts]

I think this is ready for review - but it only saves 6 minutes from the new distribution tests (out of 103 minutes) and 12 minutes (out of 28 - down to 16 minutes) on the Unit tests.

[seantalts]

Does @syclik or @sakrejda want to take a look at this for me? Still working on that PR triage system, haha.

[syclik]

So... I don't think it works. Here's what I tried from a clean build:

./runTests.py test/unit/math/rev/scal/fun/log2_test.cpp
touch stan/math/prim/scal/fun/log2.hpp 
./runTests.py test/unit/math/rev/scal/fun/log2_test.cpp

After that second time of trying to build the test, I see this (which is not what you see in the current develop branch):

make -j1 test/unit/math/rev/scal/fun/log2_test
clang++ -Wall -I . -isystem lib/eigen_3.3.3 -isystem lib/boost_1.64.0 -isystem lib/cvodes_2.9.0/include -std=c++1y -DBOOST_RESULT_OF_USE_TR1 -DBOOST_NO_DECLTYPE -DBOOST_DISABLE_ASSERTS -DBOOST_PHOENIX_NO_VARIADIC_EXPRESSION -Wno-unused-function -Wno-uninitialized -stdlib=libc++ -Wno-unknown-warning-option -Wno-tautological-compare -Wsign-compare -DGTEST_USE_OWN_TR1_TUPLE -isystem lib/gtest_1.7.0/include -isystem lib/gtest_1.7.0 -O3 -DGTEST_USE_OWN_TR1_TUPLE -isystem lib/gtest_1.7.0/include -isystem lib/gtest_1.7.0 -O3 -DNO_FPRINTF_OUTPUT -pipe  -c -include-pch stan/math/rev/scal.hpp.gch -o test/unit/math/rev/scal/fun/log2_test.o test/unit/math/rev/scal/fun/log2_test.cpp
fatal error: file 'stan/math/prim/scal/fun/log2.hpp' has been modified since the
      precompiled header 'stan/math/rev/scal.hpp.gch' was built
note: please rebuild precompiled header 'stan/math/rev/scal.hpp.gch'
1 error generated.
make: *** [test/unit/math/rev/scal/fun/log2_test.o] Error 1
make -j1 test/unit/math/rev/scal/fun/log2_test failed

[seantalts]

Good call, I didn't test that because I usually just recompile everything anyway out of caution. Will fix.

[seantalts]

Oh right, and here's the reason:

make: `test/unit/math/rev/scal/fun/log2_test' is up to date.

Make isn't set up to actually do proper dependency analysis. I would argue the current behavior is preferable as it lets you know when you're testing something that's out of date. Should we fix make's dependency resolution problems in this branch or start a new one?

[syclik]

can you clarify? I don't understand what you posted.

[syclik]

And here's the behavior, as expected, on develop:

$ ./runTests.py test/unit/math/rev/scal/fun/log2_test.cpp
------------------------------------------------------------
make -j1 test/unit/math/rev/scal/fun/log2_test
make: `test/unit/math/rev/scal/fun/log2_test' is up to date.
------------------------------------------------------------
test/unit/math/rev/scal/fun/log2_test --gtest_output="xml:test/unit/math/rev/scal/fun/log2_test.xml"
Running main() from gtest_main.cc
[==========] Running 3 tests from 1 test case.
[----------] Global test environment set-up.
[----------] 3 tests from AgradRev
[ RUN      ] AgradRev.log2
[       OK ] AgradRev.log2 (0 ms)
[ RUN      ] AgradRev.log2_NaN
[       OK ] AgradRev.log2_NaN (0 ms)
[ RUN      ] AgradRev.check_varis_on_stack
[       OK ] AgradRev.check_varis_on_stack (0 ms)
[----------] 3 tests from AgradRev (0 ms total)

[----------] Global test environment tear-down
[==========] 3 tests from 1 test case ran. (0 ms total)
[  PASSED  ] 3 tests.
$ touch stan/math/prim/scal/fun/log2.hpp 
$ ./runTests.py test/unit/math/rev/scal/fun/log2_test.cpp
------------------------------------------------------------
make -j1 test/unit/math/rev/scal/fun/log2_test
clang++ -Wall -I . -isystem lib/eigen_3.3.3 -isystem lib/boost_1.64.0 -isystem lib/cvodes_2.9.0/include -std=c++1y -DBOOST_RESULT_OF_USE_TR1 -DBOOST_NO_DECLTYPE -DBOOST_DISABLE_ASSERTS -DBOOST_PHOENIX_NO_VARIADIC_EXPRESSION -Wno-unused-function -Wno-uninitialized -stdlib=libc++ -Wno-unknown-warning-option -Wno-tautological-compare -Wsign-compare -DGTEST_USE_OWN_TR1_TUPLE -isystem lib/gtest_1.7.0/include -isystem lib/gtest_1.7.0 -O3 -DGTEST_USE_OWN_TR1_TUPLE -isystem lib/gtest_1.7.0/include -isystem lib/gtest_1.7.0 -O3 -DNO_FPRINTF_OUTPUT -pipe  -c -o test/unit/math/rev/scal/fun/log2_test.o test/unit/math/rev/scal/fun/log2_test.cpp
clang++ -Wall -I . -isystem lib/eigen_3.3.3 -isystem lib/boost_1.64.0 -isystem lib/cvodes_2.9.0/include -std=c++1y -DBOOST_RESULT_OF_USE_TR1 -DBOOST_NO_DECLTYPE -DBOOST_DISABLE_ASSERTS -DBOOST_PHOENIX_NO_VARIADIC_EXPRESSION -Wno-unused-function -Wno-uninitialized -stdlib=libc++ -Wno-unknown-warning-option -Wno-tautological-compare -Wsign-compare -DGTEST_USE_OWN_TR1_TUPLE -isystem lib/gtest_1.7.0/include -isystem lib/gtest_1.7.0 -O3 -DNO_FPRINTF_OUTPUT -pipe   -o test/unit/math/rev/scal/fun/log2_test test/unit/math/rev/scal/fun/log2_test.o lib/gtest_1.7.0/src/gtest_main.cc lib/gtest_1.7.0/src/gtest-all.o
------------------------------------------------------------
test/unit/math/rev/scal/fun/log2_test --gtest_output="xml:test/unit/math/rev/scal/fun/log2_test.xml"
Running main() from gtest_main.cc
[==========] Running 3 tests from 1 test case.
[----------] Global test environment set-up.
[----------] 3 tests from AgradRev
[ RUN      ] AgradRev.log2
[       OK ] AgradRev.log2 (0 ms)
[ RUN      ] AgradRev.log2_NaN
[       OK ] AgradRev.log2_NaN (0 ms)
[ RUN      ] AgradRev.check_varis_on_stack
[       OK ] AgradRev.check_varis_on_stack (0 ms)
[----------] 3 tests from AgradRev (0 ms total)

[----------] Global test environment tear-down
[==========] 3 tests from 1 test case ran. (0 ms total)
[  PASSED  ] 3 tests.

[syclik]

Not easy to see in the output above, but what I'm showing is on develop, if I update the source file, it will automatically rebuild the test.

[seantalts]

Interesting, apparently if I touch it soon enough after making it make considers that to be the same time. If I wait a second it does as you show! My bad. Still trying to fix...

[syclik]

I remember looking up how it does time resolution at one point. It’s timestamp based, but I think dependent on implementation. I think the right fix would be to add the .gch file to the LHS of the make target generated in the .d file. The .d files are generated using the compiler’s dependency flag then modified with the right targets using sed.

…

On Nov 7, 2017, at 12:25 PM, seantalts ***@***.***> wrote: Interesting, apparently if I touch it soon enough after making it make considers that to be the same time. If I wait a second it does as you show! My bad. Still trying to fix... — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or mute the thread.

[seantalts]

I'm not sure how to do that without repeating my logic for figuring out which header file to pre-compile, any suggestions? The commit I pushed generates a .d file for the 14 or so "end-user" includes (like prim/scal.hpp) and include those. It's not great.

[syclik]

I'll look into this later this week.

[seantalts]

I think it might be best to fix it to do as you said above, I just haven't had time recently to work on it and might not for the next few weeks. Should I close the PR for now?

[syclik]

@seantalts, up to you. Or maybe mark this as "WIP" in the title?

[seantalts]

Yeah let me just close this for now. Hope to get to it in the next few weeks.