TLS handshake timeout error when using CLI

[dspain]

After installing the exercism CLI for the first time yesterday, I kept getting TLS handshake timeout errors:

$ exercism configure --token=*** -v

========================= BEGIN DumpRequest =========================
GET /v1/ping HTTP/1.1
Host: api.exercism.io
Content-Type: application/json
User-Agent: github.com/exercism/cli v3.0.11 (darwin/amd64)


========================= END DumpRequest =========================

Error: The base API URL 'https://api.exercism.io/v1' cannot be reached.

Get https://api.exercism.io/v1/ping: net/http: TLS handshake timeout

Adding the --no-verify flag fixes the configure issue:

$ exercism configure --token=*** -v --no-verify

You have configured the Exercism command-line client:

Config dir:                       /Users/damianspain/.config/exercism
Token:         (-t, --token)      ***
Workspace:     (-w, --workspace)  /Users/damianspain/Exercism
API Base URL:  (-a, --api)        https://api.exercism.io/v1

However, there is no --no-verify flag for the download command, so I'm stuck:

exercism download --exercise=hello-world --track=elixir -v

========================= BEGIN DumpRequest =========================
GET /v1/solutions/latest?exercise_id=hello-world&track_id=elixir HTTP/1.1
Host: api.exercism.io
Authorization: Bearer ***
Content-Type: application/json
User-Agent: github.com/exercism/cli v3.0.11 (darwin/amd64)


========================= END DumpRequest =========================

Error: Get https://api.exercism.io/v1/solutions/latest?exercise_id=hello-world&track_id=elixir: net/http: TLS handshake timeout

If I go to the api endpoint using curl or in chrome it returns what appears to be an empty JSON object, with no TLS handshake error.

I am not behind a proxy or a firewall.

Any help would be appreciated.

[dspain]

Just an update - I originally ran this using v3.0.11, but I upgraded to the latest version and the error still exists for v3.0.12.

I also checked v3.0.0 and got a slightly different error, but it still didn't work:

exercism download --exercise=hello-world --track=elixir -v

========================= BEGIN DumpRequest =========================
GET /v1/solutions/latest?exercise_id=hello-world&track_id=elixir HTTP/1.1
Host: api.exercism.io
Authorization: Bearer ***
Content-Type: application/json
User-Agent: github.com/exercism/cli v3.0.0 (darwin/amd64)


========================= END DumpRequest =========================

Error: Get https://api.exercism.io/v1/solutions/latest?exercise_id=hello-world&track_id=elixir: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)

I haven't tried anything between v3.0.0 and v3.0.11, but I assume none of those will work either.

[iHiD]

I have absolutely no idea on this. @NobbZ - any wisdom?

[NobbZ]

Sadly not. If there is neither a proxy or firewall then it should just work…

And if I recall correctly, I tried already helping through the gitter and finally pointed the user here, hoping that the broader audience might have higher wisdom with network related issues like this…

And since this persists for 2+ weeks now, I can assume its no CDN outage or similar either…

[iHiD]

@NobbZ Thanks.

@ccare @kytrinyx Any ideas?

[kytrinyx]

I am completely stumped!

[ccare]

@dspain Hello, sorry to hear you're having trouble, it sounds really frustrating. Assuming you're on a linux/unix flavoured system, would you be able to try the following for me? If you're on Windows, let me know and I'll update accordingly.

NO_PROXY="api.exercism.io" exercism configure -v

Any output would be appreciated - mask out tokens like you did before.

The other thing that would be interesting would be to know the output of the following

env | grep -i -e http -e proxy

[dspain]

Hi @ccare - thanks for looking at this! I'm on a Mac so, your assumption is correct.

Here's the output for the first command:

$ NO_PROXY="api.exercism.io" exercism configure --token=*** -v

========================= BEGIN DumpRequest =========================
GET /v1/ping HTTP/1.1
Host: api.exercism.io
Content-Type: application/json
User-Agent: github.com/exercism/cli v3.0.12 (darwin/amd64)


========================= END DumpRequest =========================

Error: The base API URL 'https://api.exercism.io/v1' cannot be reached.

Get https://api.exercism.io/v1/ping: net/http: TLS handshake timeout

Second command produces no output. I don't have any environment variables with "http" or "proxy" in the name.

[ccare]

Hi @dspain - yes I thought the proxy thing was a bit of a long-shot... but you never know!

I wonder what your machine is resolving us to. Would you be able to run dig api.exercism.io in the console and see what IP it resolves to. You mentioned it worked in Chrome, what about Safari?

[ccare]

It might also be worth trying exercism troubleshoot, I think that'll try pinging GitHub too, and might give us some additional information.

[dspain]

Here's the output of dig api.exercism.io:

$ dig api.exercism.io

; <<>> DiG 9.10.6 <<>> api.exercism.io
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 21824
;; flags: qr rd ra; QUERY: 1, ANSWER: 3, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 512
;; QUESTION SECTION:
;api.exercism.io.		IN	A

;; ANSWER SECTION:
api.exercism.io.	60	IN	A	52.51.223.176
api.exercism.io.	60	IN	A	46.51.205.192
api.exercism.io.	60	IN	A	52.215.70.93

;; Query time: 21 msec
;; SERVER: 75.75.75.75#53(75.75.75.75)
;; WHEN: Thu Jul 25 18:17:56 PDT 2019
;; MSG SIZE  rcvd: 92

and exercism troubleshoot:

$ exercism troubleshoot

Troubleshooting Information
===========================

Version
----------------
Current: 3.0.12
Latest:  <unknown>

Error: Get https://api.github.com/repos/exercism/cli/releases/latest: net/http: TLS handshake timeout

Call 'exercism upgrade' to get the latest version.
See the release notes at https://github.com/exercism/cli/releases/tag/ for details.


Operating System
----------------
OS:           darwin
Architecture: amd64


Configuration
----------------
Home:      /Users/damianspain
Workspace: /Users/damianspain/Exercism
Config:    /Users/damianspain/.config/exercism
API key:   b1cd*****************************5fd

API Reachability
----------------

GitHub:
    * https://api.github.com
    * [connected]
    * 278.522654ms

Exercism:
    * https://api.exercism.io/v1/ping
    * [connected]
    * 734.393793ms


If you are having trouble please file a GitHub issue at
https://github.com/exercism/exercism.io/issues and include
this information.

Safari also returns that empty JSON object that I see in Chrome.

[ccare]

@kytrinyx , you know more about the CLI and Golang than me, but I think this is - as, in hindsight, the original message indicated actually - a clientside timeout. If you look at @dspain's network stats, the call to GitHub is working in 278ms as is the call to us (but in 734ms). For me, connecting from the UK I get this

GitHub:
    * https://api.github.com
    * [connected]
    * 136.771141ms

Exercism:
    * https://api.exercism.io/v1/ping
    * [connected]
    * 213.338826ms

So, I'm now thinking that @dspain is experiencing connection waits that are approaching 1 second, could there be a timeout in the CLI that needs raising?

update: A quick grok of https://golang.org/pkg/net/http/ indicates the default might be 10 seconds.

[NobbZ]

Yes, there is a timeout, and it can be overridden using the --timeout argument in many cases.

AFAIR the default is already a full minute…

[ccare]

Yes I saw that in the code. I don't know enough to understand if that timeout applies to the TLS exchange, or just the subsequent HTTP request.

…

On Fri, 26 Jul 2019, 10:00 Norbert Melzer, ***@***.***> wrote: Yes, there is a timeout, and it can be overridden using the --timeout argument in many cases. AFAIR the default is already a full minute… — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#48?email_source=notifications&email_token=AADLWQVLGQ4EPTLWZQAKXBDQBK4MHA5CNFSM4IGJWY6KYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD2364MI#issuecomment-515370545>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AADLWQQK6TD4MTZFDBMYI4DQBK4MHANCNFSM4IGJWY6A> .

[kytrinyx]

@dspain would you try using the --timeout flag with something like 300, maybe, to see if that works?

[dspain]

@kytrinyx - I tried --timeout 300 & --timeout 500 for both the exercism download and exercism configure commands, and I also tried with & without the NO_PROXY="api.exercism.io" env variable. They all resulted in the same error as above.

Strangely, the error comes back in only 10-15 seconds so it doesn't seem like the timeout is actually being applied.

[kytrinyx]

Strangely, the error comes back in only 10-15 seconds so it doesn't seem like the timeout is actually being applied.

That's a good observation!

I wonder if the TLS handshake timeout is different from the HTTP request timeout.

[dspain]

Another thing I noticed - if I curl the URL, the TLS handshake works. It returns an empty JSON object, but I'm assuming that's because it isn't doing any kind of authorization:

$ curl -v https://api.exercism.io/v1
*   Trying 52.215.70.93...
* TCP_NODELAY set
* Connected to api.exercism.io (52.215.70.93) port 443 (#0)
...
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS change cipher, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Finished (20):
...
< X-Runtime: 0.002636
<
* Connection #0 to host api.exercism.io left intact

Makes me think it's not a TLS handshake issue at all but I'm kinda out of my element here. I can provide the ... parts of the above output if you think it would help.

[dspain]

Hm - looks like a similar issue was opened about a year ago:
exercism/cli#701
and was fixed here:
exercism/cli#720

I tried running v3.0.8 and v3.0.9 since those were the releases that were before/after the change was made. The only difference for me is that's where my error message changed from

net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)

to

TLS handshake timeout

😄

[kytrinyx]

Similar, but not same enough, apparently, to be fixed by the same fix. I don't recall the TLS Timeout being configurable, though they may have changed that.

[ccare]

@kytrinyx - when I was trying to find my way around this issue - I came across TLSHandshakeTimeout (see https://golang.org/src/net/http/transport.go) which seemed to default at 10 seconds. But I couldn't work out from the go code whether we were initialising that differently...

...or even whether that variable only applied to the server-side stuff in go net/http

[kytrinyx]

@ccare ok, that's excellent.

I think we need to add that here: https://github.com/exercism/cli/blob/a1ddb0c8d13efd3e174a72b21a2af0f150c99cde/api/client.go#L20

[ccare]

Cool. I'll try and do a PR if I get a chance later.

…

On Tue, 30 Jul 2019, 17:38 Katrina Owen, ***@***.***> wrote: @ccare <https://github.com/ccare> ok, that's excellent. I think we need to add that here: https://github.com/exercism/cli/blob/a1ddb0c8d13efd3e174a72b21a2af0f150c99cde/api/client.go#L20 — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#48?email_source=notifications&email_token=AADLWQXEMUUZATRZYSEPFFTQCBVATA5CNFSM4IGJWY6KYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD3ESEHI#issuecomment-516497949>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AADLWQQOXTY3YHKBZ5IXRODQCBVATANCNFSM4IGJWY6A> .

[dspain]

Hi @kytrinyx, @ccare - is there a workaround I can use while waiting for the fix?

[kytrinyx]

@dspain to download you could copy/paste from the web interface, I think, and you could write a script in the language of your choice that submits to the API using the same endpoint, format, and API token as the CLI. That's undocumented though, so that would involve some careful poking around.

[dspain]

Thanks @kytrinyx - I was able to use a combination of postman/curl/ruby to download the problem files. I solved the "hello-world" exercise and tried to submit using exercism submit [filename] but got the dreaded TLS handshake timeout error again.

So I used exercism submit -v [filename] to get the appropriate API parameters and after some false starts/red herrings/typical debugging process, I was able to submit my solution using postman.

I'll keep monitoring this ticket for updates, but in the meantime I'll use my hacky process to download and submit files.

Let me know if I can help out with testing, but I should tell you that when I tried to modify the Go code I also got a TLS handshake timeout error after I tried to build using the process outlined here: https://github.com/exercism/cli/blob/master/CONTRIBUTING.md

Lastly, not a huge deal, but there is a spelling inconsistency (requester/requestor) that messed me up for longer than I'd like to admit 😄: https://github.com/exercism/cli/blob/89e80c45d13bae9c969025515b175d16ea713fdf/cmd/submit.go#L423-L425

[kytrinyx]

Oh jeez. I'm so sorry this is so painful (and the spelling mistake that just makes everything worse!)

[mislav]

This might have been caused by a known Go issue that was patched just yesterday golang/go#19561 (comment)

It would affect macOS users who 1) had many extra certificates with custom trust settings in their Keychain and 2) would try to run a Go program that was compiled with CGO disabled (e.g. cross-compiled for macOS on Linux).

Until the next Go release, users might work around it by either cleaning up unnecessary custom certificates from their Keychain or by compiling exercism from source on their own machine.

[iHiD]

/wave at @mislav - Long time no speak :)

Awesome. Thanks. We've been having lots of weird issues with connectivity recently so this would be great if that solves those.