RejectedSoftware Forums

Sign up

writing to server-mode SSLStream after initiating TCP connection

I've run into a really bizarre problem. I'm using createSSLStream, with a SSLContextKind.server that has a cert+key associated with it, to create an SSLStream on top of a TCPConnection I've created with connectTCP. The handshake goes fine, and I can read() on the SSLStream to get data that the other side sends. However, write()ing to it (even with a flush() afterwards) does nothing - as in, tcpdump shows that no packets ever get sent when that write() happens.

On the other hand, if I have the other side initiate the TCP connection, receiving it via listenTCP, all the SSL stuff works exactly as I would expect.

One thing that I'm thinking might be a problem: I'm using the D Thread class to spin off the thread that is doing the problematic createSSLStream()s. It and the main thread (the one that can correctly receive TLS connections) both have their own SSLContext to use, because using one that was created in the other thread was crashing the whole program. (I also had the same crashing problem with trying to share Mongo connections among threads. I tried using runTask before going to the thread approach, but it wasn't working... )

//DOES NOT WORK
class EmailMonitorThread : Thread
{
	this(){super(&run);}
private:
	void run()
	{
		client_sslctx = createSSLContext(SSLContextKind.server);
		client_sslctx.useCertificateChainFile("dirserv.crt");
		client_sslctx.usePrivateKeyFile("dirserv.key");
		client_dbClient = connectMongoDB("127.0.0.1");
		emailMonitor();
	}
}
//...
//later on...
TCPConnection con = connectTCP(curIP, port);
SSLStream theSSL = createSSLStream(con, client_sslctx);
ubyte[64] recvBuf;
ubyte[1] choiceBuf;
//the following reads work fine:
theSSL.read(recvBuf);
theSSL.read(choiceBuf);
//tcpdump shows that the following write fails to produce a packet on the network:
theSSL.write("K");
theSSL.flush();




//...
//elsewhere: THIS DOES WORK
server_sslctx = createSSLContext(SSLContextKind.server);
server_sslctx.useCertificateChainFile("dirserv.crt");
server_sslctx.usePrivateKeyFile("dirserv.key");
listenTCP(cast(ushort)8080,
(con)
{
	try
	{
		SSLStream theSSL = createSSLStream(con, server_sslctx);
                ubyte[64] recvBuf;
                ubyte[1] choiceBuf;
                //the following reads work fine:
                theSSL.read(recvBuf);
                theSSL.read(choiceBuf);
                //this time, this write works:
                theSSL.write("K");
                

So, are my not-exactly-the-vibe-way threads causing problems, am I making some non-thread-related configuration mistake, or is this a bug?

Re: writing to server-mode SSLStream after initiating TCP connection

Ahh, sorry, I knew I was going to forget something: the write() and flush() aren't blocking or throwing errors; the code just goes on its merry way.

Re: writing to server-mode SSLStream after initiating TCP connection

On Sun, 21 Sep 2014 06:38:09 GMT, Fred Douglas wrote:

I've run into a really bizarre problem. I'm using createSSLStream, with a SSLContextKind.server that has a cert+key associated with it, to create an SSLStream on top of a TCPConnection I've created with connectTCP. The handshake goes fine, and I can read() on the SSLStream to get data that the other side sends. However, write()ing to it (even with a flush() afterwards) does nothing - as in, tcpdump shows that no packets ever get sent when that write() happens.

On the other hand, if I have the other side initiate the TCP connection, receiving it via listenTCP, all the SSL stuff works exactly as I would expect.

One thing that I'm thinking might be a problem: I'm using the D Thread class to spin off the thread that is doing the problematic createSSLStream()s. It and the main thread (the one that can correctly receive TLS connections) both have their own SSLContext to use, because using one that was created in the other thread was crashing the whole program. (I also had the same crashing problem with trying to share Mongo connections among threads. I tried using runTask before going to the thread approach, but it wasn't working... )

(...)

So, are my not-exactly-the-vibe-way threads causing problems, am I making some non-thread-related configuration mistake, or is this a bug?

OpenSSL is initialized in thread-safe mode, so I would expect the thread to not be the issue in general. I'm not sure if using the same SSL context would be allowed to be used from multiple threads, though, so that crash may or may not indicate an issue with the way thread-safe OpenSSL is set up. But generally, non-shared classes in vibe.d should never be passed between threads, because they are tied to a single event loop. The only notable exceptions are ManualEvent, TaskMutex and TaskCondition.

Regarding the runTask version, it would be interesting to see why that failed, because that would usually be the best way to implement this. What exactly went wrong in that case?

To get some more data for the issue, can you run the program with --vvvv (LogLevel.trace) and see if the write("K") produces an "evbuffer_add ..." log entry? That should give a hint about the issue being on the OpenSSL side or on the libevent side of things.

BTW, the libevent driver only blocks when its internal write buffer fills up. The buffer is always written to the socket by libevent in the background, which can make debugging with a packet capture tool a bit more difficult. One possible explanation could be that the event loop gets terminated before the buffer was fully written (and the connection properly closed), but it doesn't sound like that could be the case here, right?

Re: writing to server-mode SSLStream after initiating TCP connection

Hi Sönke, thanks for the quick reply :)

First, about runTask:

Regarding the runTask version, it would be interesting to see why that failed, because that would usually be the best way to implement this. What exactly went wrong in that case?

Here's what's going on in my app.d this():


shared static this()
{	
	server_dbClient = connectMongoDB("127.0.0.1");
	
	auto settings = new HTTPServerSettings;
	settings.port = 7004;
	settings.bindAddresses = ["0.0.0.0"];
	listenHTTP(settings, &unifiedHTTP);

	server_sslctx = createSSLContext(SSLContextKind.server);
	server_sslctx.useCertificateChainFile("salmon_dirserv.crt");
	server_sslctx.usePrivateKeyFile("salmon_dirserv.key");
	listenTCP(cast(ushort)8080,
	(con)
	{
		try
		{
			SSLStream theSSL = createSSLStream(con, server_sslctx);
			//do stuff with theSSL
			theSSL.finalize();
			con.close();
		}
                catch(Exception e)
                {
                        logInfo(IPv4StringFromVibe(con) ~ ":" ~ to!string(e));
                }
	});
        
        UDPListenerThread theUDP = new UDPListenerThread();
	theUDP.start();

        //(this thread is just the contents of the following runTask.)
	EmailMonitorThread theEmailMonitor = new EmailMonitorThread();
	theEmailMonitor.start();
	
	/*runTask
	({
		client_sslctx = createSSLContext(SSLContextKind.server);
		client_sslctx.useCertificateChainFile("salmon_dirserv.crt");
		client_sslctx.usePrivateKeyFile("salmon_dirserv.key");
		client_dbClient = connectMongoDB("127.0.0.1");
		emailMonitor();
	});

	runTask
	({
		UDP_dbClient = connectMongoDB("127.0.0.1");
		
		auto udpServer = listenUDP(listenOnThisUDPPort);
		logInfo("started UDP listener on port "
                         ~to!string(listenOnThisUDPPort));
		while(true)
		{
			NetworkAddress packetFrom;
			ubyte[] buf = udpServer.recv(null, &packetFrom);
			logInfo("got UDP packet from "~to!string(packetFrom));
			maybeServerDownUDP(buf, packetFrom);
		}
	});*/
	

        logInfo("GOT HERE1");
	auto sCol = server_dbClient.getCollection(serverCollection);
	logInfo("GOT HERE2");
	logInfo(to!string(sCol.find()));
	logInfo("GOT HERE3");
	sCol.remove();
	logInfo("GOT HERE4");
	logInfo(to!string(sCol.find()));
	logInfo("GOT HERE5");
	logInfo("Everything has started.");
}

In this version, that HTTP listener works fine. If I comment either the EmailMonitor thread or the UDP thread, and uncomment the corresponding runTask, the program doesn't even reach the first line of the HTTP request handler function when my browser tries to connect.

Other than HTTP, trying to interact with Mongo also hangs. I included an example at the end: only GOT HERE1,2 will print if either of the threads are replaced with the corresponding runTask().

One possible explanation could be that the event loop gets terminated before the buffer was fully written (and the connection properly closed), but it doesn't sound like that could be the case here, right?

No, unfortunately, the problematic write() is happening inside one of those threads, rather than coming from the listenTCP delegate. The thread is definitely alive long after the write() is attempted.

--vvvv output: ("going to write K in 1" is the end of a 5 second countdown I was using to know when to be looking at tcpdump.)

[4DEBABC8:00000000 trc] timer event fired
[4DEBABC8:00000000 trc] Processing due timers
[4DEBABC8:00000000 trc] first timeout: -0.0016298
[4DEBABC8:00000000 trc] Timer 5 fired (false/false)
[4DEBABC8:00000000 trc] Processing due timers
[4DEBABC8:00000000 trc] no timers scheduled
going to write K in 1...
[4DEBABC8:00000000 dbv] rearming timer 6 in 1 s
[4DEBABC8:00000000 trc] Schedule timer 6
[4DEBABC8:00000000 trc] Rescheduled timer event for 0.999779 seconds
[4DEBABC8:00000000 dbv] first timer 6 in 0.999779 s
[4DEBABC8:00000000 trc] timer event fired
[4DEBABC8:00000000 trc] Processing due timers
[4DEBABC8:00000000 trc] first timeout: -0.0016107
[4DEBABC8:00000000 trc] Timer 6 fired (false/false)
[4DEBABC8:00000000 trc] Processing due timers
[4DEBABC8:00000000 trc] no timers scheduled
[4DEBABC8:00000000 trc] evbuffer_add (fd 28): 30 B
JUST TRIED TO WRITE K
[4DEBABC8:00000000 trc] evbuffer_add (fd 28): 110 B
[4DEBABC8:00000000 trc] SSLStream finalize
[4DEBABC8:00000000 trc] evbuffer_add (fd 28): 31 B
Replying to client with: 128.174.241.44 100
[end of output]

So, I'm guessing the evbufferadd 110 B at the end is the attempt to write K, and then the evbufferadd 31 B is the "finalize" SSL record?

Anyways, thanks a lot for your help so far, to say nothing of writing vibe.d in the first place! Other than this little snag, vibe.d has been really nice to work with. Even if this remains a mystery, I can just work around it, since the server can at least indicate it wants to talk to the other side by establishing a connection.

Re: writing to server-mode SSLStream after initiating TCP connection

I've been doing a lot more thinking on why runTask might have been making other things hang, and it's probably a long shot, but I'm wondering if runTask might not be yielding when I call a blocking function.

The documentation says "[The task] will continue to run until vibeYield() or any of the I/O or wait functions is called." One of the tasks has a stdout.readln() on a pipeProcess()'s stdout that it waits on, and the other waits on a UDPConnection.recv().

Any chance that the runTask framework would fail to yield when the task hits UDPConnection.recv() or pipeProcess().stdout.readln()?

Re: writing to server-mode SSLStream after initiating TCP connection

Ok, final update for the time being: it was in fact the case that whenever I was waiting on the stdin readln() or UDP recv() mentioned above, listenTCP couldn't accept connections and Mongo operations wouldn't go through.

For the time being I'm working around it by not using threads or runTask, and instead ensuring that both the readln() and UDP recv() will return at least once a second, and sleeping afterwards to give listenTCP a chance. (If there's a way to set a timeout for either of those functions, or make them non-blocking, please someone let me know! I couldn't find anything.)

Sönke, if the problem wasn't something silly in my code, and the information I posted above makes it seem like something is broken that you want to look into, I'll be happy to help however I can.

Re: writing to server-mode SSLStream after initiating TCP connection

Am 22.09.2014 06:51, schrieb Fred Douglas:

Ok, final update for the time being: it was in fact the case that whenever I was waiting on the stdin readln() or UDP recv() mentioned above, listenTCP couldn't accept connections and Mongo operations wouldn't go through.

That makes sense indeed. In case of the stdin access, you could use
vibe.stream.stdio.StdFileStream to wrap the blocking stream into a
non-blocking vibe.d stream. UDP recv (the vibe.d one) on the other
hand should be fine to use, as it yields control back to the event
loop when waiting.

Unfortunately there is no reliable way to detect when an incompatible
blocking function is called. Maybe it would make sense to add some kind
of watchdog thread in debug mode that outputs a message when any thread
running an event loop is blocked for more than, say, a second, and
prints out the call stack of that thread.