bpo-34271: Add ssl debugging helpers (GH-10031)
The ssl module now can dump key material to a keylog file and trace TLS
protocol messages with a tracing callback. The default and stdlib
contexts also support SSLKEYLOGFILE env var.
The msg_callback and related enums are private members. The feature
is designed for internal debugging and not for end users.
Signed-off-by: Christian Heimes <christian@python.org>
diff --git a/Modules/_ssl.c b/Modules/_ssl.c
index 4fb7dca..f40127d 100644
--- a/Modules/_ssl.c
+++ b/Modules/_ssl.c
@@ -185,6 +185,10 @@
# define HAVE_NPN 0
#endif
+#if (OPENSSL_VERSION_NUMBER >= 0x10101000L) && !defined(LIBRESSL_VERSION_NUMBER)
+#define HAVE_OPENSSL_KEYLOG 1
+#endif
+
#ifndef INVALID_SOCKET /* MS defines this */
#define INVALID_SOCKET (-1)
#endif
@@ -424,6 +428,11 @@
#ifdef TLS1_3_VERSION
int post_handshake_auth;
#endif
+ PyObject *msg_cb;
+#ifdef HAVE_OPENSSL_KEYLOG
+ PyObject *keylog_filename;
+ BIO *keylog_bio;
+#endif
} PySSLContext;
typedef struct {
@@ -444,6 +453,13 @@
PyObject *owner; /* Python level "owner" passed to servername callback */
PyObject *server_hostname;
_PySSLError err; /* last seen error from various sources */
+ /* Some SSL callbacks don't have error reporting. Callback wrappers
+ * store exception information on the socket. The handshake, read, write,
+ * and shutdown methods check for chained exceptions.
+ */
+ PyObject *exc_type;
+ PyObject *exc_value;
+ PyObject *exc_tb;
} PySSLSocket;
typedef struct {
@@ -517,6 +533,8 @@
#define GET_SOCKET_TIMEOUT(sock) \
((sock != NULL) ? (sock)->sock_timeout : 0)
+#include "_ssl/debughelpers.c"
+
/*
* SSL errors.
*/
@@ -703,6 +721,18 @@
Py_XDECREF(verify_obj);
}
+static int
+PySSL_ChainExceptions(PySSLSocket *sslsock) {
+ if (sslsock->exc_type == NULL)
+ return 0;
+
+ _PyErr_ChainExceptions(sslsock->exc_type, sslsock->exc_value, sslsock->exc_tb);
+ sslsock->exc_type = NULL;
+ sslsock->exc_value = NULL;
+ sslsock->exc_tb = NULL;
+ return -1;
+}
+
static PyObject *
PySSL_SetError(PySSLSocket *sslsock, int ret, const char *filename, int lineno)
{
@@ -796,6 +826,7 @@
}
fill_and_set_sslerror(sslsock, type, p, errstr, lineno, e);
ERR_clear_error();
+ PySSL_ChainExceptions(sslsock);
return NULL;
}
@@ -903,6 +934,9 @@
self->owner = NULL;
self->server_hostname = NULL;
self->err = err;
+ self->exc_type = NULL;
+ self->exc_value = NULL;
+ self->exc_tb = NULL;
/* Make sure the SSL error state is initialized */
ERR_clear_error();
@@ -1052,11 +1086,12 @@
Py_XDECREF(sock);
if (ret < 1)
return PySSL_SetError(self, ret, __FILE__, __LINE__);
-
+ if (PySSL_ChainExceptions(self) < 0)
+ return NULL;
Py_RETURN_NONE;
-
error:
Py_XDECREF(sock);
+ PySSL_ChainExceptions(self);
return NULL;
}
@@ -2151,8 +2186,26 @@
"The Python-level owner of this object.\
Passed as \"self\" in servername callback.");
+static int
+PySSL_traverse(PySSLSocket *self, visitproc visit, void *arg)
+{
+ Py_VISIT(self->exc_type);
+ Py_VISIT(self->exc_value);
+ Py_VISIT(self->exc_tb);
+ return 0;
+}
-static void PySSL_dealloc(PySSLSocket *self)
+static int
+PySSL_clear(PySSLSocket *self)
+{
+ Py_CLEAR(self->exc_type);
+ Py_CLEAR(self->exc_value);
+ Py_CLEAR(self->exc_tb);
+ return 0;
+}
+
+static void
+PySSL_dealloc(PySSLSocket *self)
{
if (self->ssl)
SSL_free(self->ssl);
@@ -2333,13 +2386,14 @@
err.ssl == SSL_ERROR_WANT_WRITE);
Py_XDECREF(sock);
- if (len > 0)
- return PyLong_FromLong(len);
- else
+ if (len <= 0)
return PySSL_SetError(self, len, __FILE__, __LINE__);
-
+ if (PySSL_ChainExceptions(self) < 0)
+ return NULL;
+ return PyLong_FromLong(len);
error:
Py_XDECREF(sock);
+ PySSL_ChainExceptions(self);
return NULL;
}
@@ -2486,6 +2540,8 @@
PySSL_SetError(self, count, __FILE__, __LINE__);
goto error;
}
+ if (self->exc_type != NULL)
+ goto error;
done:
Py_XDECREF(sock);
@@ -2498,6 +2554,7 @@
}
error:
+ PySSL_ChainExceptions(self);
Py_XDECREF(sock);
if (!group_right_1)
Py_XDECREF(dest);
@@ -2601,11 +2658,13 @@
/* Retain the SSL error code */
break;
}
-
if (ret < 0) {
Py_XDECREF(sock);
- return PySSL_SetError(self, ret, __FILE__, __LINE__);
+ PySSL_SetError(self, ret, __FILE__, __LINE__);
+ return NULL;
}
+ if (self->exc_type != NULL)
+ goto error;
if (sock)
/* It's already INCREF'ed */
return (PyObject *) sock;
@@ -2614,6 +2673,7 @@
error:
Py_XDECREF(sock);
+ PySSL_ChainExceptions(self);
return NULL;
}
@@ -2889,8 +2949,8 @@
0, /*tp_as_buffer*/
Py_TPFLAGS_DEFAULT, /*tp_flags*/
0, /*tp_doc*/
- 0, /*tp_traverse*/
- 0, /*tp_clear*/
+ (traverseproc) PySSL_traverse, /*tp_traverse*/
+ (inquiry) PySSL_clear, /*tp_clear*/
0, /*tp_richcompare*/
0, /*tp_weaklistoffset*/
0, /*tp_iter*/
@@ -3002,6 +3062,11 @@
self->ctx = ctx;
self->hostflags = X509_CHECK_FLAG_NO_PARTIAL_WILDCARDS;
self->protocol = proto_version;
+ self->msg_cb = NULL;
+#ifdef HAVE_OPENSSL_KEYLOG
+ self->keylog_filename = NULL;
+ self->keylog_bio = NULL;
+#endif
#if HAVE_NPN
self->npn_protocols = NULL;
#endif
@@ -3127,6 +3192,7 @@
#ifndef OPENSSL_NO_TLSEXT
Py_VISIT(self->set_sni_cb);
#endif
+ Py_VISIT(self->msg_cb);
return 0;
}
@@ -3136,6 +3202,16 @@
#ifndef OPENSSL_NO_TLSEXT
Py_CLEAR(self->set_sni_cb);
#endif
+ Py_CLEAR(self->msg_cb);
+#ifdef HAVE_OPENSSL_KEYLOG
+ Py_CLEAR(self->keylog_filename);
+ if (self->keylog_bio != NULL) {
+ PySSL_BEGIN_ALLOW_THREADS
+ BIO_free_all(self->keylog_bio);
+ PySSL_END_ALLOW_THREADS
+ self->keylog_bio = NULL;
+ }
+#endif
return 0;
}
@@ -4570,6 +4646,12 @@
{"maximum_version", (getter) get_maximum_version,
(setter) set_maximum_version, NULL},
#endif
+#ifdef HAVE_OPENSSL_KEYLOG
+ {"keylog_filename", (getter) _PySSLContext_get_keylog_filename,
+ (setter) _PySSLContext_set_keylog_filename, NULL},
+#endif
+ {"_msg_callback", (getter) _PySSLContext_get_msg_callback,
+ (setter) _PySSLContext_set_msg_callback, NULL},
{"sni_callback", (getter) get_sni_callback,
(setter) set_sni_callback, PySSLContext_sni_callback_doc},
{"options", (getter) get_options,
diff --git a/Modules/_ssl/debughelpers.c b/Modules/_ssl/debughelpers.c
new file mode 100644
index 0000000..53b9667
--- /dev/null
+++ b/Modules/_ssl/debughelpers.c
@@ -0,0 +1,213 @@
+/* Debug helpers */
+
+static void
+_PySSL_msg_callback(int write_p, int version, int content_type,
+ const void *buf, size_t len, SSL *ssl, void *arg)
+{
+ const char *cbuf = (const char *)buf;
+ PyGILState_STATE threadstate;
+ PyObject *res = NULL;
+ PySSLSocket *ssl_obj = NULL; /* ssl._SSLSocket, borrowed ref */
+ PyObject *ssl_socket = NULL; /* ssl.SSLSocket or ssl.SSLObject */
+ int msg_type;
+
+ threadstate = PyGILState_Ensure();
+
+ ssl_obj = (PySSLSocket *)SSL_get_app_data(ssl);
+ assert(PySSLSocket_Check(ssl_obj));
+ if (ssl_obj->ctx->msg_cb == NULL) {
+ return;
+ }
+
+ if (ssl_obj->owner)
+ ssl_socket = PyWeakref_GetObject(ssl_obj->owner);
+ else if (ssl_obj->Socket)
+ ssl_socket = PyWeakref_GetObject(ssl_obj->Socket);
+ else
+ ssl_socket = (PyObject *)ssl_obj;
+ Py_INCREF(ssl_socket);
+
+ /* assume that OpenSSL verifies all payload and buf len is of sufficient
+ length */
+ switch(content_type) {
+ case SSL3_RT_CHANGE_CIPHER_SPEC:
+ msg_type = SSL3_MT_CHANGE_CIPHER_SPEC;
+ break;
+ case SSL3_RT_ALERT:
+ /* byte 0: level */
+ /* byte 1: alert type */
+ msg_type = (int)cbuf[1];
+ break;
+ case SSL3_RT_HANDSHAKE:
+ msg_type = (int)cbuf[0];
+ break;
+ case SSL3_RT_HEADER:
+ /* frame header encodes version in bytes 1..2 */
+ version = cbuf[1] << 8 | cbuf[2];
+ msg_type = (int)cbuf[0];
+ break;
+#ifdef SSL3_RT_INNER_CONTENT_TYPE
+ case SSL3_RT_INNER_CONTENT_TYPE:
+ msg_type = (int)cbuf[0];
+ break;
+#endif
+ default:
+ /* never SSL3_RT_APPLICATION_DATA */
+ msg_type = -1;
+ break;
+ }
+
+ res = PyObject_CallFunction(
+ ssl_obj->ctx->msg_cb, "Osiiiy#",
+ ssl_socket, write_p ? "write" : "read",
+ version, content_type, msg_type,
+ buf, len
+ );
+ if (res == NULL) {
+ PyErr_Fetch(&ssl_obj->exc_type, &ssl_obj->exc_value, &ssl_obj->exc_tb);
+ } else {
+ Py_DECREF(res);
+ }
+ Py_XDECREF(ssl_socket);
+
+ PyGILState_Release(threadstate);
+}
+
+
+static PyObject *
+_PySSLContext_get_msg_callback(PySSLContext *self, void *c) {
+ if (self->msg_cb != NULL) {
+ Py_INCREF(self->msg_cb);
+ return self->msg_cb;
+ } else {
+ Py_RETURN_NONE;
+ }
+}
+
+static int
+_PySSLContext_set_msg_callback(PySSLContext *self, PyObject *arg, void *c) {
+ Py_CLEAR(self->msg_cb);
+ if (arg == Py_None) {
+ SSL_CTX_set_msg_callback(self->ctx, NULL);
+ }
+ else {
+ if (!PyCallable_Check(arg)) {
+ SSL_CTX_set_msg_callback(self->ctx, NULL);
+ PyErr_SetString(PyExc_TypeError,
+ "not a callable object");
+ return -1;
+ }
+ Py_INCREF(arg);
+ self->msg_cb = arg;
+ SSL_CTX_set_msg_callback(self->ctx, _PySSL_msg_callback);
+ }
+ return 0;
+}
+
+#ifdef HAVE_OPENSSL_KEYLOG
+
+static void
+_PySSL_keylog_callback(const SSL *ssl, const char *line)
+{
+ PyGILState_STATE threadstate;
+ PySSLSocket *ssl_obj = NULL; /* ssl._SSLSocket, borrowed ref */
+ int res, e;
+ static PyThread_type_lock *lock = NULL;
+
+ threadstate = PyGILState_Ensure();
+
+ /* Allocate a static lock to synchronize writes to keylog file.
+ * The lock is neither released on exit nor on fork(). The lock is
+ * also shared between all SSLContexts although contexts may write to
+ * their own files. IMHO that's good enough for a non-performance
+ * critical debug helper.
+ */
+ if (lock == NULL) {
+ lock = PyThread_allocate_lock();
+ if (lock == NULL) {
+ PyErr_SetString(PyExc_MemoryError, "Unable to allocate lock");
+ PyErr_Fetch(&ssl_obj->exc_type, &ssl_obj->exc_value,
+ &ssl_obj->exc_tb);
+ return;
+ }
+ }
+
+ ssl_obj = (PySSLSocket *)SSL_get_app_data(ssl);
+ assert(PySSLSocket_Check(ssl_obj));
+ if (ssl_obj->ctx->keylog_bio == NULL) {
+ return;
+ }
+
+ PySSL_BEGIN_ALLOW_THREADS
+ PyThread_acquire_lock(lock, 1);
+ res = BIO_printf(ssl_obj->ctx->keylog_bio, "%s\n", line);
+ e = errno;
+ (void)BIO_flush(ssl_obj->ctx->keylog_bio);
+ PyThread_release_lock(lock);
+ PySSL_END_ALLOW_THREADS
+
+ if (res == -1) {
+ errno = e;
+ PyErr_SetFromErrnoWithFilenameObject(PyExc_OSError,
+ ssl_obj->ctx->keylog_filename);
+ PyErr_Fetch(&ssl_obj->exc_type, &ssl_obj->exc_value, &ssl_obj->exc_tb);
+ }
+ PyGILState_Release(threadstate);
+}
+
+static PyObject *
+_PySSLContext_get_keylog_filename(PySSLContext *self, void *c) {
+ if (self->keylog_filename != NULL) {
+ Py_INCREF(self->keylog_filename);
+ return self->keylog_filename;
+ } else {
+ Py_RETURN_NONE;
+ }
+}
+
+static int
+_PySSLContext_set_keylog_filename(PySSLContext *self, PyObject *arg, void *c) {
+ FILE *fp;
+ /* Reset variables and callback first */
+ SSL_CTX_set_keylog_callback(self->ctx, NULL);
+ Py_CLEAR(self->keylog_filename);
+ if (self->keylog_bio != NULL) {
+ BIO *bio = self->keylog_bio;
+ self->keylog_bio = NULL;
+ PySSL_BEGIN_ALLOW_THREADS
+ BIO_free_all(bio);
+ PySSL_END_ALLOW_THREADS
+ }
+
+ if (arg == Py_None) {
+ /* None disables the callback */
+ return 0;
+ }
+
+ /* _Py_fopen_obj() also checks that arg is of proper type. */
+ fp = _Py_fopen_obj(arg, "a" PY_STDIOTEXTMODE);
+ if (fp == NULL)
+ return -1;
+
+ self->keylog_bio = BIO_new_fp(fp, BIO_CLOSE | BIO_FP_TEXT);
+ if (self->keylog_bio == NULL) {
+ PyErr_SetString(PySSLErrorObject,
+ "Can't malloc memory for keylog file");
+ return -1;
+ }
+ Py_INCREF(arg);
+ self->keylog_filename = arg;
+
+ /* Write a header for seekable, empty files (this excludes pipes). */
+ PySSL_BEGIN_ALLOW_THREADS
+ if (BIO_tell(self->keylog_bio) == 0) {
+ BIO_puts(self->keylog_bio,
+ "# TLS secrets log file, generated by OpenSSL / Python\n");
+ (void)BIO_flush(self->keylog_bio);
+ }
+ PySSL_END_ALLOW_THREADS
+ SSL_CTX_set_keylog_callback(self->ctx, _PySSL_keylog_callback);
+ return 0;
+}
+
+#endif
\ No newline at end of file