[issue20924] openssl init 100% CPU utilization

[Roman O. Vlasov]

Roman O. Vlasov added the comment:

To reproduce the 100% CPU load problem, we used a simple python TLS client on 
separate linux PC with Traffic control utility (tc):
tc qdisc change dev eth0 root netem delay 5000ms

After in-depth analyzing, we realized that _ssl.c behaves differently depening 
on socket.timeout:

1) sock.timeout set to None, that is equivalent to s->socket_timeout==-1 in 
_ssl.c produces 100% CPU load if client works on bad long delay channel.
The problem is this case is that the do{} loop runs in PySSL_SSLdo_handshake() 
calling check_socket_and_wait_for_timeout() which immediatly returns 
SOCKET_IS_BLOCKING because s->sock_timeout==-1. 

2) sock.timeout set to 0 (non-blocking) makes _ssl.c immediatly return with 
error:
_ssl.c: The operation did not complete

3) socket.timeout set to any positive value makes _ssl.c wait socket on select 
(producing no CPU load).

By default, accept() returns blocking socket with timeout set to None (1st case)

Below are some code details:

Our server class is inherited from asyncore.dispatcher.
In __init__ it executes the following statements (ripped), 
creating listening socket, accepting client connection and then doing 
wrap_socket:

---
asyncore.py: 
sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
sock.setblocking(0)
sock.setsockopt(
socket.SOL_SOCKET, 
socket.SO_REUSEADDR,
socket.getsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR) | 1
)
sock.bind(self.server_address)
sock.listen(5)
asyncore.loop(...)
select.select(...)  # wait for client connection

# Here client connects

conn, addr = sock.accept()
# conn.gettimeout() returns None which means blocking socket
ssl_sock = ssl.wrap_socket(
conn
, server_side = server_side
, certfile = certfile
, cert_reqs = cert_reqs
, ssl_version=ssl.PROTOCOL_SSLv3
)

File "C:\Python27\Lib\ssl.py", line 399, in wrap_socket
File "C:\Python27\Lib\ssl.py", line 152, in __init__
self.do_handshake()
File "C:\Python27\Lib\ssl.py", line 315, in do_handshake
self._sslobj.do_handshake()
_ssl.c:
PySSL_SSLdo_handshake():
// wants to read more data from socket
if (err == SSL_ERROR_WANT_READ) {
sockstate = 
check_socket_and_wait_for_timeout(self->Socket, 0);
...
check_socket_and_wait_for_timeout():
/* Nothing to do unless we're in timeout mode (not 
non-blocking) */
if (s->sock_timeout < 0.0)
return SOCKET_IS_BLOCKING;  // <-- this is 
1st case producing 100% CPU load
else if (s->sock_timeout == 0.0)
return SOCKET_IS_NONBLOCKING;   // <-- this is 2nd case 
returning error immediatly

We think that anyone who follows standard Python documentation 
(http://docs.python.org/2/library/ssl.html#server-side-operation) will get the 
same result if using client with delay>1000ms

--
nosy: +rv

___
Python tracker 
<http://bugs.python.org/issue20924>
___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue20924] openssl init 100% CPU utilization

[Roman O. Vlasov]

Roman O. Vlasov added the comment:

Antoine, Martin, thank you for your replies. You was right: NT socket was not 
in blocking mode (in 1st case). I didn't knew how to determine socket mode in 
NT, so I explicitly set socket mode to blocking in _ssl.c before calling 
SSL_do_handshake() for test:

_ssl.c::PySSL_SSLdo_handshake():

//  Explicitly set blocking mode
unsigned long iMode = 0UL; // If iMode = 0, blocking is enabled; 
int iResult = ioctlsocket( self->Socket->sock_fd, FIONBIO, &iMode );
if (iResult != NO_ERROR)
printf("\nioctlsocket failed with error: %ld\n", iResult);
// 
PySSL_BEGIN_ALLOW_THREADS
ret = SSL_do_handshake(self->ssl);
...

Test result: SSL_do_handshake() did not return (and no CPU load).

But in general, I think that check_socket_and_wait_for_timeout() logic is 
erroneous:
if (s->sock_timeout < 0.0)
return SOCKET_IS_BLOCKING;

By default (see case #1 in my message above), timeout in Python wrapping object 
is -1 (self->Socket->sock_timeout==-1). But underlying NT socket is really 
non-blocking. This leads to 100% CPU load: PySSL_SSLdo_handshake() loop is 
calling check_socket_and_wait_for_timeout() which immediately returns.

NB. I use Python 2.7.6 and openssl-0.9.8y for my build and never tried Python 3.

--

___
Python tracker 
<http://bugs.python.org/issue20924>
___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com