Critical Exception : Seg Fault when code 1006 (connection closed)

[brbatv]

Hello :)

It's been the second time i'm getting this type of error. Using python 3.7, linux mint 18.3 :
It's very hard for me to share reproductible code as it happened after several hours of connexion. But if you want to know, the script used is exactly the same as in #39
First time (yesterday) was I think after a wifi bug in my place
Today it happened more or less around when Binance opened trading again after maintenance.
Both happened after several hours of connexion with 2-3 assets with kline 1m

CRITICAL:root:BinanceWebSocketApiSocket->start_socket(f7d276df-b38e-4866-b22d-95e4a5e52ced, ['kline_1m'], ['btcusdt', 'ethusdt', 'ethbtc']) 
Exception ConnectionClosed Info: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
CRITICAL:root:BinanceWebSocketApiManager->stream_is_crashing(f7d276df-b38e-4866-b22d-95e4a5e52ced)
Segmentation fault (core dumped)

Is it a bad behaviour when Binance is reporting error 1006 (https://github.com/binance-exchange/binance-official-api-docs/blob/master/errors.md#-1006-unexpected_resp) or a problem on "my" side ? Any ideas about how to tackle and investigate this problem ? What can I do to share you more infos about what happened if it happens again ?

Thank you ❤️

[oliver-zehentleitner]

Hello! :)

I think we get this error, even if we do nothing, only receiving data. I think our pings are correct. From time to time we have to expect to get disconnected for any reason (e.g. 24 h connection reset) so we have to life with that and handle it right -> reconnect. Important is, that you will miss data which was broadcast from binance during your connection loss. My strategy is to have 2 collectors on two different machines so i receive everything two times. An other idea is a scheduled replace of the streams (#15). I think there are several ways to solve this problem.

If you want to investigate the reported error you can set logging to DEBUG and see whats happening before this error occurs.

Best regards,
Oliver

[oliver-zehentleitner]

If you start a test script and turn off your wifi or plug off the network wire, then your are going to receive exactly this error msg you posted!

https://tools.ietf.org/html/rfc6455#section-7.4.1

[brbatv]

When plugging off/on the network, multiple scenarios can happen

DEBUG:websockets.protocol:client < Frame(fin=True, opcode=1, data=b'{"stream":"btcusdt@kline_1m","data":{"e":"kline","E":1582279227981,"s":"BTCUSDT","k":{"t":1582279200000,"T":1582279259999,"s":"BTCUSDT","i":"1m","f":250357973,"L":250358164,"o":"9660.05000000","c":"9655.91000000","h":"9662.24000000","l":"9653.14000000","v":"13.34517000","n":192,"x":false,"q":"128864.46298355","V":"4.45110900","Q":"42984.84543178","B":"0"}}}', rsv1=False, rsv2=False, rsv3=False)
DEBUG:root:BinanceWebSocketApiManager->is_stop_request(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:root:BinanceWebSocketApiManager->set_heartbeat(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:websockets.protocol:client > Frame(fin=True, opcode=9, data=b'x$\x94\x04', rsv1=False, rsv2=False, rsv3=False)
DEBUG:websockets.protocol:client < Frame(fin=True, opcode=10, data=b'x$\x94\x04', rsv1=False, rsv2=False, rsv3=False)
DEBUG:websockets.protocol:client - received solicited pong: 78249404
THIS IS WHERE I DISCONNECTED/ RECONNECTED
DEBUG:websockets.protocol:client < Frame(fin=True, opcode=1, data=b'{"stream":"btcusdt@kline_1m","data":{"e":"kline","E":1582279230167,"s":"BTCUSDT","k":{"t":1582279200000,"T":1582279259999,"s":"BTCUSDT","i":"1m","f":250357973,"L":250358193,"o":"9660.05000000","c":"9657.20000000","h":"9662.24000000","l":"9653.14000000","v":"16.36057700","n":221,"x":false,"q":"157981.96915833","V":"6.40286200","Q":"61831.80602939","B":"0"}}}', rsv1=False, rsv2=False, rsv3=False)
DEBUG:root:BinanceWebSocketApiManager->is_stop_request(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:root:BinanceWebSocketApiManager->set_heartbeat(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:websockets.protocol:client < Frame(fin=True, opcode=1, data=b'{"stream":"btcusdt@kline_1m","data":{"e":"kline","E":1582279232388,"s":"BTCUSDT","k":{"t":1582279200000,"T":1582279259999,"s":"BTCUSDT","i":"1m","f":250357973,"L":250358200,"o":"9660.05000000","c":"9657.50000000","h":"9662.24000000","l":"9653.14000000","v":"17.10523700","n":228,"x":false,"q":"165173.52174913","V":"6.49236400","Q":"62696.15369399","B":"0"}}}', rsv1=False, rsv2=False, rsv3=False)
DEBUG:websockets.protocol:client < Frame(fin=True, opcode=1, data=b'{"stream":"btcusdt@kline_1m","data":{"e":"kline","E":1582279234581,"s":"BTCUSDT","k":{"t":1582279200000,"T":1582279259999,"s":"BTCUSDT","i":"1m","f":250357973,"L":250358205,"o":"9660.05000000","c":"9657.98000000","h":"9662.24000000","l":"9653.14000000","v":"17.59472700","n":233,"x":false,"q":"169900.84702937","V":"6.58185400","Q":"63560.44632419","B":"0"}}}', rsv1=False, rsv2=False, rsv3=False)
DEBUG:websockets.protocol:client < Frame(fin=True, opcode=1, data=b'{"stream":"btcusdt@kline_1m","data":{"e":"kline","E":1582279236617,"s":"BTCUSDT","k":{"t":1582279200000,"T":1582279259999,"s":"BTCUSDT","i":"1m","f":250357973,"L":250358219,"o":"9660.05000000","c":"9659.53000000","h":"9662.24000000","l":"9653.14000000","v":"18.37091100","n":247,"x":false,"q":"177397.77053790","V":"6.96397800","Q":"67251.25836292","B":"0"}}}', rsv1=False, rsv2=False, rsv3=False)
DEBUG:websockets.protocol:client < Frame(fin=True, opcode=1, data=b'{"stream":"btcusdt@kline_1m","data":{"e":"kline","E":1582279238994,"s":"BTCUSDT","k":{"t":1582279200000,"T":1582279259999,"s":"BTCUSDT","i":"1m","f":250357973,"L":250358226,"o":"9660.05000000","c":"9658.90000000","h":"9662.24000000","l":"9653.14000000","v":"18.86878300","n":254,"x":false,"q":"182206.64814554","V":"7.46185000","Q":"72060.13597056","B":"0"}}}', rsv1=False, rsv2=False, rsv3=False)
DEBUG:websockets.protocol:client < Frame(fin=True, opcode=1, data=b'{"stream":"btcusdt@kline_1m","data":{"e":"kline","E":1582279242013,"s":"BTCUSDT","k":{"t":1582279200000,"T":1582279259999,"s":"BTCUSDT","i":"1m","f":250357973,"L":250358229,"o":"9660.05000000","c":"9658.87000000","h":"9662.24000000","l":"9653.14000000","v":"18.89801100","n":257,"x":false,"q":"182488.95694014","V":"7.46185000","Q":"72060.13597056","B":"0"}}}', rsv1=False, rsv2=False, rsv3=False)
DEBUG:websockets.protocol:client < Frame(fin=True, opcode=1, data=b'{"stream":"btcusdt@kline_1m","data":{"e":"kline","E":1582279244090,"s":"BTCUSDT","k":{"t":1582279200000,"T":1582279259999,"s":"BTCUSDT","i":"1m","f":250357973,"L":250358233,"o":"9660.05000000","c":"9658.81000000","h":"9662.24000000","l":"9653.14000000","v":"19.25369200","n":261,"x":false,"q":"185924.43548993","V":"7.47001900","Q":"72139.03878945","B":"0"}}}', rsv1=False, rsv2=False, rsv3=False)
DEBUG:root:BinanceWebSocketApiManager->is_stop_request(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:root:BinanceWebSocketApiManager->set_heartbeat(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:root:BinanceWebSocketApiManager->is_stop_request(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:root:BinanceWebSocketApiManager->set_heartbeat(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:root:BinanceWebSocketApiManager->is_stop_request(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:root:BinanceWebSocketApiManager->set_heartbeat(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:root:BinanceWebSocketApiManager->is_stop_request(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:root:BinanceWebSocketApiManager->set_heartbeat(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:root:BinanceWebSocketApiManager->is_stop_request(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:root:BinanceWebSocketApiManager->set_heartbeat(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:root:BinanceWebSocketApiManager->is_stop_request(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)
DEBUG:root:BinanceWebSocketApiManager->set_heartbeat(91d8fc81-3ed1-40fb-b5f8-f5b57308a39b)

And after that it's working normally. Interesting thing is that the data doesn't seems to be lost, it looks like it's coming in a batch afterward but I have not verified it 100%.

Other scenario :

DEBUG:websockets.protocol:client < Frame(fin=True, opcode=1, data=b'{"stream":"btcusdt@kline_1m","data":{"e":"kline","E":1582279449867,"s":"BTCUSDT","k":{"t":1582279440000,"T":1582279499999,"s":"BTCUSDT","i":"1m","f":250359015,"L":250359050,"o":"9660.88000000","c":"9660.46000000","h":"9661.44000000","l":"9660.46000000","v":"5.26631100","n":36,"x":false,"q":"50876.23472509","V":"1.03570800","Q":"10005.97234818","B":"0"}}}', rsv1=False, rsv2=False, rsv3=False)
DEBUG:root:BinanceWebSocketApiManager->is_stop_request(6ccffad3-7011-4fe4-a33d-8cddcfe50e31)
DEBUG:root:BinanceWebSocketApiManager->set_heartbeat(6ccffad3-7011-4fe4-a33d-8cddcfe50e31)
THIS IS WHERE I DISCONNECTED
DEBUG:websockets.protocol:client > Frame(fin=True, opcode=9, data=b'^OC6', rsv1=False, rsv2=False, rsv3=False)
DEBUG:websockets.protocol:client ! timed out waiting for pong
DEBUG:websockets.protocol:client ! failing WebSocket connection in the OPEN state: 1011 [no reason]
DEBUG:websockets.protocol:client - state = CLOSING
DEBUG:websockets.protocol:client > Frame(fin=True, opcode=8, data=b'\x03\xf3', rsv1=False, rsv2=False, rsv3=False)
DEBUG:websockets.protocol:client ! timed out waiting for TCP close
DEBUG:websockets.protocol:client x closing TCP connection
DEBUG:websockets.protocol:client - event = connection_lost([SSL: KRB5_S_INIT] application data after close notify (_ssl.c:2629))
DEBUG:websockets.protocol:client - state = CLOSED
DEBUG:websockets.protocol:client x code = 1006, reason = [no reason]
DEBUG:websockets.protocol:client - aborted pending ping: 5e4f4336
CRITICAL:root:BinanceWebSocketApiSocket->start_socket(6ccffad3-7011-4fe4-a33d-8cddcfe50e31, ['kline_1m'], ['btcusdt']) Exception ConnectionClosed Info: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
CRITICAL:root:BinanceWebSocketApiManager->stream_is_crashing(6ccffad3-7011-4fe4-a33d-8cddcfe50e31)
Process finished with exit code 1

But this night (after around 10-12h of stream so less than the 24h mark), the same issue happened, without manual deconnexion :
a ping (opcode=9) sent with no pong, then stream crashing due to Exception ConnectionClosed. Im' not sure if it is because of my connexion not being stable.

Is it possible for the API manager or the Socket Manager to catch this exception and store somewhere that the stream needs to be restarted ? So i could program what to do in this case in my class LivePortfolio, because for me the big issue is that the program overall is crashing so everything stops.
Thank you for helping us about it.

[oliver-zehentleitner]

And after that it's working normally. Interesting thing is that the data doesn't seems to be lost, it looks like it's coming in a batch afterward but I have not verified it 100%.

You are right, if you turn off and on the wifi for a few seconds, the connection does not get closed and missing data gets flushed to you without a loss. Try turning wifi off for a minute, then it gets closed.

Actualy it should be doing it, but till now, we only had to catch this error on one place in the code. since 1.10.0 we also have to catch it in the send() method. i will provide an update for it! Thanks for reporting this!

The 24 h disconnect should be a CONNRESET not 1006 error msg.

[oliver-zehentleitner]

I just released a fixed version: https://github.com/oliver-zehentleitner/unicorn-binance-websocket-api/releases/latest

[oliver-zehentleitner]

Please close this if reconnect works proper now!

[oliver-zehentleitner]

My tests are positive, if you still have problems create a new issue or reopen this one!
Best regards!