Error in post job cleanup
casconed opened this issue · 10 comments
Using this action with
- name: Use build cache
uses: mikehardy/buildcache-action@v1
I get the following error in the post-job cleanup:
Post job cleanup.
(node:1069) UnhandledPromiseRejectionWarning: Error: Unable to locate executable file: buildcache. Please verify either the file path exists or the file can be found within a directory specified by the PATH environment variable. Also check the file mode to verify the file is executable.
at Object.<anonymous> (/Users/runner/work/_actions/mikehardy/buildcache-action/v1/dist/webpack:/buildcache-action/node_modules/@actions/io/lib/io.js:187:1)
at Generator.next (<anonymous>)
at fulfilled (/Users/runner/work/_actions/mikehardy/buildcache-action/v1/dist/webpack:/buildcache-action/node_modules/@actions/io/lib/io.js:5:1)
(node:1069) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 1)
(node:1069) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
Subsequent runs have a cache status with zeros across the board:
Cache status:
Entries in cache: 0
Cache size: 0 bytes (0.0%)
Direct hits: 0
Direct misses: 0
Local hits: 0
Local misses: 0
Remote hits: 0
Remote misses: 0
Misses: 0
Direct hit ratio: 0.0%
Local hit ratio: 0.0%
Remote hit ratio: 0.0%
Hit ratio: 0.0%
Here are the full logs from the first step:
Run mikehardy/buildcache-action@v1
with:
access_token: ***
install_dir: /Users/runner/work/***/***
upload_buildcache_log: false
zero_buildcache_stats: true
env:
CI: true
FIREBASE_TOKEN: ***
MY_KEYCHAIN: tmp-keychain
buildcache: release file based on runner os is buildcache-macos.zip
buildcache: installing from https://github.com/mbitsnbites/buildcache/releases/download/v0.27.1/buildcache-macos.zip
buildcache: download path /Users/runner/work/_temp/9b149fea-5053-46ef-abe1-a5b18d373e01
/usr/bin/unzip -q /Users/runner/work/_temp/9b149fea-5053-46ef-abe1-a5b18d373e01
buildcache: unpacked folder /Users/runner/work/***/***
/bin/ln -s /Users/runner/work/***/***/buildcache/bin/buildcache /Users/runner/work/***/***/buildcache/bin/clang
/bin/ln -s /Users/runner/work/***/***/buildcache/bin/buildcache /Users/runner/work/***/***/buildcache/bin/clang++
buildcache: no cache for key buildcache-2021-10-02T05:29:57.900Z or buildcache - cold cache or invalid key
/Users/runner/work/***/***/buildcache/bin/buildcache -c
Configuration file: /Users/runner/work/***/***/.buildcache/config.json
BUILDCACHE_ACCURACY: DEFAULT
BUILDCACHE_CACHE_LINK_COMMANDS: false
BUILDCACHE_COMPRESS: true
BUILDCACHE_COMPRESS_FORMAT: DEFAULT
BUILDCACHE_COMPRESS_LEVEL: -1
BUILDCACHE_DEBUG: 2
BUILDCACHE_DIR: /Users/runner/work/***/***/.buildcache
BUILDCACHE_DIRECT_MODE: false
BUILDCACHE_DISABLE: false
BUILDCACHE_HARD_LINKS: false
BUILDCACHE_HASH_EXTRA_FILES:
BUILDCACHE_IMPERSONATE:
BUILDCACHE_LOG_FILE: /Users/runner/work/***/***/.buildcache/buildcache.log
BUILDCACHE_LUA_PATH: /Users/runner/work/***/***/.buildcache/lua
BUILDCACHE_MAX_CACHE_SIZE: 500000000 (476.8 MiB)
BUILDCACHE_MAX_LOCAL_ENTRY_SIZE: 134217728 (128.0 MiB)
BUILDCACHE_MAX_REMOTE_ENTRY_SIZE: 134217728 (128.0 MiB)
BUILDCACHE_PERF: false
BUILDCACHE_PREFIX:
BUILDCACHE_READ_ONLY: false
BUILDCACHE_READ_ONLY_REMOTE: false
BUILDCACHE_REMOTE:
BUILDCACHE_REMOTE_LOCKS: false
BUILDCACHE_S3_ACCESS:
BUILDCACHE_S3_SECRET:
BUILDCACHE_TERMINATE_ON_MISS: false
/Users/runner/work/***/***/buildcache/bin/buildcache -s
Cache status:
Entries in cache: 0
Cache size: 0 bytes (0.0%)
Direct hits: 0
Direct misses: 0
Local hits: 0
Local misses: 0
Remote hits: 0
Remote misses: 0
Misses: 0
Direct hit ratio: 0.0%
Local hit ratio: 0.0%
Remote hit ratio: 0.0%
Hit ratio: 0.0%
buildcache: zeroing stats - stats display in cleanup task will be for this run only.
/Users/runner/work/***/***/buildcache/bin/buildcache -z
Strange - the only time the buildcache program itself is called in save.ts (the cleanup file), it is inside printStats, where there is an exec call:
Lines 6 to 18 in 2e0a490
...but every buildcache call in the whole action funnels through that exec call, and if it works at the start, why wouldn't it work at the end? 🤔
Perhaps there is something wiping out part of the repo's filespace in your build?
You could try setting "install_dir" and putting buildcache someplace else maybe?
Lines 51 to 61 in 2e0a490
then when it is installed in this function (which adds the installed location to the whole workflow's path) it will still be there
buildcache-action/src/restore.ts
Line 58 in 2e0a490
Very odd. I'm doing another run with the debugging cranked up to 3 and upload_builcache_log
set to true
to see if that sheds any light on things.
I'm noticing that I have this setup to run before I checkout my repo, so the post-job buildcache step happens AFTER the Post Checkout repository step - I wonder if something in that step is removing files? It doesn't look like it:
Post job cleanup.
/usr/local/bin/git version
git version 2.33.0
/usr/local/bin/git config --local --name-only --get-regexp core\.sshCommand
/usr/local/bin/git submodule foreach --recursive git config --local --name-only --get-regexp 'core\.sshCommand' && git config --local --unset-all 'core.sshCommand' || :
/usr/local/bin/git config --local --name-only --get-regexp http\.https\:\/\/github\.com\/\.extraheader
http.https://github.com/.extraheader
/usr/local/bin/git config --local --unset-all http.https://github.com/.extraheader
/usr/local/bin/git submodule foreach --recursive git config --local --name-only --get-regexp 'http\.https\:\/\/github\.com\/\.extraheader' && git config --local --unset-all 'http.https://github.com/.extraheader' || :
Pre-job log:
2021-10-02T15:11:18.3819260Z ##[group]Run mikehardy/buildcache-action@v1
2021-10-02T15:11:18.3820050Z with:
2021-10-02T15:11:18.3821010Z access_token: ***
2021-10-02T15:11:18.3821980Z install_dir: /Users/runner/work/***/***
2021-10-02T15:11:18.3822630Z upload_buildcache_log: false
2021-10-02T15:11:18.3823230Z zero_buildcache_stats: true
2021-10-02T15:11:18.3823920Z env:
2021-10-02T15:11:18.3824340Z CI: true
2021-10-02T15:11:18.3826810Z FIREBASE_TOKEN: ***
2021-10-02T15:11:18.3827410Z MY_KEYCHAIN: tmp-keychain
2021-10-02T15:11:18.3827960Z ##[endgroup]
2021-10-02T15:11:19.5010650Z buildcache: release file based on runner os is buildcache-macos.zip
2021-10-02T15:11:19.7997700Z buildcache: installing from https://github.com/mbitsnbites/buildcache/releases/download/v0.27.1/buildcache-macos.zip
2021-10-02T15:11:20.1694570Z buildcache: download path /Users/runner/work/_temp/c503a513-cdfc-4eb8-b888-3f8e81b85dce
2021-10-02T15:11:20.1764980Z [command]/usr/bin/unzip -q /Users/runner/work/_temp/c503a513-cdfc-4eb8-b888-3f8e81b85dce
2021-10-02T15:11:20.6761410Z buildcache: unpacked folder /Users/runner/work/***/***
2021-10-02T15:11:20.7607890Z [command]/bin/ln -s /Users/runner/work/***/***/buildcache/bin/buildcache /Users/runner/work/***/***/buildcache/bin/clang
2021-10-02T15:11:20.7728170Z [command]/bin/ln -s /Users/runner/work/***/***/buildcache/bin/buildcache /Users/runner/work/***/***/buildcache/bin/clang++
2021-10-02T15:11:21.9761470Z buildcache: no cache for key buildcache-2021-10-02T15:11:21.133Z or buildcache - cold cache or invalid key
2021-10-02T15:11:21.9796920Z [command]/Users/runner/work/***/***/buildcache/bin/buildcache -c
2021-10-02T15:11:22.1214000Z Configuration file: /Users/runner/work/***/***/.buildcache/config.json
2021-10-02T15:11:22.1214780Z
2021-10-02T15:11:22.1215370Z BUILDCACHE_ACCURACY: DEFAULT
2021-10-02T15:11:22.1216100Z BUILDCACHE_CACHE_LINK_COMMANDS: false
2021-10-02T15:11:22.1216850Z BUILDCACHE_COMPRESS: true
2021-10-02T15:11:22.1217550Z BUILDCACHE_COMPRESS_FORMAT: DEFAULT
2021-10-02T15:11:22.1218980Z BUILDCACHE_COMPRESS_LEVEL: -1
2021-10-02T15:11:22.1219630Z BUILDCACHE_DEBUG: 2
2021-10-02T15:11:22.1220670Z BUILDCACHE_DIR: /Users/runner/work/***/***/.buildcache
2021-10-02T15:11:22.1221410Z BUILDCACHE_DIRECT_MODE: false
2021-10-02T15:11:22.1222050Z BUILDCACHE_DISABLE: false
2021-10-02T15:11:22.1222650Z BUILDCACHE_HARD_LINKS: false
2021-10-02T15:11:22.1223810Z BUILDCACHE_HASH_EXTRA_FILES:
2021-10-02T15:11:22.1224430Z BUILDCACHE_IMPERSONATE:
2021-10-02T15:11:22.1225530Z BUILDCACHE_LOG_FILE: /Users/runner/work/***/***/.buildcache/buildcache.log
2021-10-02T15:11:22.1226710Z BUILDCACHE_LUA_PATH: /Users/runner/work/***/***/.buildcache/lua
2021-10-02T15:11:22.1227480Z BUILDCACHE_MAX_CACHE_SIZE: 500000000 (476.8 MiB)
2021-10-02T15:11:22.1228170Z BUILDCACHE_MAX_LOCAL_ENTRY_SIZE: 134217728 (128.0 MiB)
2021-10-02T15:11:22.1228860Z BUILDCACHE_MAX_REMOTE_ENTRY_SIZE: 134217728 (128.0 MiB)
2021-10-02T15:11:22.1229510Z BUILDCACHE_PERF: false
2021-10-02T15:11:22.1230080Z BUILDCACHE_PREFIX:
2021-10-02T15:11:22.1230920Z BUILDCACHE_READ_ONLY: false
2021-10-02T15:11:22.1231550Z BUILDCACHE_READ_ONLY_REMOTE: false
2021-10-02T15:11:22.1232180Z BUILDCACHE_REMOTE:
2021-10-02T15:11:22.1232760Z BUILDCACHE_REMOTE_LOCKS: false
2021-10-02T15:11:22.1233390Z BUILDCACHE_S3_ACCESS:
2021-10-02T15:11:22.1233950Z BUILDCACHE_S3_SECRET:
2021-10-02T15:11:22.1234590Z BUILDCACHE_TERMINATE_ON_MISS: false
2021-10-02T15:11:22.1261100Z [command]/Users/runner/work/***/***/buildcache/bin/buildcache -s
2021-10-02T15:11:22.1318320Z Cache status:
2021-10-02T15:11:22.1319120Z Entries in cache: 0
2021-10-02T15:11:22.1320780Z Cache size: 0 bytes (0.0%)
2021-10-02T15:11:22.1321450Z Direct hits: 0
2021-10-02T15:11:22.1322810Z Direct misses: 0
2021-10-02T15:11:22.1323370Z Local hits: 0
2021-10-02T15:11:22.1324070Z Local misses: 0
2021-10-02T15:11:22.1324620Z Remote hits: 0
2021-10-02T15:11:22.1325110Z Remote misses: 0
2021-10-02T15:11:22.1325620Z Misses: 0
2021-10-02T15:11:22.1326090Z Direct hit ratio: 0.0%
2021-10-02T15:11:22.1326620Z Local hit ratio: 0.0%
2021-10-02T15:11:22.1327110Z Remote hit ratio: 0.0%
2021-10-02T15:11:22.1327660Z Hit ratio: 0.0%
2021-10-02T15:11:22.1329960Z buildcache: zeroing stats - stats display in cleanup task will be for this run only.
2021-10-02T15:11:22.1357830Z [command]/Users/runner/work/***/***/buildcache/bin/buildcache -z
Post-job log:
2021-10-02T16:03:01.8614690Z Post job cleanup.
2021-10-02T16:03:02.2375480Z (node:17522) UnhandledPromiseRejectionWarning: Error: Unable to locate executable file: buildcache. Please verify either the file path exists or the file can be found within a directory specified by the PATH environment variable. Also check the file mode to verify the file is executable.
2021-10-02T16:03:02.2486790Z at Object.<anonymous> (/Users/runner/work/_actions/mikehardy/buildcache-action/v1/dist/webpack:/buildcache-action/node_modules/@actions/io/lib/io.js:187:1)
2021-10-02T16:03:02.2489140Z at Generator.next (<anonymous>)
2021-10-02T16:03:02.2592010Z at fulfilled (/Users/runner/work/_actions/mikehardy/buildcache-action/v1/dist/webpack:/buildcache-action/node_modules/@actions/io/lib/io.js:5:1)
2021-10-02T16:03:02.2694720Z (node:17522) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 1)
2021-10-02T16:03:02.2796840Z (node:17522) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
Ah yeah, I think that is it - problem resolved moving the install step after the repository checkout step. Seems obvious now but might be work having a mention in the README.
Very interesting - If you want to hit the edit button on the README and post a PR with the details of that, you might help some future people, github web PR flow for text edits is really quick and you'll know the exact details best
Will do. New problem though - nothing seems to be saved to to the cache. The post-job cleanup reports a cache size of 0 bytes. Any ideas?
That's where turning up the debug on the build log and examining it will be (hopefully) interesting. Although if it's truly zero that usually implies the buildcache binary is not even in play, not just that it's cache-miss all the time (which is what the buildlog normally helps with)
I'd examine the PATH environment variable before whatever build step you've got, and then compare your build commands vs expectations to make sure that it's referencing your compiler in whatever way buildcache says it should so that buildcache is used
Please note that without some https://duckduckgo.com/?t=canonical&q=minimum+reproducible+example I'm just offering general guidance, all of which may be deduced from source here or on buildcache main docs site
Awesome thanks - I'll do some digging. It definitely seems like the buildcache binaries aren't in play, in the upload step the log is not found.
Got this working, but only after I added the extra variables to xcodebuild
as you outline in the docs. For whatever reason, simply having the path set did not seem to work 🤷 .
Also - thanks for making this! I've been banging my head on this problem (speeding up React Native builds in CI) for a couple of years and this is by far the cleanest solution I've found.
Glad it works for you! Honestly (as a mainly react-native build consumer myself...) I've been bouncing between my own action and ccache-action personally (and the both of those locally as well). I have found that ccache can be faster, but only the newest versions (where multiple source files is handled better). So if you haven't tried the ccache-action that this is patterned from you might give it a benchmark for your case too, the difference can be substantial. At any rate, I'm happy to have wrappers for both underlying compiler caches as I've always had success with at least one of them. And it is a big help! Cheers