[ccache] FATAL: Could not create ... (permission denied?)

Wed May 30 12:09:34 MDT 2012

On Wed, May 30, 2012 at 10:34 AM, Joel Rosdahl <joel at rosdahl.net> wrote:
> On 29 May 2012 21:03, Andy Lutomirski <luto at amacapital.net> wrote:
>> I just enabled precompiled headers in my project, and I'm getting
>> intermittent ccache failures.
>
> Thanks for the bug report!
>
>> The log says (partially redacted):
>>
>> [2012-05-29T11:35:36.768787 27203] === CCACHE STARTED =========================================
>
> ccache started with PID 27203.
>
>> [...]
>> [2012-05-29T11:35:36.769448 27203] Executing [...]
>> [2012-05-29T11:35:36.769563 27204] Unlink /home/luto/.ccache/tmp/FieldGroup.tmp.my_machine.localdomain.27203.ii (as-tmp)
>
> Running the preprocessor in child with PID 27204.
>
>> [...]
>> [2012-05-29T11:35:37.161938 27203] Executing [...]
>> [2012-05-29T11:35:37.162056 27215] Unlink /home/luto/.ccache/0/5/86c6c606e035773cb8c1c6e56dfb76-3188758.o.tmp.stdout.my_machine.localdomain.27203 (as-tmp)
>
> Running the real compiler in child with PID 27215. Looks good so far.
>
>> [2012-05-29T11:35:37.377566 26882] Unlink /home/luto/.ccache/0/5/86c6c606e035773cb8c1c6e56dfb76-3188758.o.tmp.stderr.my_machine.localdomain.27203 via /home/luto/.ccache/0/5/86c6c606e035773cb8c1c6e56dfb763188758.o.tmp.stderr.my_machine.localdomain.27203.my_machine.localdomain.26882.rmXXXXXX
>
> However, this is unexpected. Where did PID 26882 come from? The error
> later in the log is a consequence of PID 26882 removing the indicated
> file.

26882 was the very first ccache execution of the build, started by the
build system.  It's building a giant precompiled header file called
subdir5/pch.h, and it takes a long time.  (None of the files it
references are related to the build that failed.)

>
> Judging from time stamps, it looks as if the compiler somehow has
> called ccache, perhaps when executing some internal helper program.
> How peculiar.
>
> Does the log contain more rows for PID 26882?

It ends with:

[2012-05-29T11:35:37.374842 26882] Cleaning up cache directory
/home/luto/.ccache/0
[2012-05-29T11:35:37.375221 26882] Unlink
/home/luto/.ccache/0/6/7de0f184b99c378d41fba78edc62a9-851385.o via
/home/luto/.ccache/0/6/7de0f184b99c378d41fba78edc62a9-851385.o.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.375400 26882] Unlink
/home/luto/.ccache/0/b/0a6946d6588797ff8cf253b255c8f8-3222080.o.tmp.stderr.my_machine.localdomain.26309
via /home/luto/.ccache/0/b/0a6946d6588797ff8cf253b255c8f8-3222080.o.tmp.stderr.my_machine.localdomain.26309.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.375531 26882] Unlink
/home/luto/.ccache/0/b/0a6946d6588797ff8cf253b255c8f8-3222080.o.tmp.stdout.my_machine.localdomain.26309
via /home/luto/.ccache/0/b/0a6946d6588797ff8cf253b255c8f8-3222080.o.tmp.stdout.my_machine.localdomain.26309.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.375630 26882] Unlink
/home/luto/.ccache/0/0/9429f13de0ad365bf332ffe351b0c7-2843.manifest
via /home/luto/.ccache/0/0/9429f13de0ad365bf332ffe351b0c7-2843.manifest.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.375770 26882] Unlink
/home/luto/.ccache/0/4/4b8863f4591b212494fcb316a44e0a-2952350.o via
/home/luto/.ccache/0/4/4b8863f4591b212494fcb316a44e0a-2952350.o.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.375947 26882] Unlink
/home/luto/.ccache/0/c/82cf3bce9662f397a864df41ad0273-2361689.o.tmp.stderr.my_machine.localdomain.26799
via /home/luto/.ccache/0/c/82cf3bce9662f397a864df41ad0273-2361689.o.tmp.stderr.my_machine.localdomain.26799.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.376168 26882] Unlink
/home/luto/.ccache/0/c/82cf3bce9662f397a864df41ad0273-2361689.o.tmp.stdout.my_machine.localdomain.26799
via /home/luto/.ccache/0/c/82cf3bce9662f397a864df41ad0273-2361689.o.tmp.stdout.my_machine.localdomain.26799.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.376274 26882] Unlink
/home/luto/.ccache/0/c/9d6e7119bcfd8f17129662d208b175-166200.o.tmp.stderr.my_machine.localdomain.26833
via /home/luto/.ccache/0/c/9d6e7119bcfd8f17129662d208b175-166200.o.tmp.stderr.my_machine.localdomain.26833.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.376377 26882] Unlink
/home/luto/.ccache/0/c/9d6e7119bcfd8f17129662d208b175-166200.o.tmp.stdout.my_machine.localdomain.26833
via /home/luto/.ccache/0/c/9d6e7119bcfd8f17129662d208b175-166200.o.tmp.stdout.my_machine.localdomain.26833.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.376478 26882] Unlink
/home/luto/.ccache/0/0/48b36aa227a76441b7f21850039880-11103.manifest
via /home/luto/.ccache/0/0/48b36aa227a76441b7f21850039880-11103.manifest.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.376598 26882] Unlink
/home/luto/.ccache/0/f/95ad40e26e129eac13935e4fd4d6bf-2281.manifest
via /home/luto/.ccache/0/f/95ad40e26e129eac13935e4fd4d6bf-2281.manifest.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.376720 26882] Unlink
/home/luto/.ccache/0/4/e0a47aaed62458bc8859c07a7c6cba-5660.manifest
via /home/luto/.ccache/0/4/e0a47aaed62458bc8859c07a7c6cba-5660.manifest.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.376836 26882] Unlink
/home/luto/.ccache/0/6/274c40c507a141589419b50134b897-3561625.o via
/home/luto/.ccache/0/6/274c40c507a141589419b50134b897-3561625.o.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.377149 26882] Unlink
/home/luto/.ccache/0/b/0a6946d6588797ff8cf253b255c8f8-3222080.o via
/home/luto/.ccache/0/b/0a6946d6588797ff8cf253b255c8f8-3222080.o.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.377453 26882] Unlink
/home/luto/.ccache/0/9/7912da027dbe418eee381e12114e1d-16965.manifest
via /home/luto/.ccache/0/9/7912da027dbe418eee381e12114e1d-16965.manifest.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.377566 26882] Unlink
/home/luto/.ccache/0/5/86c6c606e035773cb8c1c6e56dfb76-3188758.o.tmp.stderr.my_machine.localdomain.27203
via /home/luto/.ccache/0/5/86c6c606e035773cb8c1c6e56dfb76-3188758.o.tmp.stderr.my_machine.localdomain.27203.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.377665 26882] Unlink
/home/luto/.ccache/0/5/86c6c606e035773cb8c1c6e56dfb76-3188758.o.tmp.stdout.my_machine.localdomain.27203
via /home/luto/.ccache/0/5/86c6c606e035773cb8c1c6e56dfb76-3188758.o.tmp.stdout.my_machine.localdomain.27203.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.377752 26882] Unlink
/home/luto/.ccache/0/7/fd138dc066b7dfe487baf5dde7ea2b-4383.manifest
via /home/luto/.ccache/0/7/fd138dc066b7dfe487baf5dde7ea2b-4383.manifest.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.377857 26882] Unlink
/home/luto/.ccache/0/b/aa910b2e73dea3749bc485da79381c-5234719.o via
/home/luto/.ccache/0/b/aa910b2e73dea3749bc485da79381c-5234719.o.my_machine.localdomain.26882.rmXXXXXX
[2012-05-29T11:35:37.448920 26882] Acquired lock /home/luto/.ccache/0/stats.lock
[2012-05-29T11:35:37.449123 26882] Releasing lock
/home/luto/.ccache/0/stats.lock
[2012-05-29T11:35:37.449143 26882] Unlink
/home/luto/.ccache/0/stats.lock (as-tmp)

Looks like a straight-up race: one ccache invocation is cleaning up
files that are still in use by another invocation.  I bet the
precompiled headers triggered it because they take a long time to
generate.

>
> Which ccache version did you use?

3.1.7-1.fc16 (i.e. Fedora 16's package of 3.1.7).

--Andy