cache icon indicating copy to clipboard operation
cache copied to clipboard

Cache actions takes 2min+ but timestamps do not show where time is spent

Open KristofferC opened this issue 1 year ago • 17 comments

In https://github.com/JuliaIO/BufferedStreams.jl/actions/runs/10114228187/job/27972388361, the cache step seems to take about 2 minutes.

It is however unclear where the time is actually spent since looking at the timestamps:

image

it is not possible to see where the 2 minutes are actually spent.

KristofferC avatar Jul 26 '24 19:07 KristofferC

The first line from the next step is 2 min later, but not sure why Screenshot 2024-07-26 at 3 44 55 PM

IanButterworth avatar Jul 26 '24 19:07 IanButterworth

Perhaps not relevant, but latest major version of this workflow (and setup-julia) is 2, but it's worth making sure this happens on latest version (if the issue is reproducible at all)

giordano avatar Jul 26 '24 19:07 giordano

@KristofferC can you re-run via the GitHub interface with debugging turned on.

Hopefully updating will fix it, but also good to identify the issue if it does.

IanButterworth avatar Jul 28 '24 16:07 IanButterworth

Here's Kristoffer's original job, re-ran with debug logging enabled: https://github.com/JuliaIO/BufferedStreams.jl/actions/runs/10114228187/job/28018266876

DilumAluthge avatar Jul 28 '24 16:07 DilumAluthge

image

Looks like post action cleanup, perhaps the cloned registry because 1.6 just takes a long time to delete.. which it shouldn't on linux at least

IanButterworth avatar Jul 28 '24 17:07 IanButterworth

Perhaps not relevant, but latest major version of this workflow (and setup-julia) is 2, but it's worth making sure this happens on latest version (if the issue is reproducible at all)

The workflow will be updated to v2 in: https://github.com/JuliaIO/BufferedStreams.jl/pull/86

DilumAluthge avatar Jul 28 '24 17:07 DilumAluthge

Looks like the cleanup task took between 1 and 5 seconds in that PR and the following commit to master

giordano avatar Jul 28 '24 17:07 giordano

Okay, I think that is fixed then. I wonder how many are stuck at v1, it isn't like you check for updates on github action workflows very often.

KristofferC avatar Jul 28 '24 21:07 KristofferC

Dependabot or renovate help with that by automating the updates.

giordano avatar Jul 28 '24 21:07 giordano

I don't think it did on that repo.

KristofferC avatar Jul 28 '24 22:07 KristofferC

If no one merges dependabot PRs for months the bot goes stale, until someone resumes it. Which is what happened when Dilum merged https://github.com/JuliaIO/BufferedStreams.jl/pull/83.

giordano avatar Jul 28 '24 22:07 giordano

Looks like this is the issue https://github.com/nodejs/node/issues/47228

https://github.com/actions/cache/issues/1442

IanButterworth avatar Aug 06 '24 11:08 IanButterworth

Nice find

KristofferC avatar Aug 06 '24 12:08 KristofferC

Is it the same? The slowdown was with version 1 of this workflow, which wasn't using node20 (as far as I understand), while there's apparently no slowdown with version 2 of this workflow which uses node20, and in the linked issue they say that's specific to node20

giordano avatar Aug 06 '24 12:08 giordano

Isn't gha force updating old node to 20 now?

IanButterworth avatar Aug 06 '24 12:08 IanButterworth

The exact 2 min hang that was reported in that issue seems suspiciously similar for it to be something else entirely.

KristofferC avatar Aug 06 '24 12:08 KristofferC

But in v2 of this workflow the issue isn't observed, so I'm missing why the issue was reopened. And based on https://github.com/actions/cache/pull/1284#issuecomment-1885094213 the issue you found (which referred to v3 of actions/cache, not v4) was already worked around upstream.

giordano avatar Aug 06 '24 13:08 giordano