Re-subscribe only one symbol in kline stream after 1006 error

kosmodromov commented 4 years ago

Check this or we will delete your issue. (fill in the checkbox with an X like so: [x])

[x] I have searched for other issues with the same problem or similar feature requests.

Select one:

[x] Bug
[ ] Feature Request
[ ] Technical Help
[ ] Other

Environment

[x] Are you using the module on a VPS or other Cloud hosting?
[ ] Are you using the module on a Raspberry Pi?

What kind of internet connection do you have?

Average system load (CPU)

Hardware specification

Operating System? (include version)

[ ] macOS
[ ] Windows
[x] Linux (CentOS 7)

Options

[x] stream_buffer
[ ] process_stream_data

Python Version Requirement

[x] I am using Python 3.6.1 or above

Exact Python Version?

Python 3.6.4

Pip Version?

pip 20.1.1

Dependencies

pip_list.txt

UNICORN Binance WebSocket API Version?

1.20.0

Description of your issue

Hi Oliver,

Today I found out that of all kline streams there is only one left subscribed. I subscribed on UserData, kline_15m for all pairs and aggTrade only for one pair. Log file is very noisy because of many disconnects, so here is the part which I found interesting. At the end, exactly egldusdt@kline_15m from kline streams left. If you need more input from me, please let me know.

Thank you.


2020-10-02 04:06:17,248 [INFO    ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->subscribe_to_stream(199503d3-2d3d-4143-bedc-a1fae046221d, ['kline_15m'], ['mkrusdt', 'enjusdt', 'srmusdt', 'xlmusdt', 'bnbusdt', 'atomusdt', 'thetausdt', 'ltcusdt', 'snxusdt', 'qtumusdt', 'hntusdt', 'kavausdt', 'rlcusdt', 'solusdt', 'xtzusdt', 'crvusdt', 'dotusdt', 'kncusdt', 'compusdt', 'blzusdt', 'dogeusdt', 'btcusdt', 'bchusdt', 'ethusdt', 'bandusdt', 'zrxusdt', 'runeusdt', 'xrpusdt', 'zecusdt', 'zilusdt', 'ontusdt', 'uniusdt', 'sxpusdt', 'linkusdt', 'eosusdt', 'iotausdt', 'ftmusdt', 'lendusdt', 'yfiiusdt', 'bzrxusdt', 'avaxusdt', 'xmrusdt', 'vetusdt', 'adausdt', 'yfiusdt', 'etcusdt', 'icxusdt', 'iostusdt', 'algousdt', 'sushiusdt', 'balusdt', 'dashusdt', 'storjusdt', 'trbusdt', 'flmusdt', 'neousdt', 'trxusdt', 'wavesusdt', 'omgusdt', 'batusdt', 'egldusdt']) finished ...
2020-10-02 04:06:17,248 [INFO    ] 9340 140392976590592 unicorn_binance_websocket_api_manager: Created websocket URI for stream_id=199503d3-2d3d-4143-bedc-a1fae046221d is wss://fstream.binance.com/stream?streams=egldusdt@kline_15m
2020-10-02 04:06:18,551 [DEBUG   ] 9340 140392976590592 protocol: client - state = CONNECTING
2020-10-02 04:06:19,379 [DEBUG   ] 9340 140393376753408 protocol: client ! timed out waiting for TCP close
2020-10-02 04:06:19,380 [DEBUG   ] 9340 140393376753408 protocol: client x aborting TCP connection
2020-10-02 04:06:19,380 [DEBUG   ] 9340 140393376753408 protocol: client - event = connection_lost(None)
2020-10-02 04:06:19,380 [DEBUG   ] 9340 140393376753408 protocol: client - state = CLOSED
2020-10-02 04:06:19,381 [DEBUG   ] 9340 140393376753408 protocol: client x code = 1006, reason = [no reason]
2020-10-02 04:06:19,381 [DEBUG   ] 9340 140393376753408 protocol: client - aborted pending ping: a977b44c

2020-10-02 04:06:05,901 [DEBUG   ] 9340 140392976590592 protocol: client - event = data_received(<317 bytes>)
2020-10-02 04:06:05,916 [DEBUG   ] 9340 140392976590592 protocol: client - event = data_received(<324 bytes>)
2020-10-02 04:06:05,970 [DEBUG   ] 9340 140392976590592 protocol: client - event = data_received(<326 bytes>)
2020-10-02 04:06:05,971 [DEBUG   ] 9340 140392976590592 protocol: client - event = data_received(<317 bytes>)
2020-10-02 04:06:06,037 [DEBUG   ] 9340 140392976590592 protocol: client - event = data_received(<316 bytes>)
2020-10-02 04:06:06,095 [DEBUG   ] 9340 140392976590592 protocol: client - event = data_received(<319 bytes>)
2020-10-02 04:06:06,098 [DEBUG   ] 9340 140392976590592 protocol: client - event = data_received(<326 bytes>)
2020-10-02 04:06:06,120 [DEBUG   ] 9340 140392976590592 protocol: client - event = data_received(<325 bytes>)
2020-10-02 04:06:06,173 [DEBUG   ] 9340 140392976590592 protocol: client - event = data_received(<314 bytes>)
2020-10-02 04:06:06,405 [DEBUG   ] 9340 140392976590592 protocol: client ! timed out waiting for TCP close
2020-10-02 04:06:06,405 [DEBUG   ] 9340 140392976590592 protocol: client x closing TCP connection
2020-10-02 04:06:09,376 [DEBUG   ] 9340 140393376753408 protocol: client ! timed out waiting for TCP close
2020-10-02 04:06:09,376 [DEBUG   ] 9340 140393376753408 protocol: client x closing TCP connection
2020-10-02 04:06:10,293 [DEBUG   ] 9340 140392993376000 protocol: client > Frame(fin=True, opcode=9, data=b'\xe5*\x93\x14', rsv1=False, rsv2=False, rsv3=False)
2020-10-02 04:06:14,163 [DEBUG   ] 9340 140392993376000 protocol: client - event = data_received(<6 bytes>)
2020-10-02 04:06:14,163 [DEBUG   ] 9340 140392993376000 protocol: client < Frame(fin=True, opcode=10, data=b'\xe5*\x93\x14', rsv1=False, rsv2=False, rsv3=False)
2020-10-02 04:06:14,163 [DEBUG   ] 9340 140392993376000 protocol: client - received solicited pong: e52a9314
2020-10-02 04:06:16,410 [DEBUG   ] 9340 140392976590592 protocol: client ! timed out waiting for TCP close
2020-10-02 04:06:16,410 [DEBUG   ] 9340 140392976590592 protocol: client x aborting TCP connection
2020-10-02 04:06:16,411 [DEBUG   ] 9340 140392976590592 protocol: client - event = connection_lost(None)
2020-10-02 04:06:16,411 [DEBUG   ] 9340 140392976590592 protocol: client - state = CLOSED
2020-10-02 04:06:16,411 [DEBUG   ] 9340 140392976590592 protocol: client x code = 1006, reason = [no reason]
2020-10-02 04:06:16,412 [DEBUG   ] 9340 140392976590592 protocol: client - aborted pending ping: dbd7907c
2020-10-02 04:06:16,412 [CRITICAL] 9340 140392976590592 unicorn_binance_websocket_api_socket: BinanceWebSocketApiSocket->start_socket(199503d3-2d3d-4143-bedc-a1fae046221d, ['kline_15m'], ['mkrusdt', 'enjusdt', 'srmusdt', 'xlmusdt', 'bnbusdt', 'atomusdt', 'thetausdt', 'ltcusdt', 'snxusdt', 'qtumusdt', 'hntusdt', 'kavausdt', 'rlcusdt', 'solusdt', 'xtzusdt', 'crvusdt', 'dotusdt', 'kncusdt', 'dogeusdt', 'blzusdt', 'compusdt', 'btcusdt', 'bchusdt', 'ethusdt', 'bandusdt', 'zrxusdt', 'runeusdt', 'xrpusdt', 'zecusdt', 'zilusdt', 'ontusdt', 'uniusdt', 'sxpusdt', 'linkusdt', 'eosusdt', 'iotausdt', 'ftmusdt', 'lendusdt', 'yfiiusdt', 'bzrxusdt', 'avaxusdt', 'xmrusdt', 'vetusdt', 'adausdt', 'yfiusdt', 'etcusdt', 'icxusdt', 'iostusdt', 'algousdt', 'sushiusdt', 'balusdt', 'dashusdt', 'storjusdt', 'trbusdt', 'flmusdt', 'neousdt', 'trxusdt', 'wavesusdt', 'omgusdt', 'batusdt', 'egldusdt']) Exception ConnectionClosed Info: code = 1006 (connection closed abnormally [internal]), no reason
2020-10-02 04:06:16,413 [CRITICAL] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->stream_is_crashing(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:17,242 [INFO    ] 9340 140393010161408 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->kill_stream(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:17,243 [INFO    ] 9340 140392984983296 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->_restart_stream(199503d3-2d3d-4143-bedc-a1fae046221d, ['kline_15m'], ['mkrusdt', 'enjusdt', 'srmusdt', 'xlmusdt', 'bnbusdt', 'atomusdt', 'thetausdt', 'ltcusdt', 'snxusdt', 'qtumusdt', 'hntusdt', 'kavausdt', 'rlcusdt', 'solusdt', 'xtzusdt', 'crvusdt', 'dotusdt', 'kncusdt', 'compusdt', 'blzusdt', 'dogeusdt', 'btcusdt', 'bchusdt', 'ethusdt', 'bandusdt', 'zrxusdt', 'runeusdt', 'xrpusdt', 'zecusdt', 'zilusdt', 'ontusdt', 'uniusdt', 'sxpusdt', 'linkusdt', 'eosusdt', 'iotausdt', 'ftmusdt', 'lendusdt', 'yfiiusdt', 'bzrxusdt', 'avaxusdt', 'xmrusdt', 'vetusdt', 'adausdt', 'yfiusdt', 'etcusdt', 'icxusdt', 'iostusdt', 'algousdt', 'sushiusdt', 'balusdt', 'dashusdt', 'storjusdt', 'trbusdt', 'flmusdt', 'neousdt', 'trxusdt', 'wavesusdt', 'omgusdt', 'batusdt', 'egldusdt'])
2020-10-02 04:06:17,243 [DEBUG   ] 9340 140392984983296 selector_events: Using selector: EpollSelector
2020-10-02 04:06:17,244 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->is_stop_request(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:17,245 [INFO    ] 9340 140392976590592 unicorn_binance_websocket_api_socket: BinanceWebSocketApiSocket->start_socket(199503d3-2d3d-4143-bedc-a1fae046221d, ['kline_15m'], ['mkrusdt', 'enjusdt', 'srmusdt', 'xlmusdt', 'bnbusdt', 'atomusdt', 'thetausdt', 'ltcusdt', 'snxusdt', 'qtumusdt', 'hntusdt', 'kavausdt', 'rlcusdt', 'solusdt', 'xtzusdt', 'crvusdt', 'dotusdt', 'kncusdt', 'compusdt', 'blzusdt', 'dogeusdt', 'btcusdt', 'bchusdt', 'ethusdt', 'bandusdt', 'zrxusdt', 'runeusdt', 'xrpusdt', 'zecusdt', 'zilusdt', 'ontusdt', 'uniusdt', 'sxpusdt', 'linkusdt', 'eosusdt', 'iotausdt', 'ftmusdt', 'lendusdt', 'yfiiusdt', 'bzrxusdt', 'avaxusdt', 'xmrusdt', 'vetusdt', 'adausdt', 'yfiusdt', 'etcusdt', 'icxusdt', 'iostusdt', 'algousdt', 'sushiusdt', 'balusdt', 'dashusdt', 'storjusdt', 'trbusdt', 'flmusdt', 'neousdt', 'trxusdt', 'wavesusdt', 'omgusdt', 'batusdt', 'egldusdt'])
2020-10-02 04:06:17,245 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->is_stop_request(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:17,246 [INFO    ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->subscribe_to_stream(199503d3-2d3d-4143-bedc-a1fae046221d, ['kline_15m'], ['mkrusdt', 'enjusdt', 'srmusdt', 'xlmusdt', 'bnbusdt', 'atomusdt', 'thetausdt', 'ltcusdt', 'snxusdt', 'qtumusdt', 'hntusdt', 'kavausdt', 'rlcusdt', 'solusdt', 'xtzusdt', 'crvusdt', 'dotusdt', 'kncusdt', 'compusdt', 'blzusdt', 'dogeusdt', 'btcusdt', 'bchusdt', 'ethusdt', 'bandusdt', 'zrxusdt', 'runeusdt', 'xrpusdt', 'zecusdt', 'zilusdt', 'ontusdt', 'uniusdt', 'sxpusdt', 'linkusdt', 'eosusdt', 'iotausdt', 'ftmusdt', 'lendusdt', 'yfiiusdt', 'bzrxusdt', 'avaxusdt', 'xmrusdt', 'vetusdt', 'adausdt', 'yfiusdt', 'etcusdt', 'icxusdt', 'iostusdt', 'algousdt', 'sushiusdt', 'balusdt', 'dashusdt', 'storjusdt', 'trbusdt', 'flmusdt', 'neousdt', 'trxusdt', 'wavesusdt', 'omgusdt', 'batusdt', 'egldusdt']) started ...
2020-10-02 04:06:17,247 [INFO    ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->create_payload(199503d3-2d3d-4143-bedc-a1fae046221d, ['kline_15m'], ['mkrusdt', 'enjusdt', 'srmusdt', 'xlmusdt', 'bnbusdt', 'atomusdt', 'thetausdt', 'ltcusdt', 'snxusdt', 'qtumusdt', 'hntusdt', 'kavausdt', 'rlcusdt', 'solusdt', 'xtzusdt', 'crvusdt', 'dotusdt', 'kncusdt', 'dogeusdt', 'blzusdt', 'compusdt', 'btcusdt', 'bchusdt', 'ethusdt', 'bandusdt', 'zrxusdt', 'runeusdt', 'xrpusdt', 'zecusdt', 'zilusdt', 'ontusdt', 'uniusdt', 'sxpusdt', 'linkusdt', 'eosusdt', 'iotausdt', 'ftmusdt', 'lendusdt', 'yfiiusdt', 'bzrxusdt', 'avaxusdt', 'xmrusdt', 'vetusdt', 'adausdt', 'yfiusdt', 'etcusdt', 'icxusdt', 'iostusdt', 'algousdt', 'sushiusdt', 'balusdt', 'dashusdt', 'storjusdt', 'trbusdt', 'flmusdt', 'neousdt', 'trxusdt', 'wavesusdt', 'omgusdt', 'batusdt', 'egldusdt']) started ...
2020-10-02 04:06:17,247 [INFO    ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->create_payload(199503d3-2d3d-4143-bedc-a1fae046221d, ['kline_15m'], ['mkrusdt', 'enjusdt', 'srmusdt', 'xlmusdt', 'bnbusdt', 'atomusdt', 'thetausdt', 'ltcusdt', 'snxusdt', 'qtumusdt', 'hntusdt', 'kavausdt', 'rlcusdt', 'solusdt', 'xtzusdt', 'crvusdt', 'dotusdt', 'kncusdt', 'dogeusdt', 'blzusdt', 'compusdt', 'btcusdt', 'bchusdt', 'ethusdt', 'bandusdt', 'zrxusdt', 'runeusdt', 'xrpusdt', 'zecusdt', 'zilusdt', 'ontusdt', 'uniusdt', 'sxpusdt', 'linkusdt', 'eosusdt', 'iotausdt', 'ftmusdt', 'lendusdt', 'yfiiusdt', 'bzrxusdt', 'avaxusdt', 'xmrusdt', 'vetusdt', 'adausdt', 'yfiusdt', 'etcusdt', 'icxusdt', 'iostusdt', 'algousdt', 'sushiusdt', 'balusdt', 'dashusdt', 'storjusdt', 'trbusdt', 'flmusdt', 'neousdt', 'trxusdt', 'wavesusdt', 'omgusdt', 'batusdt', 'egldusdt']) Payload: [{'method': 'SUBSCRIBE', 'params': ['xlmusdt@kline_15m', 'bchusdt@kline_15m', 'xrpusdt@kline_15m', 'avaxusdt@kline_15m', 'ontusdt@kline_15m', 'qtumusdt@kline_15m', 'egldusdt@kline_15m', 'atomusdt@kline_15m', 'etcusdt@kline_15m', 'enjusdt@kline_15m', 'balusdt@kline_15m', 'btcusdt@kline_15m', 'linkusdt@kline_15m', 'sushiusdt@kline_15m', 'iostusdt@kline_15m', 'eosusdt@kline_15m', 'dogeusdt@kline_15m', 'ftmusdt@kline_15m', 'lendusdt@kline_15m', 'trxusdt@kline_15m', 'dashusdt@kline_15m', 'zecusdt@kline_15m', 'sxpusdt@kline_15m', 'neousdt@kline_15m', 'hntusdt@kline_15m', 'rlcusdt@kline_15m', 'omgusdt@kline_15m', 'storjusdt@kline_15m', 'compusdt@kline_15m', 'batusdt@kline_15m', 'blzusdt@kline_15m', 'srmusdt@kline_15m', 'vetusdt@kline_15m', 'icxusdt@kline_15m', 'yfiiusdt@kline_15m', 'bandusdt@kline_15m', 'adausdt@kline_15m', 'kncusdt@kline_15m', 'zilusdt@kline_15m', 'algousdt@kline_15m', 'wavesusdt@kline_15m', 'ltcusdt@kline_15m', 'iotausdt@kline_15m', 'crvusdt@kline_15m', 'bnbusdt@kline_15m', 'mkrusdt@kline_15m', 'runeusdt@kline_15m', 'thetausdt@kline_15m', 'xmrusdt@kline_15m', 'solusdt@kline_15m', 'xtzusdt@kline_15m', 'zrxusdt@kline_15m', 'uniusdt@kline_15m', 'trbusdt@kline_15m', 'bzrxusdt@kline_15m', 'snxusdt@kline_15m', 'ethusdt@kline_15m', 'yfiusdt@kline_15m', 'dotusdt@kline_15m', 'kavausdt@kline_15m', 'flmusdt@kline_15m'], 'id': 6}]
2020-10-02 04:06:17,247 [INFO    ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->create_payload(199503d3-2d3d-4143-bedc-a1fae046221d, ['kline_15m'], ['mkrusdt', 'enjusdt', 'srmusdt', 'xlmusdt', 'bnbusdt', 'atomusdt', 'thetausdt', 'ltcusdt', 'snxusdt', 'qtumusdt', 'hntusdt', 'kavausdt', 'rlcusdt', 'solusdt', 'xtzusdt', 'crvusdt', 'dotusdt', 'kncusdt', 'dogeusdt', 'blzusdt', 'compusdt', 'btcusdt', 'bchusdt', 'ethusdt', 'bandusdt', 'zrxusdt', 'runeusdt', 'xrpusdt', 'zecusdt', 'zilusdt', 'ontusdt', 'uniusdt', 'sxpusdt', 'linkusdt', 'eosusdt', 'iotausdt', 'ftmusdt', 'lendusdt', 'yfiiusdt', 'bzrxusdt', 'avaxusdt', 'xmrusdt', 'vetusdt', 'adausdt', 'yfiusdt', 'etcusdt', 'icxusdt', 'iostusdt', 'algousdt', 'sushiusdt', 'balusdt', 'dashusdt', 'storjusdt', 'trbusdt', 'flmusdt', 'neousdt', 'trxusdt', 'wavesusdt', 'omgusdt', 'batusdt', 'egldusdt']) finished ...
2020-10-02 04:06:17,248 [INFO    ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->subscribe_to_stream(199503d3-2d3d-4143-bedc-a1fae046221d, ['kline_15m'], ['mkrusdt', 'enjusdt', 'srmusdt', 'xlmusdt', 'bnbusdt', 'atomusdt', 'thetausdt', 'ltcusdt', 'snxusdt', 'qtumusdt', 'hntusdt', 'kavausdt', 'rlcusdt', 'solusdt', 'xtzusdt', 'crvusdt', 'dotusdt', 'kncusdt', 'compusdt', 'blzusdt', 'dogeusdt', 'btcusdt', 'bchusdt', 'ethusdt', 'bandusdt', 'zrxusdt', 'runeusdt', 'xrpusdt', 'zecusdt', 'zilusdt', 'ontusdt', 'uniusdt', 'sxpusdt', 'linkusdt', 'eosusdt', 'iotausdt', 'ftmusdt', 'lendusdt', 'yfiiusdt', 'bzrxusdt', 'avaxusdt', 'xmrusdt', 'vetusdt', 'adausdt', 'yfiusdt', 'etcusdt', 'icxusdt', 'iostusdt', 'algousdt', 'sushiusdt', 'balusdt', 'dashusdt', 'storjusdt', 'trbusdt', 'flmusdt', 'neousdt', 'trxusdt', 'wavesusdt', 'omgusdt', 'batusdt', 'egldusdt']) finished ...
2020-10-02 04:06:17,248 [INFO    ] 9340 140392976590592 unicorn_binance_websocket_api_manager: Created websocket URI for stream_id=199503d3-2d3d-4143-bedc-a1fae046221d is wss://fstream.binance.com/stream?streams=egldusdt@kline_15m
2020-10-02 04:06:18,551 [DEBUG   ] 9340 140392976590592 protocol: client - state = CONNECTING
2020-10-02 04:06:19,379 [DEBUG   ] 9340 140393376753408 protocol: client ! timed out waiting for TCP close
2020-10-02 04:06:19,380 [DEBUG   ] 9340 140393376753408 protocol: client x aborting TCP connection
2020-10-02 04:06:19,380 [DEBUG   ] 9340 140393376753408 protocol: client - event = connection_lost(None)
2020-10-02 04:06:19,380 [DEBUG   ] 9340 140393376753408 protocol: client - state = CLOSED
2020-10-02 04:06:19,381 [DEBUG   ] 9340 140393376753408 protocol: client x code = 1006, reason = [no reason]
2020-10-02 04:06:19,381 [DEBUG   ] 9340 140393376753408 protocol: client - aborted pending ping: a977b44c
2020-10-02 04:06:19,381 [CRITICAL] 9340 140393376753408 unicorn_binance_websocket_api_socket: BinanceWebSocketApiSocket->start_socket(c606de72-5993-4e02-ba33-94497646268a, ['aggTrade'], ['btcusdt']) Exception ConnectionClosed Info: code = 1006 (connection closed abnormally [internal]), no reason
2020-10-02 04:06:19,382 [CRITICAL] 9340 140393376753408 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->stream_is_crashing(c606de72-5993-4e02-ba33-94497646268a)
2020-10-02 04:06:20,248 [INFO    ] 9340 140393010161408 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->kill_stream(c606de72-5993-4e02-ba33-94497646268a)
2020-10-02 04:06:20,250 [INFO    ] 9340 140393001768704 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->_restart_stream(c606de72-5993-4e02-ba33-94497646268a, ['aggTrade'], ['btcusdt'])
2020-10-02 04:06:20,251 [DEBUG   ] 9340 140393001768704 selector_events: Using selector: EpollSelector
2020-10-02 04:06:20,251 [DEBUG   ] 9340 140393376753408 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->is_stop_request(c606de72-5993-4e02-ba33-94497646268a)
2020-10-02 04:06:20,251 [INFO    ] 9340 140393376753408 unicorn_binance_websocket_api_socket: BinanceWebSocketApiSocket->start_socket(c606de72-5993-4e02-ba33-94497646268a, ['aggTrade'], ['btcusdt'])
2020-10-02 04:06:20,252 [DEBUG   ] 9340 140393376753408 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->is_stop_request(c606de72-5993-4e02-ba33-94497646268a)
2020-10-02 04:06:20,252 [INFO    ] 9340 140393376753408 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->subscribe_to_stream(c606de72-5993-4e02-ba33-94497646268a, ['aggTrade'], ['btcusdt']) started ...
2020-10-02 04:06:20,252 [INFO    ] 9340 140393376753408 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->create_payload(c606de72-5993-4e02-ba33-94497646268a, ['aggTrade'], ['btcusdt']) started ...
2020-10-02 04:06:20,252 [INFO    ] 9340 140393376753408 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->create_payload(c606de72-5993-4e02-ba33-94497646268a, ['aggTrade'], ['btcusdt']) Payload: [{'method': 'SUBSCRIBE', 'params': ['btcusdt@aggTrade'], 'id': 7}]
2020-10-02 04:06:20,252 [INFO    ] 9340 140393376753408 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->create_payload(c606de72-5993-4e02-ba33-94497646268a, ['aggTrade'], ['btcusdt']) finished ...
2020-10-02 04:06:20,252 [INFO    ] 9340 140393376753408 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->subscribe_to_stream(c606de72-5993-4e02-ba33-94497646268a, ['aggTrade'], ['btcusdt']) finished ...
2020-10-02 04:06:20,252 [INFO    ] 9340 140393376753408 unicorn_binance_websocket_api_manager: Created websocket URI for stream_id=c606de72-5993-4e02-ba33-94497646268a is wss://fstream.binance.com/stream?streams=btcusdt@aggTrade
2020-10-02 04:06:20,595 [DEBUG   ] 9340 140392976590592 protocol: client - event = connection_made(<asyncio.sslproto._SSLProtocolTransport object at 0x7fafe1f71320>)
2020-10-02 04:06:20,597 [DEBUG   ] 9340 140392976590592 client: client > GET /stream?streams=egldusdt@kline_15m HTTP/1.1
2020-10-02 04:06:20,597 [DEBUG   ] 9340 140392976590592 client: client > Headers([('Host', 'fstream.binance.com'), ('Upgrade', 'websocket'), ('Connection', 'Upgrade'), ('Sec-WebSocket-Key', 'pjetuiSav3JjAeiv584Xpw=='), ('Sec-WebSocket-Version', '13'), ('Sec-WebSocket-Extensions', 'permessage-deflate; client_max_window_bits'), ('User-Agent', 'oliver-zehentleitner/unicorn-binance-websocket-api/1.20.0')])
2020-10-02 04:06:20,884 [DEBUG   ] 9340 140392976590592 protocol: client - event = data_received(<166 bytes>)
2020-10-02 04:06:20,885 [DEBUG   ] 9340 140392976590592 client: client < HTTP/1.1 101 Switching Protocols
2020-10-02 04:06:20,885 [DEBUG   ] 9340 140392976590592 client: client < Headers([('Date', 'Fri, 02 Oct 2020 02:06:20 GMT'), ('Connection', 'upgrade'), ('upgrade', 'websocket'), ('sec-websocket-accept', 'cmdT23RSDHmgK6Z0AID1Gnpw9Lo=')])
2020-10-02 04:06:20,885 [DEBUG   ] 9340 140392976590592 protocol: client - state = OPEN
2020-10-02 04:06:20,886 [DEBUG   ] 9340 140392976590592 protocol: client > Frame(fin=True, opcode=1, data=b'{"method":"SUBSCRIBE","params":["xlmusdt@kline_15m","bchusdt@kline_15m","xrpusdt@kline_15m","avaxusdt@kline_15m","ontusdt@kline_15m","qtumusdt@kline_15m","egldusdt@kline_15m","atomusdt@kline_15m","etcusdt@kline_15m","enjusdt@kline_15m","balusdt@kline_15m","btcusdt@kline_15m","linkusdt@kline_15m","sushiusdt@kline_15m","iostusdt@kline_15m","eosusdt@kline_15m","dogeusdt@kline_15m","ftmusdt@kline_15m","lendusdt@kline_15m","trxusdt@kline_15m","dashusdt@kline_15m","zecusdt@kline_15m","sxpusdt@kline_15m","neousdt@kline_15m","hntusdt@kline_15m","rlcusdt@kline_15m","omgusdt@kline_15m","storjusdt@kline_15m","compusdt@kline_15m","batusdt@kline_15m","blzusdt@kline_15m","srmusdt@kline_15m","vetusdt@kline_15m","icxusdt@kline_15m","yfiiusdt@kline_15m","bandusdt@kline_15m","adausdt@kline_15m","kncusdt@kline_15m","zilusdt@kline_15m","algousdt@kline_15m","wavesusdt@kline_15m","ltcusdt@kline_15m","iotausdt@kline_15m","crvusdt@kline_15m","bnbusdt@kline_15m","mkrusdt@kline_15m","runeusdt@kline_15m","thetausdt@kline_15m","xmrusdt@kline_15m","solusdt@kline_15m","xtzusdt@kline_15m","zrxusdt@kline_15m","uniusdt@kline_15m","trbusdt@kline_15m","bzrxusdt@kline_15m","snxusdt@kline_15m","ethusdt@kline_15m","yfiusdt@kline_15m","dotusdt@kline_15m","kavausdt@kline_15m","flmusdt@kline_15m"],"id":6}', rsv1=False, rsv2=False, rsv3=False)
2020-10-02 04:06:20,887 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->set_heartbeat(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:20,887 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->is_stop_request(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:20,887 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->is_stop_as_crash_request(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:20,887 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->set_heartbeat(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:21,169 [DEBUG   ] 9340 140392976590592 protocol: client - event = data_received(<24 bytes>)
2020-10-02 04:06:21,170 [DEBUG   ] 9340 140392976590592 protocol: client < Frame(fin=True, opcode=1, data=b'{"id":6,"result":null}', rsv1=False, rsv2=False, rsv3=False)
2020-10-02 04:06:21,170 [INFO    ] 9340 140392976590592 unicorn_binance_websocket_api_socket: BinanceWebSocketApiSocket->start_socket(199503d3-2d3d-4143-bedc-a1fae046221d) Received result message: {"id":6,"result":null}
2020-10-02 04:06:21,170 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->is_stop_request(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:21,170 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->is_stop_as_crash_request(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:21,170 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->set_heartbeat(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:21,203 [DEBUG   ] 9340 140392976590592 protocol: client - event = data_received(<325 bytes>)
2020-10-02 04:06:21,203 [DEBUG   ] 9340 140392976590592 protocol: client < Frame(fin=True, opcode=1, data=b'{"stream":"linkusdt@kline_15m","data":{"e":"kline","E":1601604381072,"s":"LINKUSDT","k":{"t":1601604000000,"T":1601604899999,"s":"LINKUSDT","i":"15m","f":82543747,"L":82546051,"o":"9.552","c":"9.550","h":"9.589","l":"9.527","v":"94090.65","n":2305,"x":false,"q":"899459.69848","V":"52263.53","Q":"499977.19217","B":"0"}}}', rsv1=False, rsv2=False, rsv3=False)
2020-10-02 04:06:21,204 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->is_stop_request(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:21,204 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->is_stop_as_crash_request(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:21,204 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->set_heartbeat(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:21,222 [DEBUG   ] 9340 140392976590592 protocol: client - event = data_received(<336 bytes>)
2020-10-02 04:06:21,222 [DEBUG   ] 9340 140392976590592 protocol: client < Frame(fin=True, opcode=1, data=b'{"stream":"btcusdt@kline_15m","data":{"e":"kline","E":1601604381086,"s":"BTCUSDT","k":{"t":1601604000000,"T":1601604899999,"s":"BTCUSDT","i":"15m","f":219844530,"L":219846573,"o":"10586.90","c":"10587.36","h":"10604.38","l":"10581.66","v":"553.779","n":2044,"x":false,"q":"5866458.78089","V":"297.772","Q":"3154373.24892","B":"0"}}}', rsv1=False, rsv2=False, rsv3=False)
2020-10-02 04:06:21,222 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->is_stop_request(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:21,223 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->is_stop_as_crash_request(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:21,223 [DEBUG   ] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->set_heartbeat(199503d3-2d3d-4143-bedc-a1fae046221d)
2020-10-02 04:06:21,252 [DEBUG   ] 9340 140392976590592 protocol: client - event = data_received(<315 bytes>)

oliver-zehentleitner commented 4 years ago

Hello!

Do you think the stream has only one subscription in cause of that line: unicorn_binance_websocket_api_manager: Created websocket URI for stream_id=199503d3-2d3d-4143-bedc-a1fae046221d is wss://fstream.binance.com/stream?streams=egldusdt@kline_15m?

Please do cat your_log_file.log | grep 199503d3-2d3d-4143-bedc-a1fae046221d > stream.log and post me that file!

Thank you, Oliver

kosmodromov commented 4 years ago

Yes, I have notifications from my app that only EGLD was received from 4:15, so I thought that it could be related to this string.

ma_bot.log:2020-10-02 04:00:34,075 on_message():193 STORJ/USDT - kline received
ma_bot.log:2020-10-02 04:00:34,655 on_message():193 ALGO/USDT - kline received
ma_bot.log:2020-10-02 04:00:35,235 on_message():193 KNC/USDT - kline received
ma_bot.log:2020-10-02 04:00:35,870 on_message():193 COMP/USDT - kline received
ma_bot.log:2020-10-02 04:00:36,478 on_message():193 KAVA/USDT - kline received
ma_bot.log:2020-10-02 04:00:37,079 on_message():193 THETA/USDT - kline received
ma_bot.log:2020-10-02 04:00:37,987 on_message():193 BAL/USDT - kline received
ma_bot.log:2020-10-02 04:00:38,582 on_message():193 ETC/USDT - kline received
ma_bot.log:2020-10-02 04:00:39,232 on_message():193 DOGE/USDT - kline received
ma_bot.log:2020-10-02 04:00:39,813 on_message():193 RLC/USDT - kline received
ma_bot.log:2020-10-02 04:00:40,586 on_message():193 SRM/USDT - kline received
ma_bot.log:2020-10-02 04:00:41,168 on_message():193 ICX/USDT - kline received
ma_bot.log:2020-10-02 04:00:41,708 on_message():193 HNT/USDT - kline received
ma_bot.log:2020-10-02 04:00:43,265 on_message():193 ENJ/USDT - kline received
ma_bot.log:2020-10-02 04:00:43,797 on_message():193 FLM/USDT - kline received
ma_bot.log:2020-10-02 04:15:02,202 on_message():193 EGLD/USDT - kline received
ma_bot.log:2020-10-02 04:30:02,250 on_message():193 EGLD/USDT - kline received
ma_bot.log:2020-10-02 04:45:00,464 on_message():193 EGLD/USDT - kline received
ma_bot.log:2020-10-02 05:00:02,223 on_message():193 EGLD/USDT - kline received
ma_bot.log:2020-10-02 05:15:01,450 on_message():193 EGLD/USDT - kline received
ma_bot.log:2020-10-02 05:30:02,247 on_message():193 EGLD/USDT - kline received
ma_bot.log:2020-10-02 05:45:02,269 on_message():193 EGLD/USDT - kline received
ma_bot.log:2020-10-02 06:00:00,691 on_message():193 EGLD/USDT - kline received
ma_bot.log:2020-10-02 06:15:02,019 on_message():193 EGLD/USDT - kline received
ma_bot.log:2020-10-02 06:30:02,246 on_message():193 EGLD/USDT - kline received
ma_bot.log:2020-10-02 06:45:00,385 on_message():193 EGLD/USDT - kline received
ma_bot.log:2020-10-02 07:00:02,234 on_message():193 EGLD/USDT - kline received

Also I did grep over the log, there was a tons of similar messages, so I removed them by grep -vE "is_stop_request|is_stop_as_crash_request|set_heartbeat" stream.log > stream_log_filtered.log. I've attached both files.

stream.zip stream_log_filtered.log

oliver-zehentleitner commented 4 years ago

unicorn_binance_websocket_api_manager: Created websocket URI for stream_id=199503d3-2d3d-4143-bedc-a1fae046221d is wss://fstream.binance.com/stream?streams=egldusdt@kline_15m

The UBWA manager gets the job to start a stream with kline_15m and a lot of channels. There are two ways to subscribe. One via the websocket URI during a stream start. Here the limit was at ~8004 chars in the beginning when i started writing this lib. This year 2020 in february I recognized that the limit has gained to ~16000 chars. The other way is with websocket.send() - here is also a limit of ~16000 chars per payload (thats why we split subscriptions into packages with 350 subscriptions per payload), but its possible to repeat websocket send, so I was able to subscribe to all channels via one stream. It was over 20k subscriptions i think. Very soon binance announced the limit of 1024 subscriptions per stream.

Finally: The lib always adds one subscription to the websocket connection URI and subscribes all the rest via websocket.send(). So the string in you log file is correct and nothing to worry about.

Anyway, this is really a good trace! Because of the URI its sure that you have one subscription and it gets delivered (as shown in you log file "egld/usdt"), so the stream is working in general. But what seems to have failed are the websocket.send() subscriptions.

Thank you very much for the filtered log file :+1:

First the stream is crashing:`

2020-10-02 04:06:16,412 [CRITICAL] 9340 140392976590592 unicorn_binance_websocket_api_socket: BinanceWebSocketApiSocket->start_socket(199503d3-2d3d-4143-bedc-a1fae046221d, ['kline_15m'], ['mkrusdt', 'enjusdt', 'srmusdt', 'xlmusdt', 'bnbusdt', 'atomusdt', 'thetausdt', 'ltcusdt', 'snxusdt', 'qtumusdt', 'hntusdt', 'kavausdt', 'rlcusdt', 'solusdt', 'xtzusdt', 'crvusdt', 'dotusdt', 'kncusdt', 'dogeusdt', 'blzusdt', 'compusdt', 'btcusdt', 'bchusdt', 'ethusdt', 'bandusdt', 'zrxusdt', 'runeusdt', 'xrpusdt', 'zecusdt', 'zilusdt', 'ontusdt', 'uniusdt', 'sxpusdt', 'linkusdt', 'eosusdt', 'iotausdt', 'ftmusdt', 'lendusdt', 'yfiiusdt', 'bzrxusdt', 'avaxusdt', 'xmrusdt', 'vetusdt', 'adausdt', 'yfiusdt', 'etcusdt', 'icxusdt', 'iostusdt', 'algousdt', 'sushiusdt', 'balusdt', 'dashusdt', 'storjusdt', 'trbusdt', 'flmusdt', 'neousdt', 'trxusdt', 'wavesusdt', 'omgusdt', 'batusdt', 'egldusdt']) Exception ConnectionClosed Info: code = 1006 (connection closed abnormally [internal]), no reason`
2020-10-02 04:06:16,413 [CRITICAL] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->stream_is_crashing(199503d3-2d3d-4143-bedc-a1fae046221d)

One minute and 18 seconds later it happend again:

2020-10-02 04:07:34,223 [CRITICAL] 9340 140392976590592 unicorn_binance_websocket_api_socket: BinanceWebSocketApiSocket->start_socket(199503d3-2d3d-4143-bedc-a1fae046221d, ['kline_15m'], ['mkrusdt', 'enjusdt', 'srmusdt', 'xlmusdt', 'bnbusdt', 'atomusdt', 'thetausdt', 'ltcusdt', 'snxusdt', 'qtumusdt', 'hntusdt', 'kavausdt', 'rlcusdt', 'solusdt', 'xtzusdt', 'crvusdt', 'dotusdt', 'kncusdt', 'compusdt', 'blzusdt', 'dogeusdt', 'btcusdt', 'bchusdt', 'ethusdt', 'bandusdt', 'zrxusdt', 'runeusdt', 'xrpusdt', 'zecusdt', 'zilusdt', 'ontusdt', 'uniusdt', 'sxpusdt', 'linkusdt', 'eosusdt', 'iotausdt', 'ftmusdt', 'lendusdt', 'yfiiusdt', 'bzrxusdt', 'avaxusdt', 'xmrusdt', 'vetusdt', 'adausdt', 'yfiusdt', 'etcusdt', 'icxusdt', 'iostusdt', 'algousdt', 'sushiusdt', 'balusdt', 'dashusdt', 'storjusdt', 'trbusdt', 'flmusdt', 'neousdt', 'trxusdt', 'wavesusdt', 'omgusdt', 'batusdt', 'egldusdt']) Exception ConnectionClosed Info: code = 1006 (connection closed abnormally [internal]), no reason
2020-10-02 04:07:34,223 [CRITICAL] 9340 140392976590592 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager->stream_is_crashing(199503d3-2d3d-4143-bedc-a1fae046221d)

What makes me wonder, is that there is no log entry with "Sending payload:" which should happen as you can see here: https://github.com/oliver-zehentleitner/unicorn-binance-websocket-api/blob/da0dd92c8c839ceb76708d2f2a729971a82bcd2f/unicorn_binance_websocket_api/unicorn_binance_websocket_api_socket.py#L90

Did you remove this "sending payload" from the logfile?

Is the payload saved to self.stream_list[stream_id]['payload']? You can see this with ubwa.print_stream_info(stream_id).

If it is still there, why does it not get sent?

If it is not there, what happend to it?

In such a case its cool to be able to get an iPython shell in the script as explained here: https://github.com/oliver-zehentleitner/unicorn-binance-websocket-api/blob/master/example_interactive_mode.py iPython

Then you can do some research in the running system like doing ubwa.get_stream_subscriptions(stream_id) to proof that there is really only one subscription from the URI.

You can access ubwa.get_errors_from_endpoints() and print the last errors, the same function exists for results,

Please also try what happens if you do a ubwa.set_restart_request(stream_id) does it work again or not?

I will take a look into the code, maybe I find a hint...

Best regards, Oliver

oliver-zehentleitner commented 4 years ago

What is the value of self.stream_list[stream_id]['subscriptions']?

oliver-zehentleitner commented 4 years ago

I followed the code from create_stream() and one possible reason could be this: https://github.com/oliver-zehentleitner/unicorn-binance-websocket-api/blob/e14710fc44818f80823f4af7af733d8b24c3118f/unicorn_binance_websocket_api/unicorn_binance_websocket_api_connection.py#L143

Here is also code to send the payload but without logging it. This are the only 2 places where payloads are sent. So if there is no log, its very possible, the payload is send by this code part. I removed it and changed a little bit of logging - this should help to determine the root cause.

Please update to the dev version, but you have to remove/uninstall your current version before, then install with: pip install https://github.com/oliver-zehentleitner/unicorn-binance-websocket-api/tarball/master --upgrade

kosmodromov commented 4 years ago

Hi Oliver,

grep -i 'Sending payload' problematic_binance_ma_2.py.log didn't return any results...

I will try a dev version, but this happens not so often, so It might takes time to catch it up again.

Thank you.

oliver-zehentleitner commented 4 years ago

Hi Dmitry!

Thank you!

I know, testing some bugs and their fixes is very difficult because they happen not so often.

I hope the next time the log file helps a little bit more to find the root cause.

Best regards

oliver-zehentleitner commented 4 years ago

Its now also included in 1.22.0

I added more logging so maybe you want to switch to it...

oliver-zehentleitner commented 4 years ago

1.23.0 looks incredible stable to me in a stress test i did with a lot of manually initiated disconnects.

That way i was able to to find this bug which has lead to the behaviour you reported in this issue.

Since I fixed it, every single stream disconnects every time in my tests with all subscriptions.

I am not sure its exactly the same issue you found, but i think it would be good if you stop your current test run, upgrade and restart.

kosmodromov commented 4 years ago

Sounds awesome, Oliver! I've updated to 1.23.0, hope it will fix this problem.

Thank you!

oliver-zehentleitner commented 3 years ago

How is it going?

kosmodromov commented 3 years ago

Hi Oliver!

It seems very stable. I'm checking the logs time to time and even if there is the 1006 error it reconnects and continue to work.

Thank you!

oliver-zehentleitner commented 3 years ago

Then I am going to close this. If needed, feel free to reopen!

LUCIT-Systems-and-Development / unicorn-binance-websocket-api