julia-actions / cache

A shortcut action to cache Julia artifacts, packages, and registries.
MIT License
38 stars 9 forks source link

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

Open KristofferC opened 3 months ago

KristofferC commented 3 months ago

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.

IanButterworth commented 3 months ago

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

giordano commented 3 months ago

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)

IanButterworth commented 3 months ago

@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.

DilumAluthge commented 3 months ago

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

IanButterworth commented 3 months ago

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

DilumAluthge commented 3 months ago

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

giordano commented 3 months ago

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

KristofferC commented 3 months ago

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.

giordano commented 3 months ago

Dependabot or renovate help with that by automating the updates.

KristofferC commented 3 months ago

I don't think it did on that repo.

giordano commented 3 months ago

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.

IanButterworth commented 2 months ago

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

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

KristofferC commented 2 months ago

Nice find

giordano commented 2 months ago

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

IanButterworth commented 2 months ago

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

KristofferC commented 2 months ago

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

giordano commented 2 months ago

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.