classification
Title: Asyncio Fatal Error on SSL Transport - IndexError Deque Index Out Of Range
Type: behavior Stage:
Components: asyncio, SSL Versions: Python 3.7
process
Status: open Resolution:
Dependencies: Superseder:
Assigned To: christian.heimes Nosy List: asvetlov, ben.brown, christian.heimes, yselivanov
Priority: normal Keywords:

Created on 2019-06-11 08:44 by ben.brown, last changed 2019-06-12 11:08 by asvetlov.

Messages (11)
msg345201 - (view) Author: Ben Brown (ben.brown) Date: 2019-06-11 08:44
I have been getting an intermittent errors when using asyncio with SSL. The error always occurs in the _process_write_backlog method in asyncio's sslproto.py file. I have looked at lots of possibilities as to what the cause is and found that for some reason when in _process_write_backlog's loop the deque seems to be empty, I added some quick terrible hacky code to confirm it fixed the issue and checking at each point it is used wether it is empty fixes the issue, I am unusure as to what causes it to become empty but still run through the loop. The most frequent time it happens is after we have a successful message the client sends a request to join a data stream this request mostly causes the error but sometimes it happens while the client is receiving data. I am currently using python 3.7.1 but have also tested my code on 3.7.3 with the same result. 

NOTE: I am currently working on a minimal sample to show the issue easier.

Fatal error on SSL transport
protocol: <asyncio.sslproto.SSLProtocol object at 0x7f267462e780>
transport: <_SelectorSocketTransport fd=38 read=polling write=<idle, bufsize=0>>
Traceback (most recent call last):
    File "/usr/local/lib/python3.7/asyncio/sslproto.py", line 689, in _process_write_backlog
    del self._write_backlog[0]
IndexError: deque index out of range

Fatal error on SSL transport
protocol: <asyncio.sslproto.SSLProtocol object at 0x7f45f802ec88>
transport: <_SelectorSocketTransport fd=29 read=polling write=<idle, bufsize=0>>
Traceback (most recent call last):
    File "/usr/local/lib/python3.7/asyncio/sslproto.py", line 664, in _process_write_backlog
    data, offset = self._write_backlog[0]
IndexError: deque index out of range
msg345202 - (view) Author: Christian Heimes (christian.heimes) * (Python committer) Date: 2019-06-11 08:47
This looks more like an asyncio problem than an SSL problem. Andrew, Yury,  please take a look.
msg345211 - (view) Author: Andrew Svetlov (asvetlov) * (Python committer) Date: 2019-06-11 09:41
Just to clarify: what OpenSSL version is used?
msg345212 - (view) Author: Ben Brown (ben.brown) Date: 2019-06-11 09:43
The OpenSSL version is OpenSSL 1.1.0j  20 Nov 2018
msg345213 - (view) Author: Andrew Svetlov (asvetlov) * (Python committer) Date: 2019-06-11 10:00
That's what I afraid.
asyncio/sslproto.py fails on new OpenSSL at several places :(
msg345214 - (view) Author: Ben Brown (ben.brown) Date: 2019-06-11 10:08
That's a shame, which version should it work on I don't mind downgrading for now to fix the issue as a workaround.
msg345215 - (view) Author: Christian Heimes (christian.heimes) * (Python committer) Date: 2019-06-11 10:09
Is 1.1.0 also a problem? I have only seen issue with 1.1.1 and TLS 1.3.
msg345223 - (view) Author: Ben Brown (ben.brown) Date: 2019-06-11 11:22
I am using the version I mentioned above 1.1.0 and TLS 1.2, I am sorry I can't be of more help.
msg345241 - (view) Author: Ben Brown (ben.brown) Date: 2019-06-11 15:38
I tested an older version of OpenSSL 1.0.2g and I get the same error on that
msg345316 - (view) Author: Ben Brown (ben.brown) Date: 2019-06-12 11:05
I have created a minimal example if that helps to show the issue https://gist.github.com/bobthemac/031213b8e37960ee805f2ae1e6990b60
msg345317 - (view) Author: Andrew Svetlov (asvetlov) * (Python committer) Date: 2019-06-12 11:08
Thank you!
Yuri, you might be interested too
History
Date User Action Args
2019-06-12 11:08:58asvetlovsetmessages: + msg345317
2019-06-12 11:05:45ben.brownsetmessages: + msg345316
2019-06-11 15:38:34ben.brownsetmessages: + msg345241
2019-06-11 11:22:52ben.brownsetmessages: + msg345223
2019-06-11 10:09:56christian.heimessetmessages: + msg345215
2019-06-11 10:08:56ben.brownsetmessages: + msg345214
2019-06-11 10:00:13asvetlovsetmessages: + msg345213
2019-06-11 09:43:20ben.brownsetmessages: + msg345212
2019-06-11 09:41:20asvetlovsetmessages: + msg345211
2019-06-11 08:47:56christian.heimessetnosy: + asvetlov, yselivanov
messages: + msg345202
components: + asyncio
2019-06-11 08:44:59ben.browncreate