setup-ruby: Action has become very slow

Ensure the following before filing this issue

  • I verified it reproduces with the latest version with - uses: ruby/setup-ruby@v1 (see Versioning policy)

  • I tried to reproduce the issue locally by following the workflow steps (including all commands done by ruby/setup-ruby, except for Downloading Ruby & Extracting Ruby), and it did not reproduce locally (if it does reproduce locally, it’s not a ruby/setup-ruby issue)

Are you running on a GitHub-hosted runner or a self-hosted runner?

GitHub-hosted runner

Link to the failed workflow job (must be a public workflow job, so the necessary information is available)

https://github.com/templatus/templatus-hotwire/actions/runs/6713970783/job/18246455669

Any other notes?

The action has become slow lately, the setting up Ruby went from around 10 seconds to over 2 minutes.

Furthermore, there is a strange difference between the duration measured by GitHub and the time indicated by the action itself. See this example: The job itself says “9.52 seconds”, but GitHub says “2m 21s”

Screenshot

The code I use is very simple:

- name: Set up Ruby
  uses: ruby/setup-ruby@v1
  with:
    bundler-cache: true

About this issue

  • Original URL
  • State: closed
  • Created 8 months ago
  • Reactions: 1
  • Comments: 16 (4 by maintainers)

Commits related to this issue

Most upvoted comments

Yes, that helps, thank you all for the investigation! Unfortunate that the Node 20 update brought this bug in.

PR in https://github.com/ruby/setup-ruby/pull/546

Slow build in https://github.com/ruby/setup-ruby/actions/runs/6788405695/job/18453344720 (2min 17s)

2023-11-07T17:54:28.4897445Z Took   3.80 seconds
2023-11-07T17:56:38.5288805Z ##[group]Run ruby -v

Fast build in https://github.com/ruby/setup-ruby/actions/runs/6788443622/job/18453477353?pr=546 (5s, as advertised 😃 )

2023-11-07T17:58:41.1757838Z Took   2.20 seconds
2023-11-07T17:58:41.1894986Z ##[group]Run ruby -v

This is likely due to https://github.com/nodejs/node/issues/47228. The reason it regressed in Node 20 compared to Node 16 is because Node 19 changed the default of keepAlive from false to true.

The HTTP client code is wrapped in the @actions/http-client package, which controls its own default of keepAlive. However it doesn’t override Node’s default correctly, and there’s already an open PR to fix this: https://github.com/actions/toolkit/pull/1572. This will restore the Node 16 behaviour for anything using @actions/http-client.

I’ve tested that PR (see https://github.com/Bo98/toolkit-test/commit/2fc37709b6aed5db522e867a55868107a1d8b4c4) and can confirm it fixes the slowness: https://github.com/Bo98/toolkit-test/actions/runs/6758550452/job/18370288942 (compared to without that PR: https://github.com/Bo98/toolkit-test/actions/runs/6758456188/job/18370108410).

One of the things I discovered while testing that is that the client code was leaking promises (I was not able to track this down).

I ended up working around that in the cache action itself here: https://github.com/actions/cache/blob/704facf57e6136b1bc63b828d79edcd491f0ee84/src/restoreImpl.ts#L102

The reason you likely saw this is because the restore side of @actions/cache does force keepAlive on itself: https://github.com/actions/toolkit/blob/fe3e7ce9a7f995d29d1fcfd226a32bca407f9dc8/packages/cache/src/internal/downloadUtils.ts#L220, so that explains seeing the issue under Node 16 in that particular scenario.

One left unknown is builds on #540 seem fast

No Saving cache happening?

Thanks! This is great investigation - let me get the toolkit team involved to look at the cache package and how its behavior might have changed in Node 20.