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

A Python SDK by LUCIT to use the Binance Websocket API`s (com+testnet, com-margin+testnet, com-isolated_margin+testnet, com-futures+testnet, com-coin_futures, us, tr, dex/chain+testnet) in a simple, fast, flexible, robust and fully-featured way.
https://unicorn-binance-websocket-api.docs.lucit.tech/
Other
678 stars 166 forks source link

How to trap `Exception ConnectionClosed` errors? #211

Closed OneArb closed 2 years ago

OneArb commented 2 years ago

Could you please provide some guidance on how to recover from

CRITICAL:root:BinanceWebSocketApiSocket.start_socket(6803db6a-2255-4e73-9132-0bb8d38633ff, ['trade'], ['fttusdt']) - Exception ConnectionClosed - error_msg: sent 1011 (unexpected error) keepalive ping timeout; no close frame received

I am using a two physical core laptop, python 3.9, unicorn 1.34.2, trading on two exchanges, streaming some web charts and I get after some time:

WARNING:root:BinanceWebSocketApiManager._frequent_checks() - High CPU usage since 5 seconds: 100.0

Until I upgrade, I'd like to attempt recovering critical streams. I monitor price levels, lost data is acceptable.

I have added

logging.basicConfig(level=logging.INFO, filename=os.path.basename(__file__) + '.log', format="{asctime} [{levelname:8}] {process} {thread} {module}: {message}", style="{")

before

binance_websocket_api_manager = BinanceWebSocketApiManager(exchange='binance.com', output_default='UnicornFy')

but I do not see any log file.

How do I trap Exception ConnectionClosed errors so I can attempt a set_restart_request(stream_id)?

Is it worth the effort since the lib already attempted the recovery?

Some streams, usually the ones receiving the most packets stay alive, which leads me to think I could resume or start a (new) stream.

I try to minimize processing:

oliver-zehentleitner commented 2 years ago

The philosophy of this library is that it takes care of reconnects itself.

It would help me a lot if you post your logfile and python version.

You are using the stream_buffer right?

How many entries of this kind do you have? WARNING:root:BinanceWebSocketApiManager._frequent_checks() - High CPU usage since 5 seconds: 100.0

Important to understand is that Python uses only about the power of one CPU core, no matter how many cores you have!

If your script/program constantly gets too little system performance, the backlog of incoming websocket data will grow and eventually the websocket connection will be terminated.

OneArb commented 2 years ago

I managed to get logs:

    logging.basicConfig(level=logging.DEBUG,
                        filename=os.path.basename(__file__) + '.log',
                        format="{asctime} [{levelname:8}] {process} {thread} {module}: {message}",
                        force=True,
                        style="{")

force=True is needed on my setup to actually produce the log.

It would help me a lot if you post your logfile and python version.

Python 3.9.7 pip 21.2.4 from /home//.local/lib/pypy3.7/site-packages/pip (python 3.7)

I posted a log containing about 20 unicorn_binance_websocket_api_manager: BinanceWebSocketApiManager._frequent_checks() - High CPU usage since 5 seconds messages for a 2 minutes session.

You are using the stream_buffer right?

sl = Sd.binance_websocket_api_manager.pop_stream_data_from_stream_buffer(stream_id)

Important to understand is that Python uses only about the power of one CPU core, no matter how many cores you have!

Yes, my baseline CPU for unicorn app processes is 40-60% with 12 symbols.

If your script/program constantly gets too little system performance, the backlog of incoming websocket data will grow and eventually the websocket connection will be terminated.

That circumstance is expected to occur regardless of machine specs. The day the market hits a black swan, one could hope the machine running the script will outpace Binance endpoints ability to output packets.

Live traders and bot operators can gain an edge by engineering to receive most up-to-date quotes, regardless of market volatility.

The philosophy of this library is that it takes care of reconnects itself.

Would an option clearing the websocket buffer before stream(s) reach(es) failure within the scope of that philosophy?

oliver-zehentleitner commented 2 years ago

Thanks for the data!

50% of 2 cores is 1 core...

What you can try to do is working with sub processes, this works around the GIL problem. But receiving alone for just one channel (trade) and 12 symbols should not be a problem. More important is, what are you doing with the data?

I recommend streaming the data with just one stream for all symbols instead of one stream for each symbol. This will save you some CPU power and is faster.

Also using servers with dedicated CPUs (not shared) is helping.

i dont know what you do exactly, but using aggTrade instead of trade will also reduce the incoming data records but provides the same information. And 'kline_1m` is useable for reducing incoming records and provides the last price.

There is already a method to clean the stream_buffer: clear_stream_buffer()

You can also gain speed and save resources if you use the stream_buffer as a LIFO stack and use stream_buffer_maxlen parameter! https://github.com/oliver-zehentleitner/unicorn-binance-websocket-api/wiki/%60stream_buffer%60

But a switch like clear_stream_buffer_after_reconnect=True can make sense i think.

oliver-zehentleitner commented 2 years ago

The ConnectionClosed is not included in the logfile... this would help me to add a fix

OneArb commented 2 years ago

Uploaded two new log files.

OneArb commented 2 years ago

Thanks for the tips.

I time delta between trade time and receive time, usually between 130 and 160ms.

At this point, I do not see any lag difference streaming one symbol vs. 12 symbols.

I tested with close to 100% load using an online CPU stress test. It generates many High CPU usage messages and only increases lag by about 30ms at worst while running two instances of the application.

I do use clear_stream_buffer after processing the first quote.

I use LIFO and filter subsequent quotes, if event_time > event_time_previous as clear_stream_buffer does not seem to have an immediate effect.

I set stream_buffer_maxlen = 0, not sure what maxlen unit is.

I process at most 300 new quotes per minute.

The use case for my application is getting the latest trade price with the least lag possible. Foremost for bot trading is stream stability.

I trade limit and need the real time order book stream, which I am yet to locate in the unicorn API.

Is it part of the coding club, the link is 404?

I realize I could determine how stale a stream is and replace_stream. Is the lib not already attempting so?

oliver-zehentleitner commented 2 years ago

I am able to reconstruct sent 1011 (unexpected error) keepalive ping timeout; no close frame received and will release a fix soon.

oliver-zehentleitner commented 2 years ago

Interesting!

stream_buffer_maxlen = 0 makes no sense!

its the max length of the stream_ buffer... if set to 3 the stack will not store more than 3 items in the buffer...

Yeah, it should become part of coding club but isnt done yet!

What channel type do you use to get the last price?

OneArb commented 2 years ago

stream_buffer_maxlen = 0 makes no sense!

I was also surprised that setting let, not only one quote but several quotes through, using either trade or aggTrade

                event_time = sl.get('event_time')

                # test code - quote per block
                if event_time == event_time_previous:
                        same_time += 1
                        symb = sl.get('symbol')
                        print(symb ,'multiple time', same_time)

                # process last quote only
                if event_time > event_time_previous:

                    same_time = 0  # test code - quote per block
                    event_time_previous = event_time

I was tabulating the number of quote received per packet, for a single symbol per stream, expecting the stream to stop - it did not.

On a side note, issuing binance_websocket_api_manager.clear_stream_buffer() right after the first quote is read, also lets several quotes per stream go through as well.

Would clearing the stream buffer happen through another thread which would introduce some lag in the clearing?

OneArb commented 2 years ago

I am able to reconstruct sent 1011 (unexpected error) keepalive ping timeout; no close frame received and will release a fix soon.

I am looking forwards to testing the fix!

45by90 commented 2 years ago

Hello,

Strangely, I've used this EXCELLENT library for over a month now, and just today this started happened. I think, although not sure, that recently I updated my pip/python.

Best,

John

OneArb commented 2 years ago

updated my pip/python

From which version?

oliver-zehentleitner commented 2 years ago

I analyzed the logfiles and only the b version is cointaining this 1011 error:

oliver@prestige:~/Downloads$ cat NGFQ014-03-b-exception-3.py.log | grep " 1011 "
2021-10-22 00:26:17,413 [DEBUG   ] 1492658 140488036312640 protocol: > CLOSE 1011 (unexpected error) keepalive ping timeout [24 bytes]
2021-10-22 00:26:22,978 [DEBUG   ] 1492658 140488539612736 protocol: > CLOSE 1011 (unexpected error) keepalive ping timeout [24 bytes]
2021-10-22 00:26:24,705 [DEBUG   ] 1492658 140488815715904 protocol: > CLOSE 1011 (unexpected error) keepalive ping timeout [24 bytes]
2021-10-22 00:26:37,436 [CRITICAL] 1492658 140488036312640 unicorn_binance_websocket_api_socket: BinanceWebSocketApiSocket.start_socket(f4518fa7-2aa2-4b85-acbe-371261371135, ['trade'], ['btcusdt']) - Exception ConnectionClosed - error_msg: sent 1011 (unexpected error) keepalive ping timeout; no close frame received
2021-10-22 00:26:43,003 [CRITICAL] 1492658 140488539612736 unicorn_binance_websocket_api_socket: BinanceWebSocketApiSocket.start_socket(9002225d-21ce-4ee5-acdc-984d992f334e, ['trade'], ['bnbusdt']) - Exception ConnectionClosed - error_msg: sent 1011 (unexpected error) keepalive ping timeout; no close frame received
2021-10-22 00:26:44,724 [CRITICAL] 1492658 140488815715904 unicorn_binance_websocket_api_socket: BinanceWebSocketApiSocket.start_socket(504d21bd-b372-4d79-b640-615df547406e, ['trade'], ['dogeusdt']) - Exception ConnectionClosed - error_msg: sent 1011 (unexpected error) keepalive ping timeout; no close frame received

As you can see, they all happend at the same time on 3 different streams... and they all recoverd!!

An expection handling is already implemented....

oliver-zehentleitner commented 2 years ago

If someone experience this without a restart please open a new issue with detailed information, thanks