Unexcepted behavior when restoring cache

[silver-ymz]

It happens in https://github.com/apache/incubator-opendal/actions/runs/5780637217. Related issue is https://github.com/apache/incubator-opendal/issues/2800.

What happened

When restoring cache which has exist key, the action tried downloading a lot of files, and failed because of timeout. And then it printed that Cache not found for input keys. Finally, it kept running until we stopped it manually.

Before this action, https://github.com/apache/incubator-opendal/actions/runs/5780637180/job/15664579419 ran well. After this action, https://github.com/apache/incubator-opendal/actions/runs/5781110765/job/15665742511 also ran well. They all restored cache with the same key.

Raw log

Detailed log

``` 2023-08-07T03:20:54.2335787Z shell: /usr/bin/bash --noprofile --norc -e -o pipefail {0} 2023-08-07T03:20:54.2336072Z ##[endgroup] 2023-08-07T03:20:54.5283786Z ##[group]Run actions/cache/restore@v3 2023-08-07T03:20:54.5284047Z with: 2023-08-07T03:20:54.5284451Z key: Linux-haskell-5b3626e67353cf47eab5ecf09b324f4f5c187b1d3b882be526af40cc2ced0cd5 2023-08-07T03:20:54.5284883Z path: ~/.cabal/store 2023-08-07T03:20:54.5285215Z restore-keys: Linux-haskell- 2023-08-07T03:20:54.5285484Z enableCrossOsArchive: false 2023-08-07T03:20:54.5285801Z fail-on-cache-miss: false 2023-08-07T03:20:54.5286099Z lookup-only: false 2023-08-07T03:20:54.5286335Z env: 2023-08-07T03:20:54.5286830Z RUSTFLAGS: -C debuginfo=1 2023-08-07T03:20:54.5287118Z RUST_BACKTRACE: 1 2023-08-07T03:20:54.5287354Z RUST_LOG: opendal=debug 2023-08-07T03:20:54.5287892Z CARGO_REGISTRIES_CRATES_IO_PROTOCOL: sparse 2023-08-07T03:20:54.5288201Z ##[endgroup] 2023-08-07T03:20:56.0693790Z Received 5611930 of 26583450 (21.1%), 5.3 MBs/sec 2023-08-07T03:20:57.0702026Z Received 22389146 of 26583450 (84.2%), 10.7 MBs/sec 2023-08-07T03:20:58.0714642Z Received 22389146 of 26583450 (84.2%), 7.1 MBs/sec 2023-08-07T03:20:59.0728737Z Received 22389146 of 26583450 (84.2%), 5.3 MBs/sec 2023-08-07T03:21:00.0740165Z Received 22389146 of 26583450 (84.2%), 4.3 MBs/sec 2023-08-07T03:21:01.0752191Z Received 22389146 of 26583450 (84.2%), 3.6 MBs/sec 2023-08-07T03:21:02.0766027Z Received 22389146 of 26583450 (84.2%), 3.0 MBs/sec 2023-08-07T03:21:03.0769467Z Received 22389146 of 26583450 (84.2%), 2.7 MBs/sec 2023-08-07T03:21:04.0785055Z Received 22389146 of 26583450 (84.2%), 2.4 MBs/sec 2023-08-07T03:21:05.0798344Z Received 22389146 of 26583450 (84.2%), 2.1 MBs/sec 2023-08-07T03:21:06.0812352Z Received 22389146 of 26583450 (84.2%), 1.9 MBs/sec 2023-08-07T03:21:07.0824674Z Received 22389146 of 26583450 (84.2%), 1.8 MBs/sec 2023-08-07T03:21:08.0830712Z Received 22389146 of 26583450 (84.2%), 1.6 MBs/sec 2023-08-07T03:21:09.0843142Z Received 22389146 of 26583450 (84.2%), 1.5 MBs/sec 2023-08-07T03:21:10.0853993Z Received 22389146 of 26583450 (84.2%), 1.4 MBs/sec 2023-08-07T03:21:11.0867687Z Received 22389146 of 26583450 (84.2%), 1.3 MBs/sec 2023-08-07T03:21:12.0880611Z Received 22389146 of 26583450 (84.2%), 1.3 MBs/sec 2023-08-07T03:21:13.0891834Z Received 22389146 of 26583450 (84.2%), 1.2 MBs/sec 2023-08-07T03:21:14.0904118Z Received 22389146 of 26583450 (84.2%), 1.1 MBs/sec 2023-08-07T03:21:15.0917474Z Received 22389146 of 26583450 (84.2%), 1.1 MBs/sec 2023-08-07T03:21:16.0929597Z Received 22389146 of 26583450 (84.2%), 1.0 MBs/sec 2023-08-07T03:21:17.0940756Z Received 22389146 of 26583450 (84.2%), 1.0 MBs/sec 2023-08-07T03:21:18.0956066Z Received 22389146 of 26583450 (84.2%), 0.9 MBs/sec 2023-08-07T03:21:19.0966005Z Received 22389146 of 26583450 (84.2%), 0.9 MBs/sec 2023-08-07T03:21:20.0977427Z Received 22389146 of 26583450 (84.2%), 0.9 MBs/sec 2023-08-07T03:21:21.0988973Z Received 22389146 of 26583450 (84.2%), 0.8 MBs/sec 2023-08-07T03:21:22.1001171Z Received 22389146 of 26583450 (84.2%), 0.8 MBs/sec 2023-08-07T03:21:23.1013044Z Received 22389146 of 26583450 (84.2%), 0.8 MBs/sec 2023-08-07T03:21:24.1025257Z Received 22389146 of 26583450 (84.2%), 0.7 MBs/sec 2023-08-07T03:21:25.1037551Z Received 22389146 of 26583450 (84.2%), 0.7 MBs/sec 2023-08-07T03:21:26.1049160Z Received 22389146 of 26583450 (84.2%), 0.7 MBs/sec 2023-08-07T03:21:27.1061324Z Received 22389146 of 26583450 (84.2%), 0.7 MBs/sec 2023-08-07T03:21:28.1073570Z Received 22389146 of 26583450 (84.2%), 0.6 MBs/sec 2023-08-07T03:21:29.1085444Z Received 22389146 of 26583450 (84.2%), 0.6 MBs/sec 2023-08-07T03:21:30.1096693Z Received 22389146 of 26583450 (84.2%), 0.6 MBs/sec 2023-08-07T03:21:31.1108626Z Received 22389146 of 26583450 (84.2%), 0.6 MBs/sec 2023-08-07T03:21:32.1120709Z Received 22389146 of 26583450 (84.2%), 0.6 MBs/sec 2023-08-07T03:21:33.1132468Z Received 22389146 of 26583450 (84.2%), 0.6 MBs/sec 2023-08-07T03:21:34.1144417Z Received 22389146 of 26583450 (84.2%), 0.5 MBs/sec 2023-08-07T03:21:35.1156373Z Received 22389146 of 26583450 (84.2%), 0.5 MBs/sec 2023-08-07T03:21:36.1168576Z Received 22389146 of 26583450 (84.2%), 0.5 MBs/sec 2023-08-07T03:21:37.1181616Z Received 22389146 of 26583450 (84.2%), 0.5 MBs/sec 2023-08-07T03:21:38.1193475Z Received 22389146 of 26583450 (84.2%), 0.5 MBs/sec 2023-08-07T03:21:39.1208397Z Received 22389146 of 26583450 (84.2%), 0.5 MBs/sec 2023-08-07T03:21:40.1217445Z Received 22389146 of 26583450 (84.2%), 0.5 MBs/sec 2023-08-07T03:21:41.1230742Z Received 22389146 of 26583450 (84.2%), 0.5 MBs/sec 2023-08-07T03:21:42.1243245Z Received 22389146 of 26583450 (84.2%), 0.5 MBs/sec 2023-08-07T03:21:43.1254555Z Received 22389146 of 26583450 (84.2%), 0.4 MBs/sec 2023-08-07T03:21:44.1267095Z Received 22389146 of 26583450 (84.2%), 0.4 MBs/sec 2023-08-07T03:21:45.1281614Z Received 22389146 of 26583450 (84.2%), 0.4 MBs/sec 2023-08-07T03:21:46.1294017Z Received 22389146 of 26583450 (84.2%), 0.4 MBs/sec 2023-08-07T03:21:47.1307921Z Received 22389146 of 26583450 (84.2%), 0.4 MBs/sec 2023-08-07T03:21:48.1320411Z Received 22389146 of 26583450 (84.2%), 0.4 MBs/sec 2023-08-07T03:21:49.1332263Z Received 22389146 of 26583450 (84.2%), 0.4 MBs/sec 2023-08-07T03:21:50.1344923Z Received 22389146 of 26583450 (84.2%), 0.4 MBs/sec 2023-08-07T03:21:51.1357628Z Received 22389146 of 26583450 (84.2%), 0.4 MBs/sec 2023-08-07T03:21:52.1368657Z Received 22389146 of 26583450 (84.2%), 0.4 MBs/sec 2023-08-07T03:21:53.1383348Z Received 22389146 of 26583450 (84.2%), 0.4 MBs/sec 2023-08-07T03:21:54.1392676Z Received 22389146 of 26583450 (84.2%), 0.4 MBs/sec 2023-08-07T03:21:55.1404764Z Received 22389146 of 26583450 (84.2%), 0.4 MBs/sec 2023-08-07T03:21:56.1406935Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:21:57.1419815Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:21:58.1432206Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:21:59.1447403Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:00.1446976Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:01.1459978Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:02.1473153Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:03.1483794Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:04.1495496Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:05.1509382Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:06.1519716Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:07.1533752Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:08.1546995Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:09.1548996Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:10.1560033Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:11.1573017Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:12.1586738Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:13.1598052Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:14.1610550Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:15.1622629Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:16.1637345Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:17.1647771Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:18.1661187Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:19.1673679Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:20.1687008Z Received 22389146 of 26583450 (84.2%), 0.3 MBs/sec 2023-08-07T03:22:21.1698893Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:22.1711280Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:23.1723825Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:24.1735701Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:25.1737835Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:26.1750508Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:27.1761053Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:28.1775120Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:29.1788314Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:30.1799408Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:31.1811301Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:32.1824669Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:33.1837339Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:34.1849143Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:35.1862868Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:35.3690874Z Received 22389146 of 26583450 (84.2%), 0.2 MBs/sec 2023-08-07T03:22:35.3724297Z ##[warning]Failed to restore: The operation cannot be completed in timeout. 2023-08-07T03:22:35.3733209Z Cache not found for input keys: Linux-haskell-5b3626e67353cf47eab5ecf09b324f4f5c187b1d3b882be526af40cc2ced0cd5, Linux-haskell- 2023-08-07T04:45:08.8757328Z ##[error]The operation was canceled. ```

[sc979]

We have similar issue in our project: https://github.com/centreon/centreon/actions/runs/5780555479/job/15664646313#step:6:119

[chkimes]

The timeout issue is captured in #810 and should recently be resolved.

It seems you have a separate issue in your workflow files where the build is still executed despite the cache restoring successfully. This is happening because the workflow step is missing an if: check for observing the cache hit. See the example workflow for : https://github.com/actions/cache#example-cache-workflow

[silver-ymz]

Thank you. The build after cache restoring is used to test updated code. I think it isn't an issue.

[sc979]

Thank you.

[github-actions[bot]]

This issue is stale because it has been open for 200 days with no activity. Leave a comment to avoid closing this issue in 5 days.