With latest runner code 2.317.0 binary hack seems to not be working

[tabossert]

After upgrading to latest version of Github actions runner, it is complaining it can't reach the cache server. I have shell'ed into a runner pod and verified the url can reach the cache server and get a response.

Wondering if the binary patch is no longer working.

Thanks

• Trevor

[LouisHaftmann]

If it's complaining that it cannot reach the cache server, the binary patch probably still works. Otherwise it would not throw any errors and just use the default cache server.

Could you share some action logs?

[tabossert]

`Defaulted container "runner" out of: runner, dind, init-dind-externals (init), kube-init (init) [RUNNER 2024-05-31 19:22:56Z INFO HostContext] No proxy settings were found based on environmental variables (http_proxy/https_proxy/HTTP_PROXY/HTTPS_PROXY) [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Bin': '/home/runner/bin' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Root': '/home/runner' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known config file 'Credentials': '/home/runner/.credentials' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Bin': '/home/runner/bin' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Root': '/home/runner' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known config file 'Runner': '/home/runner/.runner' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Adding extra user agent 'actions-runner-controller/0.9.2' to all HTTP requests. [RUNNER 2024-05-31 19:22:56Z INFO Listener] Runner is built for Linux (X64) - linux-x64. [RUNNER 2024-05-31 19:22:56Z INFO Listener] RuntimeInformation: Linux 5.15.0-1064-azure #73-Ubuntu SMP Tue Apr 30 14:24:24 UTC 2024. [RUNNER 2024-05-31 19:22:56Z INFO Listener] Version: 2.317.0 [RUNNER 2024-05-31 19:22:56Z INFO Listener] Commit: 6dc005ee3690a0303e0d7269b6f60295d22dcfad [RUNNER 2024-05-31 19:22:56Z INFO Listener] Culture: [RUNNER 2024-05-31 19:22:56Z INFO Listener] UI Culture: [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Bin': '/home/runner/bin' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Root': '/home/runner' [RUNNER 2024-05-31 19:22:56Z INFO Listener] Validating directory permissions for: '/home/runner' [RUNNER 2024-05-31 19:22:56Z INFO CommandLineParser] Parse [RUNNER 2024-05-31 19:22:56Z INFO CommandLineParser] Parsing 1 args [RUNNER 2024-05-31 19:22:56Z INFO CommandLineParser] parsing argument [RUNNER 2024-05-31 19:22:56Z INFO CommandLineParser] HasArgs: False [RUNNER 2024-05-31 19:22:56Z INFO CommandLineParser] Adding Command: run [RUNNER 2024-05-31 19:22:56Z INFO CommandSettings] Removing env var: 'ACTIONS_RUNNER_INPUT_JITCONFIG' [RUNNER 2024-05-31 19:22:56Z INFO Listener] Arguments parsed [RUNNER 2024-05-31 19:22:56Z INFO Runner] ExecuteCommand [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] currentAssemblyLocation: /home/runner/bin/Runner.Listener.dll [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Bin': '/home/runner/bin' [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] binPath: /home/runner/bin [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Bin': '/home/runner/bin' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Root': '/home/runner' [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] RootFolder: /home/runner [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Bin': '/home/runner/bin' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Root': '/home/runner' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known config file 'Runner': '/home/runner/.runner' [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] ConfigFilePath: /home/runner/.runner [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Bin': '/home/runner/bin' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Root': '/home/runner' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known config file 'Credentials': '/home/runner/.credentials' [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] CredFilePath: /home/runner/.credentials [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Bin': '/home/runner/bin' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Root': '/home/runner' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known config file 'MigratedCredentials': '/home/runner/.credentials_migrated' [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] MigratedCredFilePath: /home/runner/.credentials_migrated [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Bin': '/home/runner/bin' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Root': '/home/runner' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known config file 'Service': '/home/runner/.service' [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] ServiceConfigFilePath: /home/runner/.service [RUNNER 2024-05-31 19:22:56Z INFO CommandSettings] Flag 'help': 'False' [RUNNER 2024-05-31 19:22:56Z INFO CommandSettings] Flag 'version': 'False' [RUNNER 2024-05-31 19:22:56Z INFO CommandSettings] Flag 'commit': 'False' [RUNNER 2024-05-31 19:22:56Z INFO CommandSettings] Flag 'check': 'False' [RUNNER 2024-05-31 19:22:56Z INFO CommandSettings] Command 'configure': 'False' [RUNNER 2024-05-31 19:22:56Z INFO CommandSettings] Command 'remove': 'False' [RUNNER 2024-05-31 19:22:56Z INFO CommandSettings] Command 'warmup': 'False' [RUNNER 2024-05-31 19:22:56Z INFO CommandSettings] Env arg 'jitconfig': '***' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Bin': '/home/runner/bin' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Root': '/home/runner' [RUNNER 2024-05-31 19:22:56Z INFO Runner] Saved 352 bytes to '/home/runner/.runner'. [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Bin': '/home/runner/bin' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Root': '/home/runner' [RUNNER 2024-05-31 19:22:56Z INFO Runner] Saved 224 bytes to '/home/runner/.credentials'. [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Bin': '/home/runner/bin' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Root': '/home/runner' [RUNNER 2024-05-31 19:22:56Z INFO Runner] Saved 1631 bytes to '/home/runner/.credentials_rsaparams'. [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationManager] LoadSettings [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] IsConfigured() [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] IsConfigured: True [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationManager] Is configured: True [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] Read setting file: 352 chars [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationManager] Settings Loaded [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] IsServiceConfigured() [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] IsServiceConfigured: False [RUNNER 2024-05-31 19:22:56Z INFO CommandSettings] Command 'run': 'True' [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] IsConfigured() [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] IsConfigured: True [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationManager] Is configured: True [RUNNER 2024-05-31 19:22:56Z INFO Runner] Could not parse the argument value '' for StartupType. Defaulting to Manual [RUNNER 2024-05-31 19:22:56Z INFO Runner] Set runner startup type - Manual [RUNNER 2024-05-31 19:22:56Z INFO CommandSettings] Flag 'once': 'False' [RUNNER 2024-05-31 19:22:56Z INFO CommandSettings] Flag 'once': 'False' [RUNNER 2024-05-31 19:22:56Z INFO Runner] RunAsync [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationManager] LoadSettings [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] IsConfigured() [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] IsConfigured: True [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationManager] Is configured: True [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationManager] Settings Loaded [RUNNER 2024-05-31 19:22:56Z INFO MessageListener] { [RUNNER 2024-05-31 19:22:56Z INFO MessageListener] "AgentId": 162070, [RUNNER 2024-05-31 19:22:56Z INFO MessageListener] "AgentName": "self-hosted-xlarge-zp5gr-runner-4p2gt", [RUNNER 2024-05-31 19:22:56Z INFO MessageListener] "PoolId": 1, [RUNNER 2024-05-31 19:22:56Z INFO MessageListener] "DisableUpdate": true, [RUNNER 2024-05-31 19:22:56Z INFO MessageListener] "Ephemeral": true, [RUNNER 2024-05-31 19:22:56Z INFO MessageListener] "ServerUrl": "https://pipelinesghubeus8.actions.githubusercontent.com/gqz7y4BPCK235QG4RPy91qHl9zBsiKEADbofpgEchtEGu5bdHT/", [RUNNER 2024-05-31 19:22:56Z INFO MessageListener] "WorkFolder": "_work" [RUNNER 2024-05-31 19:22:56Z INFO MessageListener] } [RUNNER 2024-05-31 19:22:56Z INFO MessageListener] Loading Credentials [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] HasCredentials() [RUNNER 2024-05-31 19:22:56Z INFO ConfigurationStore] stored True [RUNNER 2024-05-31 19:22:56Z INFO CredentialManager] GetCredentialProvider [RUNNER 2024-05-31 19:22:56Z INFO CredentialManager] Creating type OAuth [RUNNER 2024-05-31 19:22:56Z INFO CredentialManager] Creating credential type: OAuth [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Bin': '/home/runner/bin' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known directory 'Root': '/home/runner' [RUNNER 2024-05-31 19:22:56Z INFO HostContext] Well known config file 'RSACredentials': '/home/runner/.credentials_rsaparams' [RUNNER 2024-05-31 19:22:56Z INFO RSAFileKeyManager] Loading RSA key parameters from file /home/runner/.credentials_rsaparams [RUNNER 2024-05-31 19:22:56Z INFO MessageListener] Attempt to create session. [RUNNER 2024-05-31 19:22:56Z INFO MessageListener] Connecting to the Runner Server... [RUNNER 2024-05-31 19:22:56Z INFO RunnerServer] EstablishVssConnection [RUNNER 2024-05-31 19:22:56Z INFO RunnerServer] Establish connection with 100 seconds timeout. [RUNNER 2024-05-31 19:22:56Z INFO GitHubActionsService] Starting operation Location.GetConnectionData [RUNNER 2024-05-31 19:22:56Z INFO RunnerServer] EstablishVssConnection [RUNNER 2024-05-31 19:22:56Z INFO RunnerServer] Establish connection with 60 seconds timeout. [RUNNER 2024-05-31 19:22:56Z INFO GitHubActionsService] Starting operation Location.GetConnectionData [RUNNER 2024-05-31 19:22:56Z INFO RunnerServer] EstablishVssConnection [RUNNER 2024-05-31 19:22:56Z INFO RunnerServer] Establish connection with 60 seconds timeout. [RUNNER 2024-05-31 19:22:56Z INFO GitHubActionsService] Starting operation Location.GetConnectionData [RUNNER 2024-05-31 19:22:57Z INFO GitHubActionsService] Finished operation Location.GetConnectionData [RUNNER 2024-05-31 19:22:57Z INFO GitHubActionsService] Finished operation Location.GetConnectionData [RUNNER 2024-05-31 19:22:57Z INFO GitHubActionsService] Finished operation Location.GetConnectionData [RUNNER 2024-05-31 19:22:58Z INFO MessageListener] VssConnection created [RUNNER 2024-05-31 19:22:58Z INFO Terminal] WRITE LINE:

√ Connected to GitHub [RUNNER 2024-05-31 19:22:58Z INFO Terminal] WRITE LINE:

[RUNNER 2024-05-31 19:22:58Z INFO RSAFileKeyManager] Loading RSA key parameters from file /home/runner/.credentials_rsaparams [RUNNER 2024-05-31 19:22:58Z INFO RSAFileKeyManager] Loading RSA key parameters from file /home/runner/.credentials_rsaparams [RUNNER 2024-05-31 19:22:58Z INFO GitHubActionsService] AAD Correlation ID for this token request: Unknown [RUNNER 2024-05-31 19:22:58Z INFO MessageListener] Session created. [RUNNER 2024-05-31 19:22:58Z INFO Terminal] WRITE LINE: Current runner version: '2.317.0' Current runner version: '2.317.0' [RUNNER 2024-05-31 19:22:58Z INFO Terminal] WRITE LINE: 2024-05-31 19:22:58Z: Listening for Jobs 2024-05-31 19:22:58Z: Listening for Jobs [RUNNER 2024-05-31 19:22:58Z INFO JobDispatcher] Set runner/worker IPC timeout to 30 seconds.`

[tabossert]

From Runner $ curl http://cache-service:3000 OK$

[tabossert]

Cache server logs [cache-server] ℹ Using database driver: sqlite [cache-server] ℹ Migrating database... [cache-server] ✔ Database migrated [cache-server] ℹ Using storage driver: filesystem [cache-server] ℹ Cleaning up cache entries older than 90d with schedule 0 0 * * * (next run: 6/1/2024, 12:00:00 AM) Listening on http://[::]:3000

[LouisHaftmann]

Do you have the logs of the workflow run that failed? Or just the error message.

[tabossert]

[tabossert]

Is there any specific ways to get logs that might help better debug this?

[LouisHaftmann]

Try setting DEBUG=true on the cache server and also update it to the latest version.

[LouisHaftmann]

And rerun the workflow with debug logs enabled.

[tabossert]

I might be setting it wrong but I added the DEBUG=true as an env var on the container but wasn't getting any additional logs from it. I verified that the container image is the latest as is the github actions runner version.

[LouisHaftmann]

The An internal error has occurred in cache backend. Please check https://www.githubstatus.com/ for any ongoing issue in actions. indicates that the ACTIONS_CACHE_URL is not set at all. Could you share your Dockerfile or wherever you set the ACTIONS_CACHE_URL env var?

[LouisHaftmann]

Gonna close this for now. Feel free to reopen.