Re: is ccache working effectively?
On 2018-11-21 04:16, Maurizio Cimadamore wrote: On 20/11/2018 11:49, Magnus Ihse Bursie wrote: On 2018-11-09 11:09, Maurizio Cimadamore wrote: That does the trick, thanks. If ccache and PCH is so bad in combination, maybe we should not allow it? Like turning off PCH by default of --enacle-ccache is given? Or at least *warn* that this combination is no good? That sounds like a good idea I know it has worked in the past, even if the effectiveness does go down, it shouldn't be a net loss. There is something weird going on here that would need some investigation but I'm pretty sure it can be fixed. /Erik Maurizio /Magnus I take a very small hit in the cold cache case, but then I get huge boost once the cache is hot. cache hit (direct) 1629 cache hit (preprocessed) 115 cache miss 1 cache hit rate 99.94 % cleanups performed 0 files in cache 5121 cache size 317.6 MB max cache size 5.0 GB And, in my laptop the clean/build time went down from 11 mins to 3 :-) Maurizio On 09/11/2018 00:24, Erik Joelsson wrote: You can try --disable-precompiled-headers and see if that helps. We have had special considerations for combining these features in the past, but it's certainly a source of trouble for ccache. /Erik On 2018-11-08 16:20, Maurizio Cimadamore wrote: On 08/11/2018 20:31, Erik Joelsson wrote: I think we need more details here to figure it out, but it doesn't surprise me that hotspot is the part that's failing. Building hotspot is way more complex than the rest. Digging more into the command lines of the various HS files, they include many generated sources and, also this folder: build//hotspot/variant-server/libjvm/objs/precompiled Now, I don't know exactly how ccache deals with PCH but I notices that every time that the files in this folder are regenerated by the build (I can easily do that by rerunning the same command line that is stored inside the , a ccache miss follows. Maurizio
Re: is ccache working effectively?
On 20/11/2018 11:49, Magnus Ihse Bursie wrote: On 2018-11-09 11:09, Maurizio Cimadamore wrote: That does the trick, thanks. If ccache and PCH is so bad in combination, maybe we should not allow it? Like turning off PCH by default of --enacle-ccache is given? Or at least *warn* that this combination is no good? That sounds like a good idea Maurizio /Magnus I take a very small hit in the cold cache case, but then I get huge boost once the cache is hot. cache hit (direct) 1629 cache hit (preprocessed) 115 cache miss 1 cache hit rate 99.94 % cleanups performed 0 files in cache 5121 cache size 317.6 MB max cache size 5.0 GB And, in my laptop the clean/build time went down from 11 mins to 3 :-) Maurizio On 09/11/2018 00:24, Erik Joelsson wrote: You can try --disable-precompiled-headers and see if that helps. We have had special considerations for combining these features in the past, but it's certainly a source of trouble for ccache. /Erik On 2018-11-08 16:20, Maurizio Cimadamore wrote: On 08/11/2018 20:31, Erik Joelsson wrote: I think we need more details here to figure it out, but it doesn't surprise me that hotspot is the part that's failing. Building hotspot is way more complex than the rest. Digging more into the command lines of the various HS files, they include many generated sources and, also this folder: build//hotspot/variant-server/libjvm/objs/precompiled Now, I don't know exactly how ccache deals with PCH but I notices that every time that the files in this folder are regenerated by the build (I can easily do that by rerunning the same command line that is stored inside the , a ccache miss follows. Maurizio
Re: is ccache working effectively?
On 2018-11-09 11:09, Maurizio Cimadamore wrote: That does the trick, thanks. If ccache and PCH is so bad in combination, maybe we should not allow it? Like turning off PCH by default of --enacle-ccache is given? Or at least *warn* that this combination is no good? /Magnus I take a very small hit in the cold cache case, but then I get huge boost once the cache is hot. cache hit (direct) 1629 cache hit (preprocessed) 115 cache miss 1 cache hit rate 99.94 % cleanups performed 0 files in cache 5121 cache size 317.6 MB max cache size 5.0 GB And, in my laptop the clean/build time went down from 11 mins to 3 :-) Maurizio On 09/11/2018 00:24, Erik Joelsson wrote: You can try --disable-precompiled-headers and see if that helps. We have had special considerations for combining these features in the past, but it's certainly a source of trouble for ccache. /Erik On 2018-11-08 16:20, Maurizio Cimadamore wrote: On 08/11/2018 20:31, Erik Joelsson wrote: I think we need more details here to figure it out, but it doesn't surprise me that hotspot is the part that's failing. Building hotspot is way more complex than the rest. Digging more into the command lines of the various HS files, they include many generated sources and, also this folder: build//hotspot/variant-server/libjvm/objs/precompiled Now, I don't know exactly how ccache deals with PCH but I notices that every time that the files in this folder are regenerated by the build (I can easily do that by rerunning the same command line that is stored inside the , a ccache miss follows. Maurizio
Re: is ccache working effectively?
That does the trick, thanks. I take a very small hit in the cold cache case, but then I get huge boost once the cache is hot. cache hit (direct) 1629 cache hit (preprocessed) 115 cache miss 1 cache hit rate 99.94 % cleanups performed 0 files in cache 5121 cache size 317.6 MB max cache size 5.0 GB And, in my laptop the clean/build time went down from 11 mins to 3 :-) Maurizio On 09/11/2018 00:24, Erik Joelsson wrote: You can try --disable-precompiled-headers and see if that helps. We have had special considerations for combining these features in the past, but it's certainly a source of trouble for ccache. /Erik On 2018-11-08 16:20, Maurizio Cimadamore wrote: On 08/11/2018 20:31, Erik Joelsson wrote: I think we need more details here to figure it out, but it doesn't surprise me that hotspot is the part that's failing. Building hotspot is way more complex than the rest. Digging more into the command lines of the various HS files, they include many generated sources and, also this folder: build//hotspot/variant-server/libjvm/objs/precompiled Now, I don't know exactly how ccache deals with PCH but I notices that every time that the files in this folder are regenerated by the build (I can easily do that by rerunning the same command line that is stored inside the , a ccache miss follows. Maurizio
Re: is ccache working effectively?
You can try --disable-precompiled-headers and see if that helps. We have had special considerations for combining these features in the past, but it's certainly a source of trouble for ccache. /Erik On 2018-11-08 16:20, Maurizio Cimadamore wrote: On 08/11/2018 20:31, Erik Joelsson wrote: I think we need more details here to figure it out, but it doesn't surprise me that hotspot is the part that's failing. Building hotspot is way more complex than the rest. Digging more into the command lines of the various HS files, they include many generated sources and, also this folder: build//hotspot/variant-server/libjvm/objs/precompiled Now, I don't know exactly how ccache deals with PCH but I notices that every time that the files in this folder are regenerated by the build (I can easily do that by rerunning the same command line that is stored inside the , a ccache miss follows. Maurizio
Re: is ccache working effectively?
On 08/11/2018 20:31, Erik Joelsson wrote: I think we need more details here to figure it out, but it doesn't surprise me that hotspot is the part that's failing. Building hotspot is way more complex than the rest. Digging more into the command lines of the various HS files, they include many generated sources and, also this folder: build//hotspot/variant-server/libjvm/objs/precompiled Now, I don't know exactly how ccache deals with PCH but I notices that every time that the files in this folder are regenerated by the build (I can easily do that by rerunning the same command line that is stored inside the , a ccache miss follows. Maurizio
Re: is ccache working effectively?
Hello, On 2018-11-08 10:58, Maurizio Cimadamore wrote: Hi, I've observed that the time spent in C/CPP compilation during a JDK build seems to have crept higher lately. By monitoring processes during the build I found an awful lot of c++ compilations taking place, which was surprising since I'm setup to use ccache. Interesting, I stopped using it myself a long time ago. So I decided to run some more precise analysis of what's going on - and I set up builds in two machine (one with Ubuntu 16.04 and another with Ubuntu 18.04) and monitor ccache statistics; the results I got in both machines are very similar, ruling out toolchain issues and the likes (I think). So, I started up by resetting ccache stats history with $ ccache -z then cleared ccache $ ccache -C then fired up a release build: $ make clean images After which I displayed ccache stats: $ ccache -s stats zero time Thu Nov 8 18:05:19 2018 cache hit (direct) 0 cache hit (preprocessed) 0 cache miss 1747 cache hit rate 0.00 % cleanups performed 16 files in cache 5222 cache size 410.5 MB max cache size 5.0 GB Ok, that's fine, all misses - after all I just cleared up everything. So, I cleaned and built everything again: $ make clean images And queried stats from ccache once more: $ ccache -s cache hit (direct) 785 cache hit (preprocessed) 8 cache miss 2701 cache hit rate 22.70 % cleanups performed 16 files in cache 7126 cache size 719.6 MB max cache size 5.0 GB Now, ignoring the percentage displayed by ccache, I think if we put together the numbers in both runs we get a hit ratio of: (785 + 8) / 1747 = 45.39% While this looks correct, you can reset stats after priming the cache to get exactly the numbers you seek. So, we get an hit for slightly less than all the compilation that run on ccache; how is that possible since no file in the repo actually changed? I remember than few years ago, doing a clean build with an hot ccache would result in massive speedup, with very very little c++ compilation going on; this is clearly no longer the case; what has changed - and, more importantly, is the change deliberate? Not deliberate, just not noticed and prioritized. ccache only really shines if you do clean rebuilds of the same source multiple times. In hotspot, the cache is basically invalidated completely as soon as a header file is touched, so developers there have no use for it. Same thing happens if you pull changes from upstream. Because of this I expect that using it is rare, which is also why it hasn't received much love lately. Btw, I also tried to get ccache to dump whatever it was doing (by exporting the variable CCACHE_LOGFILE) - and I got a lot of stuff like this: I think we need more details here to figure it out, but it doesn't surprise me that hotspot is the part that's failing. Building hotspot is way more complex than the rest. /Erik [2018-11-08T18:33:17.787569 31608] Preprocessor created ../../build/linux-x86_64-server-slowdebug/hotspot/variant-server/libjvm/objs/weakHandle.d [2018-11-08T18:33:17.787621 31608] Object file /home/maurizio/.ccache/6/3/5b851dd4174db423c3fb55fd7f1235-13635.o not in cache [2018-11-08T18:33:17.787718 31608] Running real compiler -- [2018-11-08T18:33:20.184685 31659] Preprocessor created ../../build/linux-x86_64-server-slowdebug/hotspot/variant-server/libjvm/objs/weakProcessorPhaseTimes.d [2018-11-08T18:33:20.184751 31659] Object file /home/maurizio/.ccache/1/7/190bc529eb14c5bda3c89daba9a5e5-50508.o not in cache [2018-11-08T18:33:20.184843 31659] Running real compiler -- [2018-11-08T18:33:20.247227 31668] Preprocessor created ../../build/linux-x86_64-server-slowdebug/hotspot/variant-server/libjvm/objs/weakProcessorPhases.d [2018-11-08T18:33:20.247270 31668] Object file /home/maurizio/.ccache/a/4/80bfe54bd0bf9c021aa7389bd7012f-10398.o not in cache [2018-11-08T18:33:20.247349 31668] Running real compiler -- [2018-11-08T18:33:21.085803 31692] Preprocessor created ../../build/linux-x86_64-server-slowdebug/hotspot/variant-server/libjvm/objs/workerDataArray.d [2018-11-08T18:33:21.085848 31692] Object file /home/maurizio/.ccache/b/1/a69dc0b13132029886e1155b39acd2-24155.o not in cache [2018-11-08T18:33:21.085936 31692] Running real compiler -- [2018-11-08T18:33:21.184015 31682] Preprocessor created ../../build/linux-x86_64-server-slowdebug/hotspot/variant-server/libjvm/objs/whitebox.d [2018-11-08T18:33:21.184060 31682] Object file /home/maurizio/.ccache/3/d/5ebb87455fe07d2a8866ff30c48338-959488.o not in cache [2018-11-08T18:33:21.184150 31682] Running real compiler -- [2018-11-08T18:33:21.433881 31703]
is ccache working effectively?
Hi, I've observed that the time spent in C/CPP compilation during a JDK build seems to have crept higher lately. By monitoring processes during the build I found an awful lot of c++ compilations taking place, which was surprising since I'm setup to use ccache. So I decided to run some more precise analysis of what's going on - and I set up builds in two machine (one with Ubuntu 16.04 and another with Ubuntu 18.04) and monitor ccache statistics; the results I got in both machines are very similar, ruling out toolchain issues and the likes (I think). So, I started up by resetting ccache stats history with $ ccache -z then cleared ccache $ ccache -C then fired up a release build: $ make clean images After which I displayed ccache stats: $ ccache -s stats zero time Thu Nov 8 18:05:19 2018 cache hit (direct) 0 cache hit (preprocessed) 0 cache miss 1747 cache hit rate 0.00 % cleanups performed 16 files in cache 5222 cache size 410.5 MB max cache size 5.0 GB Ok, that's fine, all misses - after all I just cleared up everything. So, I cleaned and built everything again: $ make clean images And queried stats from ccache once more: $ ccache -s cache hit (direct) 785 cache hit (preprocessed) 8 cache miss 2701 cache hit rate 22.70 % cleanups performed 16 files in cache 7126 cache size 719.6 MB max cache size 5.0 GB Now, ignoring the percentage displayed by ccache, I think if we put together the numbers in both runs we get a hit ratio of: (785 + 8) / 1747 = 45.39% So, we get an hit for slightly less than all the compilation that run on ccache; how is that possible since no file in the repo actually changed? I remember than few years ago, doing a clean build with an hot ccache would result in massive speedup, with very very little c++ compilation going on; this is clearly no longer the case; what has changed - and, more importantly, is the change deliberate? Btw, I also tried to get ccache to dump whatever it was doing (by exporting the variable CCACHE_LOGFILE) - and I got a lot of stuff like this: [2018-11-08T18:33:17.787569 31608] Preprocessor created ../../build/linux-x86_64-server-slowdebug/hotspot/variant-server/libjvm/objs/weakHandle.d [2018-11-08T18:33:17.787621 31608] Object file /home/maurizio/.ccache/6/3/5b851dd4174db423c3fb55fd7f1235-13635.o not in cache [2018-11-08T18:33:17.787718 31608] Running real compiler -- [2018-11-08T18:33:20.184685 31659] Preprocessor created ../../build/linux-x86_64-server-slowdebug/hotspot/variant-server/libjvm/objs/weakProcessorPhaseTimes.d [2018-11-08T18:33:20.184751 31659] Object file /home/maurizio/.ccache/1/7/190bc529eb14c5bda3c89daba9a5e5-50508.o not in cache [2018-11-08T18:33:20.184843 31659] Running real compiler -- [2018-11-08T18:33:20.247227 31668] Preprocessor created ../../build/linux-x86_64-server-slowdebug/hotspot/variant-server/libjvm/objs/weakProcessorPhases.d [2018-11-08T18:33:20.247270 31668] Object file /home/maurizio/.ccache/a/4/80bfe54bd0bf9c021aa7389bd7012f-10398.o not in cache [2018-11-08T18:33:20.247349 31668] Running real compiler -- [2018-11-08T18:33:21.085803 31692] Preprocessor created ../../build/linux-x86_64-server-slowdebug/hotspot/variant-server/libjvm/objs/workerDataArray.d [2018-11-08T18:33:21.085848 31692] Object file /home/maurizio/.ccache/b/1/a69dc0b13132029886e1155b39acd2-24155.o not in cache [2018-11-08T18:33:21.085936 31692] Running real compiler -- [2018-11-08T18:33:21.184015 31682] Preprocessor created ../../build/linux-x86_64-server-slowdebug/hotspot/variant-server/libjvm/objs/whitebox.d [2018-11-08T18:33:21.184060 31682] Object file /home/maurizio/.ccache/3/d/5ebb87455fe07d2a8866ff30c48338-959488.o not in cache [2018-11-08T18:33:21.184150 31682] Running real compiler -- [2018-11-08T18:33:21.433881 31703] Preprocessor created ../../build/linux-x86_64-server-slowdebug/hotspot/variant-server/libjvm/objs/workgroup.d [2018-11-08T18:33:21.433940 31703] Object file /home/maurizio/.ccache/c/8/f2bc626039e475a9a03c8f884ccd3e-32923.o not in cache [2018-11-08T18:33:21.434029 31703] Running real compiler -- [2018-11-08T18:33:21.684945 31722] Preprocessor created ../../build/linux-x86_64-server-slowdebug/hotspot/variant-server/libjvm/objs/writeableFlags.d [2018-11-08T18:33:21.685005 31722] Object file /home/maurizio/.ccache/e/1/ee622e320e77e144a1c731509ef382-26538.o not in cache [2018-11-08T18:33:21.685097 31722] Running real compiler -- [2018-11-08T18:33:21.704748 31732] Preprocessor created ../../build/linux-x86_64-server-slowdebug/hotspot/variant-server/libjvm/objs/xmlstream.d [2018-11-08T18:33:21.704795 31732] Object file
