Python 3: How to log server side SSL handshake errors
I am using HTTPServer for a basic HTTP server using SSL. I would like to log anytime the client initiates an SSL handshake (or perhaps anytime the socket is accepted?) Along with any associated errors. I am guessing that I will need to extend the class or override some method, but I'm not sure which or how to properly implement it. I would really appreciate any help. Thanks in advance!
Sample code example:
from http.server import BaseHTTPRequestHandler, HTTPServer
from socketserver import ThreadingMixIn
from threading import Thread
import ssl
import logging
import sys
class MyHTTPHandler(BaseHTTPRequestHandler):
def log_message(self, format, *args):
logger.info("%s - - %s" % (self.address_string(), format%args))
def do_GET(self):
self.send_response(200)
self.end_headers()
self.wfile.write('test'.encode("utf-8"))
class ThreadedHTTPServer(ThreadingMixIn, HTTPServer):
pass
logger = logging.getLogger('myserver')
handler = logging.FileHandler('server.log')
formatter = logging.Formatter('[%(asctime)s] %(message)s')
handler.setFormatter(formatter)
logger.addHandler(handler)
logger.setLevel(logging.DEBUG)
server = ThreadedHTTPServer(('', 443), MyHTTPHandler)
server.socket = ssl.wrap_socket (server.socket, keyfile='server.key', certfile='server.crt', server_side=True, cert_reqs=ssl.CERT_REQUIRED, ca_certs='client.crt')
Thread(target=server.serve_forever).start()
try:
quitcheck = input("Type 'quit' at any time to quit.\n")
if quitcheck == "quit":
server.shutdown()
except (KeyboardInterrupt) as error:
server.shutdown()
source to share
From looking at the module, ssl
most of the relevant magic happens in the classroom . SSLSocket
ssl.wrap_socket()
is a tiny convenience function that basically serves as a factory for SSLSocket
with some reasonable defaults and wraps an existing socket.
Unfortunately, SSLSocket
it doesn't seem to follow any of its own protocols, so there is no easy way to increase the logging level, set a flag, debug
or register any handlers.
So what can you do instead of this subclass SSLSocket
, override the methods you are interested in and make some notes, and also create and use your own helper function wrap_socket
.
Subclass SSLSocket
First copy ssl.wrap_socket()
from your Python .../lib/python2.7/ssl.py
to your code. (Make sure that any code you copy and modify actually comes from the Python installation you are using - the code may have changed between different Python versions).
Now adjust your copy wrap_socket()
to
- create an instance
LoggingSSLSocket
(which will be implemented below) instead ofSSLSocket
- and use constants from the module
ssl
where necessary (ssl.CERT_NONE
andssl.PROTOCOL_SSLv23
in this example)
def wrap_socket(sock, keyfile=None, certfile=None,
server_side=False, cert_reqs=ssl.CERT_NONE,
ssl_version=ssl.PROTOCOL_SSLv23, ca_certs=None,
do_handshake_on_connect=True,
suppress_ragged_eofs=True,
ciphers=None):
return LoggingSSLSocket(sock=sock, keyfile=keyfile, certfile=certfile,
server_side=server_side, cert_reqs=cert_reqs,
ssl_version=ssl_version, ca_certs=ca_certs,
do_handshake_on_connect=do_handshake_on_connect,
suppress_ragged_eofs=suppress_ragged_eofs,
ciphers=ciphers)
Now change your line
server.socket = ssl.wrap_socket (server.socket, ...)
to
server.socket = wrap_socket(server.socket, ...)
to use your own wrap_socket()
.
Now for the subclass SSLSocket
. Create a class LoggingSSLSocket
that subclasses SSLSocket
by adding the following to your code:
class LoggingSSLSocket(ssl.SSLSocket):
def accept(self, *args, **kwargs):
logger.debug('Accepting connection...')
result = super(LoggingSSLSocket, self).accept(*args, **kwargs)
logger.debug('Done accepting connection.')
return result
def do_handshake(self, *args, **kwargs):
logger.debug('Starting handshake...')
result = super(LoggingSSLSocket, self).do_handshake(*args, **kwargs)
logger.debug('Done with handshake.')
return result
Here we override accept()
and do_handshake()
methods ssl.SSLSocket
- everything else remains the same, because the class inherits from SSLSocket
.
General approach to overriding methods
I've used a specific pattern to override these methods to make it easier to apply to just about any method you've ever overridden:
def methodname(self, *args, **kwargs):
*args, **kwargs
ensures that our method accepts any number of positional and keyword arguments, if any. accept
doesn't actually accept any of these, but it still works because of Python's packing / unpacking argument lists .
logger.debug('Before call to superclass method')
This is where you get to do your thing before calling the superclass method.
result = super(LoggingSSLSocket, self).methodname(*args, **kwargs)
This is the actual call to the superclass method. For more details on how this works, see the docs onsuper()
, but mostly calls .methodname()
on LoggingSSLSocket
superclass ( SSLSocket
). Since we are passing in a method *args, **kwargs
, we are simply passing any positional and keyword arguments our method receives - we don't even need to know what they are, the method signatures will always match.
Since some methods (for example accept()
) will return a result, we'll save this result
and return it at the end of our method, before doing our work after the call:
logger.debug('After call.')
return result
Recording more details
If you want to include more information in your logging statements, you may have to completely overwrite the corresponding methods. So copy them over and modify them as needed, and make sure you are satisfied with the missing imports.
Here's an example for accept()
that includes the IP address and local port of the client trying to connect:
def accept(self):
"""Accepts a new connection from a remote client, and returns
a tuple containing that new connection wrapped with a server-side
SSL channel, and the address of the remote client."""
newsock, addr = socket.accept(self)
logger.debug("Accepting connection from '%s'..." % (addr, ))
newsock = self.context.wrap_socket(newsock,
do_handshake_on_connect=self.do_handshake_on_connect,
suppress_ragged_eofs=self.suppress_ragged_eofs,
server_side=True)
logger.debug('Done accepting connection.')
return newsock, addr
(Be sure to include from socket import socket
in your imports at the top of your code - refer to the module ssl
to determine where you need to import the missing names if you got one NameError
. A good text editor is PyFlakes
very helpful in pointing out those imports that are missing).
This method will result in a log entry like this:
[2014-10-24 22:01:40,299] Accepting connection from '('127.0.0.1', 64152)'...
[2014-10-24 22:01:40,300] Done accepting connection.
[2014-10-24 22:01:40,301] Accepting connection from '('127.0.0.1', 64153)'...
[2014-10-24 22:01:40,302] Done accepting connection.
[2014-10-24 22:01:40,306] Accepting connection from '('127.0.0.1', 64155)'...
[2014-10-24 22:01:40,307] Done accepting connection.
[2014-10-24 22:01:40,308] 127.0.0.1 - - "GET / HTTP/1.1" 200 -
Because this includes quite a few changes scattered all over the place, here's a gist containing all the changes to your example code .
source to share