SSL handshake timeout leaves persistent connections hanging

[jlesueur]

Description

We have a redis server, we're using the phpredis extension to connect to it. The phpredis extension is built on top of php's stream sockets. The bug I'm reporting can be duplicated without the phpredis extension.

Sometimes, a redis server will timeout during the ssl negotiation. This will generate a warning from php_openssl_enable_crypto(). If there is an error handler that stops execution on warnings, then the underlying connection will be left in place, even without SSL negotiation succeeding. We can see this by looking at client list on the redis server. The connection will still be hanging around, for as long as the fpm process exists.

For testing purposes, we can disable tls on the redis server, which will force the "handshake timed out" results.

Is there a reason that the connection is maintained even if the ssl negotiation fails? Could/should php close the connection when ssl negotiation fails?

The following code:

<?php

set_error_handler(function($errno, $errstring, $errfile, $errline, $errcontext) {
	var_dump(get_resources());
	exit(1);
});
$socket = stream_socket_client("tls://redis:6379", $error_code, $error_message, 0.2, STREAM_CLIENT_CONNECT | STREAM_CLIENT_PERSISTENT, stream_context_create(['tls' => ['verify_peer_name' => false]]));
echo "here";

Resulted in this output:

array(2) { [2]=> resource(2) of type (stream-context) [3]=> resource(3) of type (persistent stream) }

But I expected this output instead:

array(2) { [2]=> resource(2) of type (stream-context) }

PHP Version

PHP 7.4.28

Operating System

Ubuntu 20.04

[cmb69]

This looks related to https://bugs.php.net/bug.php?id=79501.

[staabm]

OT: it has to be related.. it was posted on the very same day - 2 years ago ;-)

[bukka]

Just FYI I have got this on my list with relatively high priority. Although there's bunch of other things so it might take few months to get this resolved.

[jlesueur]

Thanks for the update, let me know if there's something I can do to make duplication easier.

[bukka]

I assume it's this, right? phpredis/phpredis#1726 . After reading it, it seems that it's specific to TLS 1.3. Can you confirm that it's just related to TLS 1.3? Also does this happen with the latest Redis server version?

[jlesueur]

I ran this to check if tls version matters:

<?php

set_error_handler(function($errno, $errstring, $errfile, $errline, $errcontext) {
        var_dump(get_resources());
        exit(1);
});
$socket = stream_socket_client("tlsv1.2://redis:6379", $error_code, $error_message, 0.2, STREAM_CLIENT_CONNECT | STREAM_CLIENT_PERSISTENT, stream_context_create(['tls' => ['verify_peer_name' => false]]));
echo "here";

Sorry, this is long. tl;dr: I am proposing that the internals stream code should close connections where the tls handshake has timed out before emitting a warning.

For some context, I don't think the issue I'm seeing is the same as phpredis/phpredis#1726
How we found this issue was that we're moving to redis as a session store. We're using persistent connections to limit the number of new connections that need to be created, however, we still sometimes see bursts of new fpm workers coming online, triggering 500 or more new tls-enabled connections to redis. Redis does not like this. It starts to bog down, and ssl connections start to take longer and longer, eventually hitting our timeout (which we set somewhat aggressively at .2 seconds). In this case, the timeout is not a bug with php or redis, but a capacity problem at the redis server. But there is some strange behavior, in that the connections where phpredis hit the timeout while negotiating the tls handshake, are not closed until the fpm process exits. This meant each new request created a new connection, failed tls, but left that connection open, resulting in 20k open connections on a redis host.

This was because the stream internals code emits a warning when the tls handshake times out, and then returns the connection to the phpredis extension, and the phpredis extension attempts to work with the connection, notices communication problems, and closes the connection, except if an error handler exists that stops execution in the case of warnings. In that case, the connection is not closed.

[bukka]

I took a closer look on this one and the problem is basically that there is an area of code in _php_stream_xport_create (specifically everything after stream is created and freed:

php-src/main/streams/transports.c

Lines 130 to 182 in 80197c5

	stream = (factory)(protocol, n,
	(char*)name, namelen, persistent_id, options, flags, timeout,
	context STREAMS_REL_CC);
	if (stream) {
	php_stream_context_set(stream, context);
	if ((flags & STREAM_XPORT_SERVER) == 0) {
	/* client */
	if (flags & (STREAM_XPORT_CONNECT|STREAM_XPORT_CONNECT_ASYNC)) {
	if (-1 == php_stream_xport_connect(stream, name, namelen,
	flags & STREAM_XPORT_CONNECT_ASYNC ? 1 : 0,
	timeout, &error_text, error_code)) {
	ERR_RETURN(error_string, error_text, "connect() failed: %s");
	failed = 1;
	}
	}
	} else {
	/* server */
	if (flags & STREAM_XPORT_BIND) {
	if (0 != php_stream_xport_bind(stream, name, namelen, &error_text)) {
	ERR_RETURN(error_string, error_text, "bind() failed: %s");
	failed = 1;
	} else if (flags & STREAM_XPORT_LISTEN) {
	zval *zbacklog = NULL;
	int backlog = 32;
	if (PHP_STREAM_CONTEXT(stream) && (zbacklog = php_stream_context_get_option(PHP_STREAM_CONTEXT(stream), "socket", "backlog")) != NULL) {
	backlog = zval_get_long(zbacklog);
	}
	if (0 != php_stream_xport_listen(stream, backlog, &error_text)) {
	ERR_RETURN(error_string, error_text, "listen() failed: %s");
	failed = 1;
	}
	}
	}
	}
	}
	if (failed) {
	/* failure means that they don't get a stream to play with */
	if (persistent_id) {
	php_stream_pclose(stream);
	} else {
	php_stream_close(stream);
	}
	stream = NULL;
	}

) where it's not safe to trigger error as it can call error handler which exits so the stream cannot be cleaned up which is especially issue for persistent streams like it's the case here.

I think it's not very practical handle it in every function that triggers error but instead store the errors and emit them later (after freeing the stream). The good thing that we have got already in core (used for inheritance) some functionality to record errors so I will take a look if we could modify that slightly so we can do just record and then reply it after the stream is cleaned up.