Self-hosted Runners Timeout on Authentication with EC2 Instances #47563

jkruse14 · 2023-02-15T15:43:56Z

jkruse14
Feb 15, 2023

Select Topic Area

Question

Body

I'm using phllips-labs/terraform-aws-github-runner to create self-hosted runners on EC2 instances. The user-script runs fine until I get to the Authentication step when running the config script, it just hangs:

<13>Feb 15 14:36:54 user-data: --------------------------------------------------------------------------------
<13>Feb 15 14:36:54 user-data: |        ____ _ _   _   _       _          _        _   _                      |
<13>Feb 15 14:36:54 user-data: |       / ___(_) |_| | | |_   _| |__      / \   ___| |_(_) ___  _ __  ___      |
<13>Feb 15 14:36:54 user-data: |      | |  _| | __| |_| | | | | '_ \    / _ \ / __| __| |/ _ \| '_ \/ __|     |
<13>Feb 15 14:36:54 user-data: |      | |_| | | |_|  _  | |_| | |_) |  / ___ \ (__| |_| | (_) | | | \__ \     |
<13>Feb 15 14:36:54 user-data: |       \____|_|\__|_| |_|\__,_|_.__/  /_/   \_\___|\__|_|\___/|_| |_|___/     |
<13>Feb 15 14:36:54 user-data: |                                                                              |
<13>Feb 15 14:36:54 user-data: |                       Self-hosted runner registration                        |
<13>Feb 15 14:36:54 user-data: |                                                                              |
<13>Feb 15 14:36:54 user-data: --------------------------------------------------------------------------------
<13>Feb 15 14:36:54 user-data: 
<13>Feb 15 14:36:54 user-data: # Authentication
<13>Feb 15 14:36:54 user-data: 
<13>Feb 15 14:46:55 user-data: The HTTP request timed out after 00:01:00.

I've seen the _diag logs requested in other issues, so here is the last bit of it (immediately following the logo printout):

2023-02-15 15:20:23Z INFO ConfigurationManager] ConfigureAsync
[2023-02-15 15:20:23Z INFO CommandSettings] Flag 'generateServiceConfig': 'False'
[2023-02-15 15:20:23Z INFO ConfigurationStore] IsConfigured()
[2023-02-15 15:20:23Z INFO ConfigurationStore] IsConfigured: False
[2023-02-15 15:20:23Z INFO ConfigurationManager] Is configured: False
[2023-02-15 15:20:23Z INFO CommandSettings] Arg 'url': 'https://github.com/DoosanBobcatSandbox'
[2023-02-15 15:20:23Z INFO CommandSettings] Remove url from Arg dictionary.
[2023-02-15 15:20:23Z INFO CommandSettings] Arg 'token': '***'
[2023-02-15 15:20:23Z INFO CommandSettings] Remove token from Arg dictionary.
[2023-02-15 15:20:24Z INFO ConfigurationManager] Http response code: OK from 'POST https://api.github.com/actions/runner-registration' (4778:7458:1BDA4C9:3907870:63ECF838)
[2023-02-15 15:20:24Z INFO ConfigurationManager] cred retrieved via GitHub auth
[2023-02-15 15:20:24Z INFO RunnerServer] EstablishVssConnection
[2023-02-15 15:20:24Z INFO RunnerServer] Establish connection with 100 seconds timeout.
[2023-02-15 15:20:24Z INFO GitHubActionsService] Starting operation Location.GetConnectionData
[2023-02-15 15:20:24Z INFO RunnerServer] EstablishVssConnection
[2023-02-15 15:20:24Z INFO RunnerServer] Establish connection with 60 seconds timeout.
[2023-02-15 15:20:24Z INFO GitHubActionsService] Starting operation Location.GetConnectionData
[2023-02-15 15:20:24Z INFO RunnerServer] EstablishVssConnection
[2023-02-15 15:20:24Z INFO RunnerServer] Establish connection with 60 seconds timeout.
[2023-02-15 15:20:24Z INFO GitHubActionsService] Starting operation Location.GetConnectionData
[2023-02-15 15:21:24Z WARN GitHubActionsService] GET request to https://pipelines.actions.githubusercontent.com/WwH58rYm16yb81FWQzkSnD8S3sUx9xj40RpAMo2ZqlfENPswJB/_apis/connectionData?connectOptions=1&lastChangeId=-1&lastChangeId64=-1 timed out after 60 seconds.
[2023-02-15 15:21:24Z WARN GitHubActionsService] GET request to https://pipelines.actions.githubusercontent.com/WwH58rYm16yb81FWQzkSnD8S3sUx9xj40RpAMo2ZqlfENPswJB/_apis/connectionData?connectOptions=1&lastChangeId=-1&lastChangeId64=-1 timed out after 60 seconds.
[2023-02-15 15:21:24Z INFO GitHubActionsService] Finished operation Location.GetConnectionData
[2023-02-15 15:21:24Z INFO GitHubActionsService] Finished operation Location.GetConnectionData
[2023-02-15 15:21:24Z INFO GitHubActionsService] Starting operation Location.GetConnectionData
[2023-02-15 15:21:24Z INFO GitHubActionsService] Starting operation Location.GetConnectionData

When I curl the pipleines.actions.githubuserconetent.com URL above, it gives a 200 immediately with a lot of output.

Does anyone have any ideas as to why it might be hanging or how I should proceed?

Update

I got more information from the _daig log file:

2023-02-15 15:55:02Z INFO GitHubActionsService] Starting operation Location.GetConnectionData
[2023-02-15 15:56:02Z WARN GitHubActionsService] GET request to https://pipelines.actions.githubusercontent.com/WwH58rYm16yb81FWQzkSnD8S3sUx9xj40RpAMo2ZqlfENPswJB/_apis/connectionData?connectOptions=1&lastChangeId=-1&lastChangeId64=-1 timed out after 60 seconds.
[2023-02-15 15:56:02Z INFO GitHubActionsService] Finished operation Location.GetConnectionData
[2023-02-15 15:56:02Z WARN GitHubActionsService] GET request to https://pipelines.actions.githubusercontent.com/WwH58rYm16yb81FWQzkSnD8S3sUx9xj40RpAMo2ZqlfENPswJB/_apis/connectionData?connectOptions=1&lastChangeId=-1&lastChangeId64=-1 timed out after 60 seconds.
[2023-02-15 15:56:02Z INFO GitHubActionsService] Finished operation Location.GetConnectionData
[2023-02-15 15:56:02Z INFO CommandSettings] Flag 'unattended': 'True'
[2023-02-15 15:56:02Z ERR  Runner] System.TimeoutException: The HTTP request timed out after 00:01:00.
 ---> System.Threading.Tasks.TaskCanceledException: A task was canceled.
   at System.Threading.Tasks.TaskCompletionSourceWithCancellation`1.WaitWithCancellationAsync(CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.GetHttp11ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.AuthenticationHelper.SendWithAuthAsync(HttpRequestMessage request, Uri authUri, Boolean async, ICredentials credentials, Boolean preAuthenticate, Boolean isProxyAuth, Boolean doRequestAuth, HttpConnectionPool pool, CancellationToken cancellationToken)
   at System.Net.Http.DecompressionHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at GitHub.Services.Common.VssHttpMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at GitHub.Services.Common.VssHttpMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
   at GitHub.Services.Common.VssHttpRetryMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   at GitHub.Services.WebApi.VssHttpClientBase.SendAsync(HttpRequestMessage message, HttpCompletionOption completionOption, Object userState, CancellationToken cancellationToken)
   at GitHub.Services.WebApi.VssHttpClientBase.SendAsync[T](HttpRequestMessage message, Object userState, CancellationToken cancellationToken)
   at GitHub.Services.Location.Client.LocationHttpClient.GetConnectionDataAsync(ConnectOptions connectOptions, Int64 lastChangeId, CancellationToken cancellationToken, Object userState)
   at GitHub.Services.WebApi.Location.VssServerDataProvider.GetConnectionDataAsync(ConnectOptions connectOptions, Int32 lastChangeId, CancellationToken cancellationToken)
   at GitHub.Services.WebApi.Location.VssServerDataProvider.ConnectAsync(ConnectOptions connectOptions, CancellationToken cancellationToken)
   at GitHub.Runner.Common.RunnerService.EstablishVssConnection(Uri serverUrl, VssCredentials credentials, TimeSpan timeout)
   at GitHub.Runner.Common.RunnerServer.ConnectAsync(Uri serverUrl, VssCredentials credentials)
   at GitHub.Runner.Listener.Configuration.ConfigurationManager.ConfigureAsync(CommandSettings command)
   at GitHub.Runner.Listener.Runner.ExecuteCommand(CommandSettings command)
[2023-02-15 15:56:02Z ERR  Runner] #####################################################
[2023-02-15 15:56:02Z ERR  Runner] System.Threading.Tasks.TaskCanceledException: A task was canceled.
   at System.Threading.Tasks.TaskCompletionSourceWithCancellation`1.WaitWithCancellationAsync(CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.GetHttp11ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.AuthenticationHelper.SendWithAuthAsync(HttpRequestMessage request, Uri authUri, Boolean async, ICredentials credentials, Boolean preAuthenticate, Boolean isProxyAuth, Boolean doRequestAuth, HttpConnectionPool pool, CancellationToken cancellationToken)
   at System.Net.Http.DecompressionHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at GitHub.Services.Common.VssHttpMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
[2023-02-15 15:56:02Z ERR  Terminal] WRITE ERROR: The HTTP request timed out after 00:01:00.
[2023-02-15 15:56:02Z INFO Listener] Runner execution has finished with return code 1

cloud-init-outp.log also says the user-data script failed:

Feb 15 15:56:02 cloud-init[1222]: util.py[WARNING]: Running module scripts-user (<module 'cloudinit.config.cc_scripts_user' from '/usr/lib/python2.7/site-packages/cloudinit/config/cc_scripts_user.pyc'>) failed

Answered by jkruse14

Feb 22, 2023

I just found the answer and tested. The issue seems to be with IPv6. I removed the IPv6 assignment from the runner as it was starting up and everything ran fine.

I created subnets without IPv6 (setting assign_ipv6_address_on_creation to false) and the issue was then resolved and authentication took place.

Side note: originally, amazon-linux-extras just hung during the start up when trying to install docker. This resolved that issue as well.

View full answer

vitalykarasik · 2023-02-16T05:36:47Z

vitalykarasik
Feb 16, 2023

The HTTP request timed out after 00:01:00.

My bet is that your EC2 SG denies outgoing connections.
I'll suggest deactivating deleting this EC2 in your flow, so you'll be able to log in and debug manually.

5 replies

jkruse14 Feb 16, 2023
Author

The HTTP request timed out after 00:01:00.

My bet is that your EC2 SG denies outgoing connections. I'll suggest deactivating deleting this EC2 in your flow, so you'll be able to log in and debug manually.

Thanks for your response! I can log into the EC2 instances created with SSM and use curl to hit the endpoints. Wouldn't curl fail if the SG was denying outgoing connections?

jkruse14 Feb 16, 2023
Author

I've confirmed the Security Group allows outbound HTTPS traffic

jkruse14 Feb 16, 2023
Author

The VPC NACL is also set to allow all traffic on all ports.
VPC flow logs don't show any REJECTed traffic.

vitalykarasik Feb 17, 2023

I see.
So I suggest setting all relevant environment variables and trying to setup github runner manually - hopefully, it'll help to understand the root case for this issue.

jkruse14 Feb 18, 2023
Author

I've run this locally and had no issues. I see it register successfully from my local machine. From what I've read, the runner and config process uses a HTTPS long poll. I want to double check that SSH is not used because we do block that.

jkruse14 · 2023-02-16T16:49:55Z

jkruse14
Feb 16, 2023
Author

I realized now that authentication doesn't seem to be the issue. I assume these lines mean the registration and authentication of the runner was successful:

[2023-02-15 15:20:24Z INFO ConfigurationManager] Http response code: OK from 'POST https://api.github.com/actions/runner-registration' (4778:7458:1BDA4C9:3907870:63ECF838)
[2023-02-15 15:20:24Z INFO ConfigurationManager] cred retrieved via GitHub auth

0 replies

konstantinos-kafkas-cko · 2023-02-21T19:53:52Z

konstantinos-kafkas-cko
Feb 21, 2023

I am having the exact same issue, did you come up with a resolution here?

0 replies

jkruse14 · 2023-02-22T12:05:15Z

jkruse14
Feb 22, 2023
Author

I just found the answer and tested. The issue seems to be with IPv6. I removed the IPv6 assignment from the runner as it was starting up and everything ran fine.

I created subnets without IPv6 (setting assign_ipv6_address_on_creation to false) and the issue was then resolved and authentication took place.

Side note: originally, amazon-linux-extras just hung during the start up when trying to install docker. This resolved that issue as well.

2 replies

konstantinos-kafkas-cko Feb 22, 2023

So it's my understanding that all it took was to set the environment variable assign_ipv6_address_on_creation to false, is this the OS environment variable or something else?

jkruse14 Apr 6, 2023
Author

So it's my understanding that all it took was to set the environment variable assign_ipv6_address_on_creation to false, is this the OS environment variable or something else?

assign_ipv6_address_on_creation is a setting on the subnet configuration - see here in cloudformation and here in terraform (same field)

stbischof · 2023-05-12T15:28:45Z

stbischof
May 12, 2023

Have the same but on a metal box from hetzner. any ideas how to solve?

4 replies

moltar Nov 15, 2023

Same here. Have you figured it out @stbischof?

stbischof Nov 15, 2023

Disable ipv6 Network Interfaces in command Center..

Something like this helped. Cant remember really. How this was solved.

moltar Nov 15, 2023

command Center

Is that a Hetzner feature?

stbischof Nov 15, 2023

somewhere in this hetzner robot interface on network

mario-sangar · 2023-08-01T12:01:00Z

mario-sangar
Aug 1, 2023

Following up with the answer by @jkruse14, the issue is somehow related to the IPv6 configuration. I had this problem in a bare-metal provider, so I couldn't use the assign_ipv6_address_on_creation option as in AWS EC2. In fact, the provider doesn't seem to have the option to disable it from the console.

My take on this was finally to disable the IPv6 traffic in the machine itself, using sysctl.

net.ipv6.conf.all.disable_ipv6=1
net.ipv6.conf.default.disable_ipv6=1
net.ipv6.conf.lo.disable_ipv6=1

After a restart on the github runner service, it was able to connect normally and fulfill the session connection establishment.

0 replies

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

GitHub Community

Self-hosted Runners Timeout on Authentication with EC2 Instances #47563

{{title}}

{{editor}}'s edit

{{editor}}'s edit

Replies: 6 comments 11 replies

{{title}}

{{title}}

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

Select a reply

Self-hosted Runners Timeout on Authentication with EC2 Instances #47563

Select Topic Area

Body

Update

Replies: 6 comments · 11 replies

jkruse14 Feb 16, 2023 Author

jkruse14 Feb 16, 2023 Author

jkruse14 Feb 16, 2023 Author

jkruse14 Feb 18, 2023 Author

jkruse14 Feb 16, 2023 Author

jkruse14 Feb 22, 2023 Author

jkruse14 Apr 6, 2023 Author

Replies: 6 comments 11 replies

jkruse14 Feb 16, 2023
Author

jkruse14 Feb 16, 2023
Author

jkruse14 Feb 16, 2023
Author

jkruse14 Feb 18, 2023
Author

jkruse14
Feb 16, 2023
Author

jkruse14
Feb 22, 2023
Author

jkruse14 Apr 6, 2023
Author