tls-sni-02, "connection reset by peer" on PEBBLE_VA_NOSLEEP about pebble HOT 11 CLOSED

I just read your comment right now, a little too late for helping you...

Basically, all you need to do is:

• Install Java, Maven and Docker.
• Edit acme-it/pom.xml and comment in the <env> block with PEBBLE_VA_NOSLEEP.
• Then invoke mvn -Pci verify. It builds and starts the docker images, and runs the tests.

But I'm glad that you could figure it out yourself. If there's anything missing in the documentation that would have helped you, please let me know.

from pebble.

Most likely your client isn't waiting for your TLS server to be set up before POSTing to the challenge, so you have a race. This is a pretty common failure mode, since the TLS server generally has to be configured in a different process, thread, or {g,c}oroutine. You can do a variety of things to make sure the TLS server is ready before POSTing, from waiting on a semaphore (threads or goroutines) to checking whether the relevant TCP port can be opened (processes).

This suggests that even when NOSLEEP isn't set, we should have one of our checks that always runs as quickly as possible.

from pebble.

I thought so, too... So I set a breakpoint in my code, and manually checked that the TLS server is ready and delivers the correct certificate, before sending the challenge POST request. I also see in the logs that the TLS server responds to a certificate request by Pebble.

from pebble.

I have added debug log output to va.go's fetchCerts(): a line when the function is invoked, one if err != nil, and another one when conn.Close() is invoked within the defer func().

Without PEBBLE_VA_NOSLEEP=1, fetchCerts() is invoked three times, at different times:

Pulled a task from the Tasks queue: &va.vaTask{Identifier:"example.com", Challenge:(*core.Challenge)(0xc4204642c0), Account:(*core.Account)(0xc420486180)}
Starting 3 validations.
Sleeping for 11s seconds before validating
Sleeping for 12s seconds before validating
Sleeping for 2s seconds before validating
[2 seconds later...]
********* fetchCerts(): example.com:443, a063d94f5bf38bfeea7b142b2ead2855.33d14859d348287838c7690ba0bcc0d1.token.acme.invalid
********* conn.Close()
[9 seconds later...]
********* fetchCerts(): example.com:443, a063d94f5bf38bfeea7b142b2ead2855.33d14859d348287838c7690ba0bcc0d1.token.acme.invalid
********* conn.Close()
[1 second later...]
********* fetchCerts(): example.com:443, a063d94f5bf38bfeea7b142b2ead2855.33d14859d348287838c7690ba0bcc0d1.token.acme.invalid
********* conn.Close()

With PEBBLE_VA_NOSLEEP=1, fetchCerts() is invoked three times simultaneously. The first thread actually fetches the validation certificate successfully, and closes the connection. But it seems that the other two connections are closed as well. The second and third thread get a network error, and the validation finally fails:

Pulled a task from the Tasks queue: &va.vaTask{Identifier:"example.com", Challenge:(*core.Challenge)(0xc4204e8210), Account:(*core.Account)(0xc4204ac2a0)}
Starting 3 validations.
********* fetchCerts(): example.com:443, 41f342da5ccb3ca82b73b009f2ac04eb.2d91064012fd92c7470eb8ae38a05850.token.acme.invalid
********* fetchCerts(): example.com:443, 41f342da5ccb3ca82b73b009f2ac04eb.2d91064012fd92c7470eb8ae38a05850.token.acme.invalid
********* fetchCerts(): example.com:443, 41f342da5ccb3ca82b73b009f2ac04eb.2d91064012fd92c7470eb8ae38a05850.token.acme.invalid
********* conn.Close()
********* Error: read tcp 172.17.0.3:40170->172.17.0.2:443: read: connection reset by peer
********* Error: read tcp 172.17.0.3:40164->172.17.0.2:443: read: connection reset by peer

I'm not sure what happens in the background, but I guess that Go's DialWithDialer() returns the same Conn object all three times.

from pebble.

Ooh, this looks interesting. I agree, I'm not totally sure what's happening here, but it does seem like it could be a problem with Pebble, or with Go reusing conn objects. Will take a look, thanks for the report!

from pebble.

Does this happen with the HTTP challenge?

from pebble.

No, only tls-sni-02.

from pebble.

@shred I built acme4j's draft branch locally to try and reproduce this bug. It's been a looooong time since I've used Maven, is there an easy way to run the integration tests locally against a Pebble instance? I don't have a docker daemon handy on the machine I'm using today. Importing the project into Eclipse made this easy enough however the OrderIT integration tests are failing for me with:
org.shredzone.acme4j.exception.AcmeProtocolException: orders: bad URL. Going to dig further, it seems like the accounts get created correctly on the Pebble instance

Update 2: Aha! There's a Pebble workarounds bool I missed. I think #43 will make this unnecessary.

Update 3: Was able to reproduce with Acme4J - I'll see what I can figure out.

from pebble.

I'm pretty baffled! I read through the Go 1.8 TLS code and can't spot any obvious place where it would be reusing connections. I also ran Pebble through strace and it seemed like there are multiple calls to socket to create outbound connections.

I also created a small test program that starts a TLS server on 1443 and then spawns a number of concurrent connections using the same tls.DialWithDialer approach as the Pebble VA. No matter how many connections I start at once in individual goroutines I'm not able to reproduce the failures seen with Acme4J.

This feels like something specific to the Acme4J server but I don't have any strong evidence except that I can't reproduce it with a different server & a simpler reproduction program :(

I'm out of time to hack around today but I will try and pick this up again soon. It's a compelling mystery!!!

from pebble.

No, it's not a mystery... I'm an idiot, that's all.

In my TlsSniServer, I have placed a bad loop. After accepting and processing a connection, I have closed and reopened the socket, instead of just waiting for the next connection. It was working fine and nobody would have noticed, until Pebble started to open three simultaneous connections. My server responded to the first connection, and then closed the socket, killing the other two.

I don't know why I haven't thought of that before... I have fixed the loop, and now the test is running fine.

I am really sorry for having wasted your time...

from pebble.

No, it's not a mystery... I'm an idiot, that's all.

@shred Hahaha. We've all been there. 😆

I'm glad to hear you figured it out. It wasn't a waste, now I have a functional acme4j environment to play around with 💻 🔍 I'm really grateful for your implementation of the V2 API!

from pebble.