search

Haehnchen / crypto-trading-bot

Cryptocurrency trading bot in javascript for Bitfinex, Bitmex, Binance, Bybit ... (public edition)
MIT License
3.09k stars 978 forks source link

Order gets executed multiple times since newest Commits #53

Open ghost opened 5 years ago

ghost commented 5 years ago

When executing an order I receive the following error since the newest commits:

UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'find' of undefined at ExchangeOrderWatchdogListener.onPositionChanged (c:\Users\Documents\Archive\ctb\modules\listener\exchange_order_watchdog_listener.js:80:36) at EventEmitter.eventEmitter.on (c:\Users\Documents\Archive\ctb\modules\trade.js:150:52) at EventEmitter.emit (events.js:198:13) at ExchangePositionWatcher.onPositionStateChangeTick (c:\Users\Documents\Archive\ctb\modules\exchange\exchange_position_watcher.js:48:35) warning.js:18 (node:9796) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 2) warning.js:18 (node:9796) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. warning.js:18

This causes one order being created multiple times on the exchange :-/ It seems to be related to the newest position handling update?

Haehnchen commented 5 years ago

yes, missed one empty check. its pushed.

ghost commented 5 years ago

Great, thanks for the fast response!! :) Much appreciated!

ghost commented 5 years ago

The above error is fixed with the newest commit. However, unfortunately the bot still created new orders sometimes even though the first order already has been filled. That then causes the bot to buy the 2x or 3x amount of what it actually should buy because multiple orders are created! I can see the "fills" on Bitmex happening within seconds from each other (market oders).

Is it maybe related to the possible issue that during the execution of the "OnSellBuyPair" method in the pair_state_execution class, the positions have not been updated yet to reflect the already executed buy/sell from a few seconds ago?

Here an example. It even goes back and forth buying and selling. The capital parameter is set to 50(!): image

mrseeker commented 5 years ago

The above error is fixed with the newest commit. However, unfortunately the bot still created new orders sometimes even though the first order already has been filled. That then causes the bot to buy the 2x or 3x amount of what it actually should buy because multiple orders are created! I can see the "fills" on Bitmex happening within seconds from each other (market oders).

Is it maybe related to the possible issue that during the execution of the "OnSellBuyPair" method in the pair_state_execution class, the positions have not been updated yet to reflect the already executed buy/sell from a few seconds ago?

Here an example. It even goes back and forth buying and selling. The capital parameter is set to 50(!): image

This might be related to #47

doftorul commented 5 years ago

This is related to https://github.com/Haehnchen/crypto-trading-bot/issues/47 in the sense that the bot can't access fast enough the order execution data. The behavior can be observed on bitmex and bybit both. For bybit.com the issue is the update every minute... There might not be much that can be done now with the current state of both exchanges API.

Haehnchen commented 5 years ago

@POCO10 how this orders got executed? did you press any button in the ui?

edit: maybe you can also give the log entries, that would be really helpful

ghost commented 5 years ago

These orders got executed by the bot itself. I did not press any buttons on the GUI. I tested it again this morning (no changes to software or strategy and the issue did not occur yet again. Attached you can find the log from the shown behavior from yesterday.

It is interesting that the second order always came in 10 seconds after the first one. So not with the new "strategy run" every 20 seconds, but earlier. Hope this helps! log.txt

Haehnchen commented 5 years ago

can you check if npm had apply the patch? https://github.com/Haehnchen/crypto-trading-bot/blob/master/patches/bitmex-realtime-api%2B0.4.0.patch

bitmex is having an issues getting positions update on the nodejs client. https://github.com/BitMEX/api-connectors/pull/285

i found https://github.com/bretton/api-connectors maybe i will switch to this because it also fixing some more issues. ;)

mrseeker commented 5 years ago

@Haehnchen Seems like npm applied your patch. I believe its more of an issue of a limit order getting instantly filled on execution, and when you check if it's in the order book it cannot be found. The bot then thinks the order failed, and retries the order. A similar pattern can be found when there is an instant reject due to "insufficient funds", the bot will keep reordering instead of failing. EDIT: It only seems to happen during volatile moments for me, when prices keep jumping up and down.

ghost commented 5 years ago

Yes, the patch should be in place. Is there a way that I could specifically check this?

ghost commented 5 years ago

@Haehnchen Seems like npm applied your patch. I believe its more of an issue of a limit order getting instantly filled on execution, and when you check if it's in the order book it cannot be found. The bot then thinks the order failed, and retries the order. A similar pattern can be found when there is an instant reject due to "insufficient funds", the bot will keep reordering instead of failing. EDIT: It only seems to happen during volatile moments for me, when prices keep jumping up and down.

For me it seems similar. I used market orders in the tests I executed. So also instant execution. It seems to me as well that the bot thinks, "I dont have a position, but I also dont have an order anymore, so lets create a new order then". However, in that moment the position is already created, the bot just doesnt know yet.

Haehnchen commented 5 years ago

did lots of improvements here today. still some edge cases left. especially on the exchange overloading times

ghost commented 5 years ago

Awesome! :) Thank you so much for sharing your work! Looking forward to the further future improvements!

ghost commented 5 years ago

One thing I have noticed recently, maybe this information is helpful. The following short log came from a short order process:

Pair State: Order directly filled clearing state: ["bitmex","XBTUSD"...]
Pair state cleared: {"state":"short"}
Bitmex: Invalid order created request cancel ordering:{"body":"{\"error\":{\"message\":\"Account has insufficient Available Balance, 2005503 XBt required\",\"name\":\"ValidationError\"}}"}
Order create canceled:{"id":XXX,"symbol":"XBTUSD","side":"short"}
Pair State: Signal canceled for invalid order: ["bitmex","XBTUSD"]
Position opened:["bitmex","XBTUSD"]

It seems to me in some situations the bot correctly notices that the order got directly filled, however it still tries to send in a second order (which was not successful in this case as the account balance was not high enough)?

Edit: By the way this happened the first time now after some tries. So it seems to happen only occasionally.

ghost commented 5 years ago

Here another example of the above behavior:

The bot actually notices in time that the order filled, however it seems it has the second order from the retries already queued up.

`Bitmex 2, [15.07.19 11:57] [short (XXX)] bitmex:XBTUSD - 10352

Bitmex 2, [15.07.19 11:57] 2019-07-15T09:57:52.040Z short XXX bitmex XBTUSD 10352

Bitmex 2, [15.07.19 11:57] Pair state changed: {"new":{"state":"short","options":{"period":"1h"},"time":"2019-07-15T09:57:52.047Z","symbol":"XBTUSD","exchange":"bitmex"},"old":{}}

Bitmex 2, [15.07.19 11:58] Pair State: Create position open order: ["bitmex","XBTUSD","short",{"period":"1h"}]

Bitmex 2, [15.07.19 11:58] Bitmex: Wallet Balance fetched

Bitmex 2, [15.07.19 11:58] Bitmex: Leverage update:"XBTUSD"

Bitmex 2, [15.07.19 11:58] Bitmex: Order created:{"body":"{\"orderID\":\"7baaf25a

Bitmex 2, [15.07.19 11:58] OrderAdjust: No price update needed:["7baaf25a

Bitmex 2, [15.07.19 11:58] Order created: ["7baaf25a

Bitmex 2, [15.07.19 11:58] Pair State: Create position open order: ["bitmex","XBTUSD","short",{"period":"1h"}]

Bitmex 2, [15.07.19 11:58] Bitmex: Order created:{"body":"{\"orderID\":\"b24aa8e0

Bitmex 2, [15.07.19 11:58] Order not placed force retry: {"id":"b24aa8e0

Bitmex 2, [15.07.19 11:58] Retry (1) creating order: {"id":48573

Bitmex 2, [15.07.19 11:58] Bitmex: Order created:{"body":"{\"orderID\":\"a2c2134a

Bitmex 2, [15.07.19 11:58] Order not placed force retry: {"id":"a2c2134a

Bitmex 2, [15.07.19 11:58] Retry (2) creating order: {"id":10911

Bitmex 2, [15.07.19 11:58] Bitmex: Order created:{"body":"{\"orderID\":\"ac83a30c

Bitmex 2, [15.07.19 11:58] Order not placed force retry: {"id":"ac83a30c

Bitmex 2, [15.07.19 11:58] Retry (3) creating order: {"id":1445

Bitmex 2, [15.07.19 11:58] Bitmex: Order created:{"body":"{\"orderID\":\"5d85a6aa

Bitmex 2, [15.07.19 11:58] Order not placed force retry: {"id":"5d85a6aa

Bitmex 2, [15.07.19 11:58] Retry (4) creating order: {"id":40907

Bitmex 2, [15.07.19 11:58] Bitmex: Order created:{"body":"{\"orderID\":\"fcec713a

Bitmex 2, [15.07.19 11:58] Order created: ["fcec713a

Bitmex 2, [15.07.19 11:58] OrderAdjust: managed order does not exists maybe filled; cleanup: ["7baaf25a

HERE THE BOT SHOULD STOP? ORDER HAS BEEN FILLED.

Bitmex 2, [15.07.19 11:58] OrderAdjust: No price update needed:["fcec713a

Bitmex 2, [15.07.19 11:58] Pair state cleared: {"state":"short","options":{"period":"1h"},"time":"2019-07-15T09:57:52.047Z","symbol":"XBTUSD","exchange":"bitmex"}

Bitmex 2, [15.07.19 11:58] block short order; open position:["bitmex","XBTUSD"]

Bitmex 2, [15.07.19 11:58] OrderAdjust: No price update needed:["fcec713a

Bitmex 2, [15.07.19 11:58] Position opened:["bitmex","XBTUSD"

Bitmex 2, [15.07.19 11:58] Bitmex: Order updated:{"body":"{\"orderID\":\"fcec713a

Bitmex 2, [15.07.19 11:58] OrderAdjust: Order adjusted with orderbook price: ["fcec713a

Bitmex 2, [15.07.19 11:58] Bitmex: Order updated:{"body":"{\"orderID\":\"fcec713a

Bitmex 2, [15.07.19 11:58] OrderAdjust: Order adjusted with orderbook price: ["fcec713a

Bitmex 2, [15.07.19 11:58] Bitmex: Order updated:{"body":"{\"orderID\":\"fcec713a

Bitmex 2, [15.07.19 11:58] OrderAdjust: Order adjusted with orderbook price: ["fcec713a

Bitmex 2, [15.07.19 11:59] OrderAdjust: No price update needed:["fcec713a

HERE I DELETED THE 2nd ORDER MANUALLY BEFORE IT FILLED.`

ghost commented 5 years ago

Per what I see at the moment this was related to my hardware not being powerful enough (raspi). Closing for the time being.

mrseeker commented 5 years ago

Per what I see at the moment this was related to my hardware not being powerful enough (raspi). Closing for the time being.

If this is the cause of the issue, then explain why my VPS with 8 cores is having the same issue?

ghost commented 5 years ago

Hm okay? Reopening. You are using the most recent commits? I wasnt able to see this exact issue anymore (had it running a few hours only though).