Can the same timeouts on the HTTP server and client cause problems?

[tchaloupka]

Some calls between our services end up with strange error:

[0FB99F23:E8466F22 2017.10.12 22:07:34.021 dbg] object.Exception@../../../../../.dub/packages/vibe-d-0.8.1/vibe-d/tls/vibe/stream/openssl.d(391): Reading from TLS stream: error:80000001:lib(128):func(0):reason(1) (2147483649)
----------------
../../../../../.dub/packages/vibe-d-0.8.1/vibe-d/tls/vibe/stream/openssl.d:391 @safe int vibe.stream.openssl.OpenSSLStream.enforceSSL(int, immutable(char)[]) [0x1715544]
../../../../../.dub/packages/vibe-d-0.8.1/vibe-d/tls/vibe/stream/openssl.d:349 @safe int vibe.stream.openssl.OpenSSLStream.checkSSLRet(int, immutable(char)[]) [0x171502f]
../../../../../.dub/packages/vibe-d-0.8.1/vibe-d/tls/vibe/stream/openssl.d:257 @property @safe ulong vibe.stream.openssl.OpenSSLStream.leastSize() [0x17148c0]
../../../../../.dub/packages/vibe-d-0.8.1/vibe-d/tls/vibe/stream/openssl.d:252 @property @safe bool vibe.stream.openssl.OpenSSLStream.empty() [0x171483a]
../../../../../.dub/packages/vibe-d-0.8.1/vibe-d/http/vibe/http/client.d:531 @safe bool vibe.http.client.HTTPClient.doRequestWithRetry(scope void delegate(vibe.http.client.HTTPClientRequest), bool, out bool, out std.datetime.systime.SysTime) [0x166ad83]
../../../../../.dub/packages/vibe-d-0.8.1/vibe-d/http/vibe/http/client.d:462 @trusted void vibe.http.client.HTTPClient.request(scope void delegate(scope vibe.http.client.HTTPClientRequest), scope void delegate(scope vibe.http.client.HTTPClientResponse)) [0x166a768]
../../../../../.dub/packages/vibe-d-0.8.1/vibe-d/http/vibe/http/client.d:178 @safe void vibe.http.client.requestHTTP(vibe.inet.url.URL, void delegate(scope vibe.http.client.HTTPClientRequest), scope void delegate(scope vibe.http.client.HTTPClientResponse), const(vibe.http.client.HTTPClientSettings)) [0x1669615]
../../../../../.dub/packages/vibe-d-0.8.1/vibe-d/http/vibe/http/client.d:133 @safe void vibe.http.client.requestHTTP(immutable(char)[], scope void delegate(scope vibe.http.client.HTTPClientRequest), scope void delegate(scope vibe.http.client.HTTPClientResponse), const(vibe.http.client.HTTPClientSettings)) [0x16692d5]

On the server side there is not much information, but I noticed this:

[06024939:DB518938 2017.10.12 22:07:33.952 dbg] Keep-alive connection timed out!
[06024939:DB518938 2017.10.12 22:07:33.952 dbg] TCP close request true open
[06024939:DB518938 2017.10.12 22:07:33.952 dia] Actively closing TCP connection
[06024939:DB518938 2017.10.12 22:07:33.952 dbg] task out (fd -1).
[06024939:DB518938 2017.10.12 22:07:33.952 dbg] task finished.
[06024939:DB518938 2017.10.12 22:07:33.952 dbg] TCP close request false open

The communitation is on the localhost

I found that HTTPServer and HTTPClient by default uses the same keep-alive timeout:

vibe.d/http/vibe/http/client.d

Line 254 in f5f35b6

Duration defaultKeepAliveTimeout = 10.seconds;

vibe.d/http/vibe/http/server.d

Line 655 in af86e65

Duration keepAliveTimeout = 10.seconds;

Could this theoretically lead to the described problem?

[s-ludwig]

I was going to say that the client removes a few seconds from the reported timeout to avoid a race condition, but checking the code revealed that this code has been removed at some point. So this would indeed explain the exception. I'll have to investigate why this was removed.

[s-ludwig]

Relevant issue and PR: #448 and #450

I think both, the client and the server, need to allow some leeway. I'll add configuration options for both.