vibe-d / vibe.d

Official vibe.d development
MIT License
1.15k stars 284 forks source link

HTTPS connections timeout/fail with exception #1631

Open Marenz opened 7 years ago

Marenz commented 7 years ago

Very suddenly, my HTTPS connections start to fail. I was using the dummy certificate at first provided in the https example, but I also generated my own for another instance, but both show the same problem. One is vibe 29, the other the latest.

Here is what the log shows:

Nov 23 17:07:07 timeoutd masterbeta[32755]: 93.219.94.189 - - 2016-Nov-23 16:06:37.6829753Z "GET / HTTP/1.1" 200 - "-" "-"
Nov 23 17:07:07 timeoutd masterbeta[32755]: task out (fd -1).
Nov 23 17:07:07 timeoutd masterbeta[32755]: task finished.
Nov 23 17:07:07 timeoutd masterbeta[32755]: TCP close request false open
Nov 23 17:07:07 timeoutd masterbeta[32755]: Socket event on fd 25: 17 (29C5698 vs 29C5698)
Nov 23 17:07:07 timeoutd masterbeta[32755]: Connection was closed by remote peer (fd 25).
Nov 23 17:07:07 timeoutd masterbeta[32755]: Error while writing the response: Connection error while reading from TCPConnection.
Nov 23 17:07:07 timeoutd masterbeta[32755]: Exception while handling request GET /: object.Exception@../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/core/drivers/libevent2_tcp.d(438): Connection error while reading from TCPConnection.
Nov 23 17:07:07 timeoutd masterbeta[32755]: ----------------
Nov 23 17:07:07 timeoutd masterbeta[32755]: ../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/core/drivers/libevent2_tcp.d:438 void vibe.core.drivers.libevent2_tcp.Libevent2TCPConnection.checkConnected(bool) [0x104ba62]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/core/drivers/libevent2_tcp.d:302 void vibe.core.drivers.libevent2_tcp.Libevent2TCPConnection.read(ubyte[]) [0x104ad93]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/stream/counting.d:62 void vibe.stream.counting.LimitedInputStream.read(ubyte[]) [0x1082925]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/stream/operations.d:355 void vibe.stream.operations.readUntilSmall!(vibe.utils.array.AllocAppender!(ubyte[], ubyte).AllocAppender).readUntilSmall(vibe.core.stream.InputStream, ref vibe.utils.array.AllocAppender!(ubyte[], ubyte).AllocAppender, const(ubyte[]), ulong) [0xf8ba18]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/stream/operations.d:137 void vibe.stream.operations.readUntil!(vibe.utils.array.AllocAppender!(ubyte[], ubyte).AllocAppender).readUntil(vibe.core.stream.InputStream, ref vibe.utils.array.AllocAppender!(ubyte[], ubyte).AllocAppender, const(ubyte[]), ulong) [0xf8b863]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/stream/operations.d:53 void vibe.stream.operations.readLine!(vibe.utils.array.AllocAppender!(ubyte[], ubyte).AllocAppender).readLine(vibe.core.stream.InputStream, ref vibe.utils.array.AllocAppender!(ubyte[], ubyte).AllocAppender, ulong, immutable(char)[]) [0xf8b80c]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/stream/operations.d:39 ubyte[] vibe.stream.operations.readLine!().readLine(vibe.core.stream.InputStream, ulong, immutable(char)[], vibe.utils.memory.Allocator) [0xf8b7c8]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/http/server.d:1971 void vibe.http.server.parseRequestHeader(vibe.http.server.HTTPServerRequest, vibe.core.stream.InputStream, vibe.utils.memory.Allocator, ulong) [0x1015e43]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/http/server.d:1769 bool vibe.http.server.handleRequest(vibe.core.stream.Stream, vibe.core.net.TCPConnection, vibe.http.server.HTTPListenInfo, ref vibe.http.server.HTTPServerSettings, ref bool) [0x1013be6]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/http/server.d:1662 void vibe.http.server.handleHTTPConnection(vibe.core.net.TCPConnection, vibe.http.server.HTTPListenInfo) [0x1013470]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/http/server.d:1543 void vibe.http.server.listenHTTPPlain(vibe.http.server.HTTPServerSettings).doListen(vibe.http.server.HTTPListenInfo, bool, bool).__lambda4(vibe.core.net.TCPConnection) [0x1012e18]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/core/drivers/libevent2_tcp.d:618 void vibe.core.drivers.libevent2_tcp.ClientTask.execute() [0x10abbdd]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/core/core.d:592 void vibe.core.core.makeTaskFuncInfo!(void delegate()).makeTaskFuncInfo(ref void delegate()).callDelegate(vibe.core.core.TaskFuncInfo*) [0xf83721]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ../../.dub/packages/vibe-d-0.7.30/vibe-d/source/vibe/core/core.d:1221 void vibe.core.core.CoreTask.run() [0x103db59]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ??:? void core.thread.Fiber.run() [0x113f4e9]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ??:? fiber_entryPoint [0x113f263]
Nov 23 17:07:07 timeoutd masterbeta[32755]: ??:? [0xffffffff]
Nov 23 17:07:07 timeoutd masterbeta[32755]: 93.219.94.189 - - 2016-Nov-23 16:06:37.6841907Z "GET / HTTP/1.1" 200 - "-" "-"
Nov 23 17:07:07 timeoutd masterbeta[32755]: task out (fd -1).
Nov 23 17:07:07 timeoutd masterbeta[32755]: task finished.
Nov 23 17:07:07 timeoutd masterbeta[32755]: TCP close request false open

Here is the code that sets up the HTTPS:

    auto https_router = new URLRouter;

    with(https_router)
    {
        any("*", &allowAllOrigins);
        match(HTTPMethod.OPTIONS, "/*", &handleOptions);
        // now any request is matched and checked for authentication:
        any("*", performBasicAuth("Site Realm", toDelegate(&checkPassword)));

        get("/green", &managers.matchmaking.getGreen);
        get("/red", &managers.matchmaking.getRed);
        get("/live", &managers.matchmaking.getLive);
    }

    auto https_settings = new HTTPServerSettings;

    with (https_settings)
    {
        port = config.monitor_port;
        bindAddresses = [config.listen_addr];
        tlsContext = createTLSContext(TLSContextKind.server);
        tlsContext.useCertificateChainFile(config.server_cert);
        tlsContext.usePrivateKeyFile(config.server_key);
    }

    listenHTTP(https_settings, https_router);
s-ludwig commented 7 years ago

Sorry for the late reply, I just noticed this now. The call trace above looks like the connection is actually just an unencrypted HTTP connection, just the Libevent2TCPConnection wrapped in a LimitedInputStream. However, the setup sequence looks unsuspicious. Is there any chance that the code below does not belong to the setup sequence below?

Marenz commented 7 years ago

This is some time ago now. But I suspect what happened was that I called the https connection with a http:// prefix in the browser (happens easily when you use non-std ports).

Maybe it would be good to have some dumb check in the HTTPS part to see if it is normal HTTP and give a better error message?