Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

"Warning: Cache not found" on first run in branch #1552

Closed
MikeMcC399 opened this issue Feb 12, 2025 · 9 comments
Closed

"Warning: Cache not found" on first run in branch #1552

MikeMcC399 opened this issue Feb 12, 2025 · 9 comments
Labels
bug Something isn't working

Comments

@MikeMcC399
Copy link

MikeMcC399 commented Feb 12, 2025

Current behavior

'actions/cache@v4' (SHA:1bd1e32a3bdc45362d1e726936510720a7c30a57)
actions/cache@v4.2.0

displays a warning such as:

Warning: Cache not found for keys: my-cache-Linux-e13c8d95e393dfdbfc3046a36b72e0d02da8e564e776fb3f7d5b53be6b568bc5
Cache not found for input keys: my-cache-Linux-e13c8d95e393dfdbfc3046a36b72e0d02da8e564e776fb3f7d5b53be6b568bc5

when a GitHub Actions workflow contains:

uses: actions/cache@v4

and the workflow is running for the first time in a branch.

This is a regression compared to how it used to work.

Expected behavior

No warning should be issued when a workflow runs for the first time in a branch.

Caches are linked to branches and if a workflow runs for the first time in a branch, then it is an expected condition that there is no cache available.

Warnings should only be issued if some corrective action is necessary. In this situation no user corrective action is necessary. After the workflow has run once, a cache will be established and any subsequent runs will use the cache. The situation is self-correcting.

@MikeMcC399
Copy link
Author

MikeMcC399 commented Feb 12, 2025

Example workflow

https://github.com/cypress-io/github-action/actions/workflows/example-install-only.yml

Renovate creates a new branch
https://github.com/cypress-io/github-action/tree/refs/heads/renovate/node-22.x

Run actions/cache@v4
  with:
    path: ~/.cache/Cypress
  node_modules

    key: my-cache-Linux-e13c8d95e393dfdbfc3046a36b72e0d02da8e564e776fb3f7d5b53be6b568bc5
    enableCrossOsArchive: false
    fail-on-cache-miss: false
    lookup-only: false
    save-always: false
Warning: Cache not found for keys: my-cache-Linux-e13c8d95e393dfdbfc3046a36b72e0d02da8e564e776fb3f7d5b53be6b568bc5
Cache not found for input keys: my-cache-Linux-e13c8d95e393dfdbfc3046a36b72e0d02da8e564e776fb3f7d5b53be6b568bc5

Image

@MikeMcC399
Copy link
Author

Debug logs

2025-02-13T09:59:29.4211385Z ##[debug]Evaluating condition for step: 'Cache npm and Cypress 📦'
2025-02-13T09:59:29.4215658Z ##[debug]Evaluating: success()
2025-02-13T09:59:29.4217639Z ##[debug]Evaluating success:
2025-02-13T09:59:29.4219402Z ##[debug]=> true
2025-02-13T09:59:29.4221364Z ##[debug]Result: true
2025-02-13T09:59:29.4300746Z ##[debug]Starting: Cache npm and Cypress 📦
2025-02-13T09:59:29.4359379Z ##[debug]Register post job cleanup for action: actions/cache@v4
2025-02-13T09:59:29.4385773Z ##[debug]Loading inputs
2025-02-13T09:59:29.4404423Z ##[debug]Evaluating: format('my-cache-{0}-{1}', runner.os, hashFiles('package-lock.json'))
2025-02-13T09:59:29.4406376Z ##[debug]Evaluating format:
2025-02-13T09:59:29.4410945Z ##[debug]..Evaluating String:
2025-02-13T09:59:29.4412169Z ##[debug]..=> 'my-cache-{0}-{1}'
2025-02-13T09:59:29.4425524Z ##[debug]..Evaluating Index:
2025-02-13T09:59:29.4426718Z ##[debug]....Evaluating runner:
2025-02-13T09:59:29.4427879Z ##[debug]....=> Object
2025-02-13T09:59:29.4428960Z ##[debug]....Evaluating String:
2025-02-13T09:59:29.4430325Z ##[debug]....=> 'os'
2025-02-13T09:59:29.4431420Z ##[debug]..=> 'Linux'
2025-02-13T09:59:29.4433126Z ##[debug]..Evaluating hashFiles:
2025-02-13T09:59:29.4443476Z ##[debug]....Evaluating String:
2025-02-13T09:59:29.4444729Z ##[debug]....=> 'package-lock.json'
2025-02-13T09:59:29.4446476Z ##[debug]Search root directory: '/home/runner/work/github-action/github-action'
2025-02-13T09:59:29.4448470Z ##[debug]Search pattern: 'package-lock.json'
2025-02-13T09:59:29.4453049Z ##[debug]Starting process:
2025-02-13T09:59:29.4454625Z ##[debug]  File name: '/home/runner/runners/2.322.0/externals/node20/bin/node'
2025-02-13T09:59:29.4456576Z ##[debug]  Arguments: '"/home/runner/runners/2.322.0/bin/hashFiles"'
2025-02-13T09:59:29.4458555Z ##[debug]  Working directory: '/home/runner/work/github-action/github-action'
2025-02-13T09:59:29.4460431Z ##[debug]  Require exit code zero: 'False'
2025-02-13T09:59:29.4461768Z ##[debug]  Encoding web name:  ; code page: ''
2025-02-13T09:59:29.4463141Z ##[debug]  Force kill process on cancellation: 'False'
2025-02-13T09:59:29.4464497Z ##[debug]  Redirected STDIN: 'False'
2025-02-13T09:59:29.4465745Z ##[debug]  Persist current code page: 'False'
2025-02-13T09:59:29.4467090Z ##[debug]  Keep redirected STDIN open: 'False'
2025-02-13T09:59:29.4468389Z ##[debug]  High priority process: 'False'
2025-02-13T09:59:29.4475113Z ##[debug]Updated oom_score_adj to 500 for PID: 1874.
2025-02-13T09:59:29.4477587Z ##[debug]Process started with process id 1874, waiting for process exit.
2025-02-13T09:59:29.4841921Z ##[debug]Match Pattern: package-lock.json
2025-02-13T09:59:29.4849696Z ##[debug]::debug::followSymbolicLinks 'false'
2025-02-13T09:59:29.4872736Z ##[debug]::debug::followSymbolicLinks 'false'
2025-02-13T09:59:29.4874389Z ##[debug]::debug::implicitDescendants 'true'
2025-02-13T09:59:29.4875835Z ##[debug]::debug::matchDirectories 'true'
2025-02-13T09:59:29.4877558Z ##[debug]::debug::omitBrokenSymbolicLinks 'true'
2025-02-13T09:59:29.4880251Z ##[debug]::debug::Search path '/home/runner/work/github-action/github-action/package-lock.json'
2025-02-13T09:59:29.4890260Z ##[debug]/home/runner/work/github-action/github-action/package-lock.json
2025-02-13T09:59:29.4952209Z ##[debug]Found 1 files to hash.
2025-02-13T09:59:29.4956811Z ##[debug]Hash result: 'e69f254a4259acbf6a34a461c0e418d74b8991258c426d0ef31d011d0d6f8137'
2025-02-13T09:59:29.4959592Z ##[debug]undefined
2025-02-13T09:59:29.4984998Z ##[debug]STDOUT/STDERR stream read finished.
2025-02-13T09:59:29.4985268Z ##[debug]STDOUT/STDERR stream read finished.
2025-02-13T09:59:29.4988123Z ##[debug]Finished process 1874 with exit code 0, and elapsed time 00:00:00.0517128.
2025-02-13T09:59:29.4991188Z ##[debug]..=> 'e69f254a4259acbf6a34a461c0e418d74b8991258c426d0ef31d011d0d6f8137'
2025-02-13T09:59:29.4994027Z ##[debug]=> 'my-cache-Linux-e69f254a4259acbf6a34a461c0e418d74b8991258c426d0ef31d011d0d6f8137'
2025-02-13T09:59:29.4997465Z ##[debug]Result: 'my-cache-Linux-e69f254a4259acbf6a34a461c0e418d74b8991258c426d0ef31d011d0d6f8137'
2025-02-13T09:59:29.5015655Z ##[debug]Loading env
2025-02-13T09:59:29.5030449Z ##[group]Run actions/cache@v4
2025-02-13T09:59:29.5031664Z with:
2025-02-13T09:59:29.5032500Z   path: ~/.cache/Cypress
node_modules

2025-02-13T09:59:29.5034313Z   key: my-cache-Linux-e69f254a4259acbf6a34a461c0e418d74b8991258c426d0ef31d011d0d6f8137
2025-02-13T09:59:29.5036192Z   enableCrossOsArchive: false
2025-02-13T09:59:29.5037241Z   fail-on-cache-miss: false
2025-02-13T09:59:29.5038225Z   lookup-only: false
2025-02-13T09:59:29.5039110Z   save-always: false
2025-02-13T09:59:29.5040117Z ##[endgroup]
2025-02-13T09:59:29.6271576Z ##[debug]Cache service version: v2
2025-02-13T09:59:29.6274170Z ##[debug]Resolved Keys:
2025-02-13T09:59:29.6277257Z ##[debug]["my-cache-Linux-e69f254a4259acbf6a34a461c0e418d74b8991258c426d0ef31d011d0d6f8137"]
2025-02-13T09:59:29.6280873Z ##[debug]Checking zstd --quiet --version
2025-02-13T09:59:29.6382632Z ##[debug]1.5.6
2025-02-13T09:59:29.6387361Z ##[debug]zstd version: 1.5.6
2025-02-13T09:59:29.6400221Z ##[debug][Request] GetCacheEntryDownloadURL https://results-receiver.actions.githubusercontent.com/twirp/github.actions.results.api.v1.CacheService/GetCacheEntryDownloadURL
2025-02-13T09:59:29.7311311Z ##[debug][Response] - 200
2025-02-13T09:59:29.7313971Z ##[debug]Headers: {
2025-02-13T09:59:29.7315495Z ##[debug]  "content-length": "56",
2025-02-13T09:59:29.7317469Z ##[debug]  "content-type": "application/json",
2025-02-13T09:59:29.7319538Z ##[debug]  "date": "Thu, 13 Feb 2025 09:59:29 GMT",
2025-02-13T09:59:29.7321621Z ##[debug]  "x-github-backend": "Kubernetes",
2025-02-13T09:59:29.7323861Z ##[debug]  "x-github-request-id": "0483:3160E8:36DC03A:422393D:67ADC281"
2025-02-13T09:59:29.7325867Z ##[debug]}
2025-02-13T09:59:29.7327995Z ##[debug]Body: {
2025-02-13T09:59:29.7329208Z ##[debug]  "ok": false,
2025-02-13T09:59:29.7330734Z ##[debug]  "signed_download_url": "",
2025-02-13T09:59:29.7332209Z ##[debug]  "matched_key": ""
2025-02-13T09:59:29.7333187Z ##[debug]}
2025-02-13T09:59:29.7353550Z ##[warning]Cache not found for keys: my-cache-Linux-e69f254a4259acbf6a34a461c0e418d74b8991258c426d0ef31d011d0d6f8137
2025-02-13T09:59:29.7364015Z Cache not found for input keys: my-cache-Linux-e69f254a4259acbf6a34a461c0e418d74b8991258c426d0ef31d011d0d6f8137
2025-02-13T09:59:29.7371841Z ##[debug]Node Action run completed with exit code 0
2025-02-13T09:59:29.7378100Z ##[debug]Save intra-action state CACHE_KEY = my-cache-Linux-e69f254a4259acbf6a34a461c0e418d74b8991258c426d0ef31d011d0d6f8137
2025-02-13T09:59:29.7381832Z ##[debug]Finishing: Cache npm and Cypress 📦

@MikeMcC399
Copy link
Author

I'm trying to reproduce this in a simpler example and I'm not getting the warning, so I guess there is something subtle going on. I'll keep looking.

@joshmgross joshmgross added the bug Something isn't working label Feb 13, 2025
@joshmgross
Copy link
Member

This is something we plan to fix - a cache miss is expected behavior and should not be a warning.

@MikeMcC399
Copy link
Author

@joshmgross

This is something we plan to fix - a cache miss is expected behavior and should not be a warning.

I am relieved to hear that! I was scratching my head a little as I was having difficulty reproducing it in all situations.

@vinmassaro
Copy link

@MikeMcC399 thanks for posting this bug. I started working on a new workflow using actions/cache and never saw this behavior previously and thought I was going crazy

@MikeMcC399
Copy link
Author

MikeMcC399 commented Feb 18, 2025

@robherley

I saw that there is a new release actions/cache@4.2.1

Will the v4 tag also be updated?

v4 is currently 1bd1e32
equivalent to
https://github.com/actions/cache/tree/v4.2.0

Edit: I see this is queued up in https://github.com/actions/cache/actions/runs/13396823681 so no need to answer!

@robherley
Copy link
Contributor

@MikeMcC399 the major tags (v4 and v3) should now be updated to fix this behavior, thanks again for reporting!

@MikeMcC399
Copy link
Author

@robherley

Thanks very much for fixing and letting me know! 👍🏻

I ran through my repro steps and there is no more warning.

First run

Cache not found for input keys: my-cache-Linux-fb8af90643217d0fa75ca969caf93d2318f6b85c6703a3e20c24eb9463eec00e

Second run

Cache hit for: my-cache-Linux-fb8af90643217d0fa75ca969caf93d2318f6b85c6703a3e20c24eb9463eec00e
Received 134217728 of 203875842 (65.8%), [12](https://github.com/MikeMcC399/github-action/actions/runs/13399852547/job/37427882952#step:3:13)7.4 MBs/sec
Received 203875842 of 203875842 (100.0%), 156.9 MBs/sec
Cache Size: ~194 MB (203875842 B)
/usr/bin/tar -xf /home/runner/work/_temp/170b7c9f-7f87-4ce6-bce2-[14](https://github.com/MikeMcC399/github-action/actions/runs/13399852547/job/37427882952#step:3:15)cdd89929a1/cache.tzst -P -C /home/runner/work/github-action/github-action --use-compress-program unzstd
Cache restored successfully
Cache restored from key: my-cache-Linux-fb8af90643217d0fa75ca969caf93d2318f6b85c6703a3e20c24eb9463eec00e

Closing as resolved!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

4 participants