search

askmike / gekko

A bitcoin trading bot written in node - https://gekko.wizb.it/
MIT License
10.08k stars 3.93k forks source link

Fatal Error insufficient balance (Binance API) #2405

Closed cuthulino closed 6 years ago

cuthulino commented 6 years ago

Note: this is the technical bug tracker, please use other platforms for getting support and starting a (non technical) discussion. See the getting help page for details.

I'm submitting a ... [ X] bug report [ ] question about the decisions made in the repository

Action taken (what you did) Gekko got advise to go long. This Error appered:

2018-08-03T00:45:31.575Z '[sticky order] FATAL ERROR' 'Error -2010: Account has insufficient balance for requested action.' 2018-08-03T00:45:31.579Z Error: Error -2010: Account has insufficient balance for requested action. at /home/cthulhu/gekko/exchange/wrappers/binance.js:78:15 at Request.request [as _callback] (/home/cthulhu/gekko/exchange/node_modules/binance/lib/rest.js:90:25) at Request.self.callback (/home/cthulhu/gekko/exchange/node_modules/request/request.js:185:22) at emitTwo (events.js:126:13) at Request.emit (events.js:214:7) at Request. (/home/cthulhu/gekko/exchange/node_modules/request/request.js:1157:10) at emitOne (events.js:116:13) at Request.emit (events.js:211:7) at IncomingMessage. (/home/cthulhu/gekko/exchange/node_modules/request/request.js:1079:12) at Object.onceWrapper (events.js:313:30)

Gekko kept running and bougth the Coin.

Reported balance on Gekko startup: 0.12009614 Original balance in Profit Report after sell: 0.11931790 ( Me nor Gekko did any trades in the time bevor the advice arrived)

I do not know where this difference comes from.

Expected result (what you hoped would happen) Maybe gekko should check the actual available balance bevor placing a trade?

askmike commented 6 years ago

Are you able to provide more logs?

Maybe gekko should check the actual available balance bevor placing a trade?

It checks this every few minutes already.

cuthulino commented 6 years ago

I had debugging set to off. So this is everything i got.

Orders were executed right. But binance api answered insufficient balance.

Will have to check on next trade whats up. I restartet the process and now i have to wait for the next buy signal.

cstegmann commented 6 years ago

I got the same thing. After the error the strategy failed to provide Debug updates like it usually does and just kept processing trades.

2018-08-07 23:34:06 (DEBUG): StopLoss Triggered: 1 2018-08-07 23:34:06 (DEBUG): Last buy price: 0.12954 Last high price: 0.12987 2018-08-07 23:34:06 (DEBUG): Current Price: 0.12292 Actual percent changed from buy: -5.110390612938079 2018-08-07 23:34:06 (DEBUG): Current market: bear Percent change predicted: 0.9955918861074834 Current price: 0.12292 Last buy price: 0.12954 Current position: long 2018-08-07 23:34:06 (INFO): Trader Received advice to go short. Selling ADA 2018-08-07 23:34:06 (DEBUG): Creating order to sell 15100.0065 ADA 2018-08-07 23:34:11 (DEBUG): syncing private data 2018-08-07 23:34:12 (DEBUG): [ORDER] statusChange: SUBMITTED 2018-08-07 23:34:12 (DEBUG): [ORDER] statusChange: OPEN 2018-08-07 23:34:14 (DEBUG): [ORDER] statusChange: MOVING 2018-08-07 23:34:14 (DEBUG): [ORDER] statusChange: OPEN 2018-08-07 23:34:15 (DEBUG): Requested ADA/USDT trade data from Binance ... 2018-08-07 23:34:15 (DEBUG): Processing 2 new trades. From 2018-08-07 21:34:09 UTC to 2018-08-07 21:34:14 UTC. (a few seconds) 2018-08-07 23:34:16 (DEBUG): [ORDER] statusChange: MOVING 2018-08-07 23:34:17 (DEBUG): [ORDER] statusChange: OPEN 2018-08-07 23:34:20 (DEBUG): [ORDER] statusChange: MOVING 2018-08-07T21:34:21.463Z '[sticky order] FATAL ERROR' 'Error -2010: Account has insufficient balance for requested action.' 2018-08-07T21:34:21.463Z Error: Error -2010: Account has insufficient balance for requested action. at /home/chris/gekko-neural-USDTpair/exchange/wrappers/binance.js:74:15 at Request.request [as _callback] (/home/chris/gekko-neural-USDTpair/exchange/node_modules/binance/lib/rest.js:90:25) at Request.self.callback (/home/chris/gekko-neural-USDTpair/exchange/node_modules/request/request.js:185:22) at emitTwo (events.js:126:13) at Request.emit (events.js:214:7) at Request. (/home/chris/gekko-neural-USDTpair/exchange/node_modules/request/request.js:1157:10) at emitOne (events.js:116:13) at Request.emit (events.js:211:7) at IncomingMessage. (/home/chris/gekko-neural-USDTpair/exchange/node_modules/request/request.js:1079:12) at Object.onceWrapper (events.js:313:30) at emitNone (events.js:111:20) at IncomingMessage.emit (events.js:208:7) at endReadableNT (_stream_readable.js:1064:12) at args.(anonymous function) (/usr/lib/node_modules/pm2/node_modules/event-loop-inspector/index.js:133:29) at _combinedTickCallback (internal/process/next_tick.js:138:11) at process._tickDomainCallback (internal/process/next_tick.js:218:9) 2018-08-07 23:34:21 (DEBUG): [ORDER] statusChange: ERROR 2018-08-07 23:34:21 (DEBUG): Error: Error -2010: Account has insufficient balance for requested action. at /home/chris/gekko-neural-USDTpair/exchange/wrappers/binance.js:74:15 at Request.request [as _callback] (/home/chris/gekko-neural-USDTpair/exchange/node_modules/binance/lib/rest.js:90:25) at Request.self.callback (/home/chris/gekko-neural-USDTpair/exchange/node_modules/request/request.js:185:22) at emitTwo (events.js:126:13) at Request.emit (events.js:214:7) at Request. (/home/chris/gekko-neural-USDTpair/exchange/node_modules/request/request.js:1157:10) at emitOne (events.js:116:13) at Request.emit (events.js:211:7) at IncomingMessage. (/home/chris/gekko-neural-USDTpair/exchange/node_modules/request/request.js:1079:12) at Object.onceWrapper (events.js:313:30) at emitNone (events.js:111:20) at IncomingMessage.emit (events.js:208:7) at endReadableNT (_stream_readable.js:1064:12) at args.(anonymous function) (/usr/lib/node_modules/pm2/node_modules/event-loop-inspector/index.js:133:29) at _combinedTickCallback (internal/process/next_tick.js:138:11) at process._tickDomainCallback (internal/process/next_tick.js:218:9) 2018-08-07 23:34:25 (DEBUG): Requested ADA/USDT trade data from Binance ...

I did change the amount to sell in trader.js to 100%, basically removed the ' * 0.95 ' because I didn't like that, guess that might have messed with things but it shouldn't really if the portfolio asset balance is kept current.

EDIT: I'm on commit 61a5cf9f3a81ca86e3c618c42da984fcd2c2943e (HEAD -> stable, origin/stable) Merge: 0a47199 310afe9 Might change to develop.

askmike commented 6 years ago

@cstegmann

I did change the amount to sell in trader.js to 100%, basically removed the ' * 0.95 ' because I didn't like that, guess that might have messed with things but it shouldn't really if the portfolio asset balance is kept current.

You can't buy with 100% since gekko converts this into an amount (asset). If the price moves 1 satoshi that amount is too much: amount * price > 100%. That is likely the cause of why you are seeing this.

@cuthulino cool let me know when it does :)

cstegmann commented 6 years ago

@askmike I didn't change the buy from 0.95, only the sell amount. I have changed to the develop branch and haven't had any problems since, even when having the sell at 100%.

cstegmann commented 6 years ago

@askmike Ok, it just happened to me on a buy this time. I didn't change amount = this.portfolio.currency / this.price * 0.95; in trader.js

2018-08-10 21:47:02 (INFO): Trader Received advice to go long. Buying XLM isValidLot 0.01 true 2018-08-10 21:47:02 (DEBUG): Creating order to buy 8121.06190620155 XLM 2018-08-10 21:47:08 (DEBUG): [ORDER] statusChange: SUBMITTED isValidLot 0.01 true 2018-08-10 21:47:08 (DEBUG): [ORDER] statusChange: OPEN 2018-08-10 21:47:11 (DEBUG): Requested XLM/ETH trade data from Binance ... 2018-08-10 21:47:12 (DEBUG): Processing 8 new trades. From 2018-08-10 19:47:02 UTC to 2018-08-10 19:47:10 UTC. (a few seconds) 2018-08-10 21:47:19 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.01 true 2018-08-10 21:47:20 (DEBUG): [ORDER] statusChange: OPEN 2018-08-10 21:47:21 (DEBUG): Requested XLM/ETH trade data from Binance ... 2018-08-10 21:47:22 (DEBUG): [ORDER] statusChange: MOVING 2018-08-10 21:47:23 (DEBUG): Processing 9 new trades. From 2018-08-10 19:47:12 UTC to 2018-08-10 19:47:21 UTC. (a few seconds) isValidLot 0.01 true 2018-08-10T19:47:23.497Z '[sticky order] FATAL ERROR' 'Error -2010: Account has insufficient balance for requested action.' 2018-08-10T19:47:23.497Z Error: Error -2010: Account has insufficient balance for requested action. at /home/chris/gekko-neural-ETHpair/exchange/wrappers/binance.js:94:15 at Request.request [as _callback] (/home/chris/gekko-neural-ETHpair/exchange/node_modules/binance/lib/rest.js:90:25) at Request.self.callback (/home/chris/gekko-neural-ETHpair/exchange/node_modules/request/request.js:185:22) at emitTwo (events.js:126:13) at Request.emit (events.js:214:7) at Request. (/home/chris/gekko-neural-ETHpair/exchange/node_modules/request/request.js:1157:10) at emitOne (events.js:116:13) at Request.emit (events.js:211:7) at IncomingMessage. (/home/chris/gekko-neural-ETHpair/exchange/node_modules/request/request.js:1079:12) at Object.onceWrapper (events.js:313:30) at emitNone (events.js:111:20) at IncomingMessage.emit (events.js:208:7) at endReadableNT (_stream_readable.js:1064:12) at args.(anonymous function) (/usr/lib/node_modules/pm2/node_modules/event-loop-inspector/index.js:133:29) at _combinedTickCallback (internal/process/next_tick.js:138:11) at process._tickDomainCallback (internal/process/next_tick.js:218:9) 2018-08-10 21:47:23 (DEBUG): [ORDER] statusChange: ERROR 2018-08-10 21:47:23 (DEBUG): Error: Error -2010: Account has insufficient balance for requested action. at /home/chris/gekko-neural-ETHpair/exchange/wrappers/binance.js:94:15 at Request.request [as _callback] (/home/chris/gekko-neural-ETHpair/exchange/node_modules/binance/lib/rest.js:90:25) at Request.self.callback (/home/chris/gekko-neural-ETHpair/exchange/node_modules/request/request.js:185:22) at emitTwo (events.js:126:13) at Request.emit (events.js:214:7) at Request. (/home/chris/gekko-neural-ETHpair/exchange/node_modules/request/request.js:1157:10) at emitOne (events.js:116:13) at Request.emit (events.js:211:7) at IncomingMessage. (/home/chris/gekko-neural-ETHpair/exchange/node_modules/request/request.js:1079:12) at Object.onceWrapper (events.js:313:30) at emitNone (events.js:111:20) at IncomingMessage.emit (events.js:208:7) at endReadableNT (_stream_readable.js:1064:12) at args.(anonymous function) (/usr/lib/node_modules/pm2/node_modules/event-loop-inspector/index.js:133:29) at _combinedTickCallback (internal/process/next_tick.js:138:11) at process._tickDomainCallback (internal/process/next_tick.js:218:9)

. . . a while later . . . 2018-08-10 21:53:41 (DEBUG): Requested XLM/ETH trade data from Binance ... 2018-08-10 21:53:42 (DEBUG): Processing 1 new trades. From 2018-08-10 19:53:41 UTC to 2018-08-10 19:53:41 UTC. (a few seconds) 2018-08-10 21:53:42 (DEBUG): [EVENT portfolioChange] { asset: 1900.762, currency: 4.28721185 } 2018-08-10 21:53:51 (DEBUG): Requested XLM/ETH trade data from Binance ... 2018-08-10 21:53:52 (DEBUG): No new trades. 2018-08-10 21:54:01 (DEBUG): Requested XLM/ETH trade data from Binance ... 2018-08-10 21:54:02 (DEBUG): Processing 7 new trades. From 2018-08-10 19:53:57 UTC to 2018-08-10 19:53:59 UTC. (a few seconds) 2018-08-10 21:54:11 (DEBUG): Requested XLM/ETH trade data from Binance ...

It ended up buying 1902 or so XLM and didn't show a tradeCompleted event, which is why I was suprised when there was a sell showing up after another sell to my Telegrambot without showing the buy.

Could it be that we are sending a trade when moving without first cancelling the previous trade and that causes binance to see that we don't have enough balance and doesn't put in the new trade and then a while later cancels the old one?

askmike commented 6 years ago

Could it be that we are sending a trade when moving without first cancelling the previous trade and that causes binance to see that we don't have enough balance and doesn't put in the new trade and then a while later cancels the old one?

It definitely should not be: it always cancels first and waits until binance says it indeed has been cancelled. This to make sure that between Gekko checking if the order was fully filled and trying to execute a cancel (which happens some time later, like half a second).

I see two reasons why this might be happening:

  1. Binance needs some time after a cancel to make sure the balance is updated again (unlikely since I am not running into this, I am making orders on binance 24/7 using the same code).
  2. There was a partial fill between the last time Gekko Checked and when Binance processed the cancel request. Unlike other exchanges (poloniex for example) Binance does not tell you how much of the order was partial filled when you can cancel an order.

I've created a new branch that has some debug logging for both of these cases: @cuthulino @cstegmann would you mind running that one and post logs if it happens again? This is the branch: https://github.com/askmike/gekko/tree/hotfix/binance-insufficient-funds

cstegmann commented 6 years ago

@askmike Ok, done. Running my bots on the hotfix branch. Thanks for the help!

askmike commented 6 years ago

Thanks for the bugreports :)

On Sat, 11 Aug 2018, 16:05 cstegmann, notifications@github.com wrote:

@askmike https://github.com/askmike Ok, done. Running my bots on the hotfix branch. Thanks for the help!

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/askmike/gekko/issues/2405#issuecomment-412259363, or mute the thread https://github.com/notifications/unsubscribe-auth/AA7MD-T3XZcPgwXiUoQdOmhhpjawuvUSks5uPpA5gaJpZM4VuJ4q .

cstegmann commented 6 years ago

@askmike Ok, so it happened on a Sell this time. Both times it caused gekko to crash (running it in pm2), the first time it restarted it started selling again. Problem with the oldOrder variable.

EDIT: Oh i found it, this.getOrder(oldOrder, (err, res) => { should be this.getOrder(this.oldOrder, (err, res) => { . I changed it locally and restarted my bots.

ReferenceError: oldOrder is not defined at /home/chris/gekko-neural-BTCpair/exchange/wrappers/binance.js:127:25 at Request.request [as _callback] (/home/chris/gekko-neural-BTCpair/exchange/node_modules/binance/lib/rest.js:90:25) at Request.self.callback (/home/chris/gekko-neural-BTCpair/exchange/node_modules/request/request.js:185:22) at emitTwo (events.js:126:13) at Request.emit (events.js:214:7) at Request. (/home/chris/gekko-neural-BTCpair/exchange/node_modules/request/request.js:1157:10) at emitOne (events.js:116:13) at Request.emit (events.js:211:7) at IncomingMessage. (/home/chris/gekko-neural-BTCpair/exchange/node_modules/request/request.js:1079:12) at Object.onceWrapper (events.js:313:30) at emitNone (events.js:111:20) at IncomingMessage.emit (events.js:208:7) at endReadableNT (_stream_readable.js:1064:12) at args.(anonymous function) (/usr/lib/node_modules/pm2/node_modules/event-loop-inspector/index.js:133:29) at _combinedTickCallback (internal/process/next_tick.js:138:11) at process._tickDomainCallback (internal/process/next_tick.js:218:9)

2018-08-11 19:40:17 (INFO): Trader Received advice to go short. Selling ZEC isValidLot 0.001 true 2018-08-11 19:40:17 (DEBUG): Creating order to sell 12.209928 ZEC 2018-08-11 19:40:24 (DEBUG): [ORDER] statusChange: SUBMITTED isValidLot 0.001 true 2018-08-11 19:40:25 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:40:26 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:40:27 (DEBUG): No new trades. 2018-08-11 19:40:31 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:40:32 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:40:34 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:40:35 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:40:36 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:40:37 (DEBUG): Processing 2 new trades. From 2018-08-11 17:40:28 UTC to 2018-08-11 17:40:35 UTC. (a few seconds) 2018-08-11 19:40:46 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:40:46 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:40:46 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:40:47 (DEBUG): No new trades. 2018-08-11 19:40:50 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:40:51 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:40:56 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:40:57 (DEBUG): Processing 1 new trades. From 2018-08-11 17:40:48 UTC to 2018-08-11 17:40:48 UTC. (a few seconds) 2018-08-11 19:41:00 (DEBUG): syncing private data 2018-08-11 19:41:03 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:41:04 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:41:06 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:41:07 (DEBUG): No new trades. 2018-08-11 19:41:16 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:41:17 (DEBUG): No new trades. 2018-08-11 19:42:26 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:42:27 (DEBUG): No new trades. 2018-08-11 19:42:36 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:42:37 (DEBUG): No new trades. 2018-08-11 19:42:40 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true isValidLot 0.001 true 2018-08-11 19:42:40 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:42:43 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:42:44 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:42:46 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:42:46 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:42:47 (DEBUG): Processing 7 new trades. From 2018-08-11 17:42:36 UTC to 2018-08-11 17:42:36 UTC. (a few seconds) 2018-08-11 19:42:48 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:42:51 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:42:51 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:42:54 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:42:54 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:42:56 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:42:57 (DEBUG): [ORDER] statusChange: MOVING 2018-08-11 19:42:57 (DEBUG): No new trades. isValidLot 0.001 true 2018-08-11 19:42:58 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:43:00 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true isValidLot 0.001 true 2018-08-11 19:43:01 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:43:04 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:43:05 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:43:06 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:43:07 (DEBUG): Processing 1 new trades. From 2018-08-11 17:43:05 UTC to 2018-08-11 17:43:05 UTC. (a few seconds) 2018-08-11 19:43:10 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:43:11 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:43:16 (DEBUG): [ORDER] statusChange: MOVING 2018-08-11 19:43:16 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:43:17 (DEBUG): Processing 1 new trades. From 2018-08-11 17:43:08 UTC to 2018-08-11 17:43:08 UTC. (a few seconds) isValidLot 0.001 true 2018-08-11 19:43:17 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:43:20 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:43:22 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:43:26 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:43:27 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:43:27 (DEBUG): No new trades. 2018-08-11 19:43:27 (DEBUG): [ORDER] statusChange: OPEN isValidLot 0.001 true 2018-08-11 19:43:27 (DEBUG): No new trades. 2018-08-11 19:43:27 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:43:31 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:43:31 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:43:35 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:43:35 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:43:36 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:43:37 (DEBUG): Processing 3 new trades. From 2018-08-11 17:43:27 UTC to 2018-08-11 17:43:27 UTC. (a few seconds) 2018-08-11 19:43:38 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:43:39 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:43:41 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:43:42 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:43:44 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:43:45 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:43:46 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:43:47 (DEBUG): No new trades. 2018-08-11 19:43:53 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:43:54 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:43:56 (DEBUG): [ORDER] statusChange: MOVING 2018-08-11 19:43:56 (DEBUG): Requested ZEC/BTC trade data from Binance ... isValidLot 0.001 true 2018-08-11 19:43:57 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:43:57 (DEBUG): Processing 1 new trades. From 2018-08-11 17:43:47 UTC to 2018-08-11 17:43:47 UTC. (a few seconds) 2018-08-11 19:43:59 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:44:00 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:44:06 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:44:08 (DEBUG): No new trades. 2018-08-11 19:44:11 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-11 19:44:12 (DEBUG): [ORDER] statusChange: OPEN 2018-08-11 19:44:16 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:44:17 (DEBUG): Processing 4 new trades. From 2018-08-11 17:44:08 UTC to 2018-08-11 17:44:15 UTC. (a few seconds) 2018-08-11 19:44:26 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-11 19:44:28 (DEBUG): Processing 4 new trades. From 2018-08-11 17:44:17 UTC to 2018-08-11 17:44:25 UTC. (a few seconds) 2018-08-11 19:44:30 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true Binance said: "Account has insufficient balance", retrying once..

______   ________  __    __  __    __   ______

/ \ / |/ | / |/ | / | / \ /$$$$$$ |$$$$$$$$/ $$ | /$$/ $$ | /$$/ /$$$$$$ | $$ | $$/ $$ | $$ |/$$/ $$ |/$$/ $$ | $$ | $$ |/ |$$ | $$ $$< $$ $$< $$ | $$ | $$ |$$$$ |$$$$$/ $$$$$ \ $$$$$ \ $$ | $$ | $$ \$$ |$$ |____ $$ |$$ \ $$ |$$ \ $$ __$$ | $$ $$/ $$ |$$ | $$ |$$ | $$ |$$ $$/ $$$$$$/ $$$$$$$$/ $$/ $$/ $$/ $$/ $$$$$$/

    Gekko v0.6.5
    I'm gonna make you rich, Bud Fox.

2018-08-11 19:44:31 (INFO): Setting up Gekko in realtime mode 2018-08-11 19:44:31 (INFO): 2018-08-11 19:44:31 (INFO): Setting up: 2018-08-11 19:44:31 (INFO): Candle writer 2018-08-11 19:44:31 (INFO): Store candles in a database 2018-08-11 19:44:31 (INFO):

2018-08-11 19:44:31 (INFO): Setting up:

cstegmann commented 6 years ago

@askmike It happened again, this time we got some error messages and Gekko didn't restart. But it thought that I had sold everything and told my strategy we were short when we were still way long and I didn't notice it until I just checked the logs. I am switching back to develop because I also encountered the summary/feePercent issue which is fixed on develop. Will try to patch this in so that errors keep getting sent but this is really not viable.

2018-08-14 19:01:14 (DEBUG): Current market: bear Percent change predicted: -0.6155017433044886 Current price: 0.021043 Last buy price: 0.020905 Current position: long 2018-08-14 19:01:14 (INFO): Trader Received advice to go short. Selling ZEC isValidLot 0.001 true 2018-08-14 19:01:14 (DEBUG): Creating order to sell 13.735961 ZEC 2018-08-14 19:01:19 (DEBUG): syncing private data 2018-08-14 19:01:20 (DEBUG): [ORDER] statusChange: SUBMITTED isValidLot 0.001 true 2018-08-14 19:01:21 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:01:23 (DEBUG): [ORDER] statusChange: MOVING 2018-08-14 19:01:23 (DEBUG): Requested ZEC/BTC trade data from Binance ... isValidLot 0.001 true 2018-08-14 19:01:24 (DEBUG): Processing 3 new trades. From 2018-08-14 17:01:19 UTC to 2018-08-14 17:01:23 UTC. (a few seconds) 2018-08-14 19:01:24 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:01:27 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:01:28 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:01:30 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:01:31 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:01:33 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:01:34 (DEBUG): [ORDER] statusChange: MOVING 2018-08-14 19:01:34 (DEBUG): Processing 2 new trades. From 2018-08-14 17:01:24 UTC to 2018-08-14 17:01:31 UTC. (a few seconds) isValidLot 0.001 true 2018-08-14 19:01:35 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:01:37 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:01:38 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:01:43 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:01:44 (DEBUG): No new trades. 2018-08-14 19:01:53 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:01:54 (DEBUG): No new trades. 2018-08-14 19:02:03 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:02:04 (DEBUG): Processing 4 new trades. From 2018-08-14 17:01:55 UTC to 2018-08-14 17:01:58 UTC. (a few seconds) 2018-08-14 19:02:08 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:02:09 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:02:11 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:02:12 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:02:13 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:02:14 (DEBUG): No new trades. 2018-08-14 19:02:23 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:02:23 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:02:24 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:02:24 (DEBUG): Processing 2 new trades. From 2018-08-14 17:02:22 UTC to 2018-08-14 17:02:22 UTC. (a few seconds) 2018-08-14 19:02:26 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:02:27 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:02:33 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:02:34 (DEBUG): Processing 1 new trades. From 2018-08-14 17:02:29 UTC to 2018-08-14 17:02:29 UTC. (a few seconds) 2018-08-14 19:02:35 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:02:36 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:02:41 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:02:42 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:02:43 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:02:44 (DEBUG): Processing 1 new trades. From 2018-08-14 17:02:35 UTC to 2018-08-14 17:02:35 UTC. (a few seconds) 2018-08-14 19:02:44 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:02:45 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:02:48 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:02:49 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:02:53 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:02:55 (DEBUG): No new trades. 2018-08-14 19:03:02 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:03:03 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:03:03 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:03:04 (DEBUG): No new trades. 2018-08-14 19:03:08 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:03:09 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:03:13 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:03:14 (DEBUG): Processing 3 new trades. From 2018-08-14 17:03:12 UTC to 2018-08-14 17:03:13 UTC. (a few seconds) 2018-08-14 19:03:23 (DEBUG): [ORDER] statusChange: MOVING 2018-08-14 19:03:23 (DEBUG): Requested ZEC/BTC trade data from Binance ... isValidLot 0.001 true 2018-08-14 19:03:24 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:03:24 (DEBUG): No new trades. 2018-08-14 19:03:33 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:03:35 (DEBUG): Processing 1 new trades. From 2018-08-14 17:03:34 UTC to 2018-08-14 17:03:34 UTC. (a few seconds) 2018-08-14 19:03:42 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:03:43 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:03:43 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:03:44 (DEBUG): No new trades. 2018-08-14 19:03:46 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:03:47 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:03:53 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:03:54 (DEBUG): No new trades. 2018-08-14 19:04:03 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:04:04 (DEBUG): No new trades. 2018-08-14 19:04:13 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:04:14 (DEBUG): No new trades. 2018-08-14 19:04:23 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:04:24 (DEBUG): No new trades. 2018-08-14 19:04:33 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:04:35 (DEBUG): Processing 1 new trades. From 2018-08-14 17:04:31 UTC to 2018-08-14 17:04:31 UTC. (a few seconds) 2018-08-14 19:04:43 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:04:44 (DEBUG): No new trades. 2018-08-14 19:04:48 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:04:49 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:04:53 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:04:55 (DEBUG): Processing 4 new trades. From 2018-08-14 17:04:45 UTC to 2018-08-14 17:04:53 UTC. (a few seconds) 2018-08-14 19:05:03 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:05:04 (DEBUG): Processing 2 new trades. From 2018-08-14 17:04:54 UTC to 2018-08-14 17:05:01 UTC. (a few seconds) 2018-08-14 19:05:05 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true 2018-08-14 19:05:06 (DEBUG): [ORDER] statusChange: OPEN 2018-08-14 19:05:11 (DEBUG): [ORDER] statusChange: MOVING isValidLot 0.001 true Binance said: "Account has insufficient balance", retrying once.. partial fill on old order? { err: undefined, res: { price: 0.020944, amount: 3.432, date: moment("2018-08-14T19:05:11.813"), fees: { BTC: 0.00007188 }, feePercent: 0.1 } } 2018-08-14 19:05:13 (DEBUG): Requested ZEC/BTC trade data from Binance ... Binance said: "Account has insufficient balance", retrying once.. 2018-08-14T17:05:14.159Z '[sticky order] FATAL ERROR' 'Error -2010: Account has insufficient balance for requested action.' 2018-08-14T17:05:14.159Z { Error: Error -2010: Account has insufficient balance for requested action. at /home/chris/gekko-neural-BTCpair/exchange/wrappers/binance.js:96:15 at Request.request [as _callback] (/home/chris/gekko-neural-BTCpair/exchange/node_modules/binance/lib/rest.js:90:25) at Request.self.callback (/home/chris/gekko-neural-BTCpair/exchange/node_modules/request/request.js:185:22) at emitTwo (events.js:126:13) at Request.emit (events.js:214:7) at IncomingMessage. (/home/chris/gekko-neural-BTCpair/exchange/node_modules/request/request.js:1079:12) at Object.onceWrapper (events.js:313:30) at emitNone (events.js:111:20) at IncomingMessage.emit (events.js:208:7) at endReadableNT (_stream_readable.js:1064:12) at args.(anonymous function) (/usr/lib/node_modules/pm2/node_modules/event-loop-inspector/index.js:133:29) at _combinedTickCallback (internal/process/next_tick.js:138:11) at process._tickDomainCallback (internal/process/next_tick.js:218:9) retry: 1 } 2018-08-14 19:05:14 (DEBUG): [ORDER] statusChange: ERROR 2018-08-14 19:05:14 (DEBUG): { Error: Error -2010: Account has insufficient balance for requested action. at /home/chris/gekko-neural-BTCpair/exchange/wrappers/binance.js:96:15 at Request.request [as _callback] (/home/chris/gekko-neural-BTCpair/exchange/node_modules/binance/lib/rest.js:90:25) at Request.self.callback (/home/chris/gekko-neural-BTCpair/exchange/node_modules/request/request.js:185:22) at emitTwo (events.js:126:13) at Request.emit (events.js:214:7) at Request. (/home/chris/gekko-neural-BTCpair/exchange/node_modules/request/request.js:1157:10) at emitOne (events.js:116:13) at Request.emit (events.js:211:7) at IncomingMessage. (/home/chris/gekko-neural-BTCpair/exchange/node_modules/request/request.js:1079:12) at Object.onceWrapper (events.js:313:30) at emitNone (events.js:111:20) at IncomingMessage.emit (events.js:208:7) at endReadableNT (_stream_readable.js:1064:12) at args.(anonymous function) (/usr/lib/node_modules/pm2/node_modules/event-loop-inspector/index.js:133:29) at _combinedTickCallback (internal/process/next_tick.js:138:11) at process._tickDomainCallback (internal/process/next_tick.js:218:9) retry: 1 } 2018-08-14 19:05:14 (DEBUG): Processing 3 new trades. From 2018-08-14 17:05:11 UTC to 2018-08-14 17:05:11 UTC. (a few seconds) partial fill on old order? { err: undefined, res: { price: 0.020944, amount: 3.432, date: moment("2018-08-14T19:05:11.813"), fees: { BTC: 0.00007188 }, feePercent: 0.1 } } 2018-08-14 19:05:23 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:05:24 (DEBUG): Processing 2 new trades. From 2018-08-14 17:05:18 UTC to 2018-08-14 17:05:18 UTC. (a few seconds) 2018-08-14 19:05:33 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:05:34 (DEBUG): Processing 1 new trades. From 2018-08-14 17:05:32 UTC to 2018-08-14 17:05:32 UTC. (a few seconds) 2018-08-14 19:05:43 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:05:44 (DEBUG): Processing 1 new trades. From 2018-08-14 17:05:35 UTC to 2018-08-14 17:05:35 UTC. (a few seconds) 2018-08-14 19:05:53 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:05:54 (DEBUG): Processing 1 new trades. From 2018-08-14 17:05:48 UTC to 2018-08-14 17:05:48 UTC. (a few seconds) 2018-08-14 19:06:03 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:06:04 (DEBUG): No new trades. 2018-08-14 19:06:13 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:06:14 (DEBUG): No new trades. 2018-08-14 19:06:23 (DEBUG): Requested ZEC/BTC trade data from Binance ... 2018-08-14 19:06:24 (DEBUG): Processing 3 new trades. From 2018-08-14 17:06:17 UTC to 2018-08-14 17:06:23 UTC. (a few seconds) 2018-08-14 19:06:24 (DEBUG): Current market: bear Percent change predicted: -0.13167922561283874 Current price: 0.020948 Last buy price: 0.020905 Current position: short 2018-08-14 19:06:33 (DEBUG): Requested ZEC/BTC trade data from Binance ...

cstegmann commented 6 years ago

@askmike It happened on the BNB/USDT pair on Binance as well now. That pair has a daily volume of $16,000,000+ so this isn't just something that happens to low volume pairs like ZEC/BTC.

2018-08-15 15:44:10 (DEBUG): Current market: bear Percent change predicted: -1.2597176923922422 Current price: 10.0517 Last buy price: 9.8745 Current position: long 2018-08-15 15:44:10 (INFO): Trader Received advice to go short. Selling BNB isValidLot 10 true 2018-08-15 15:44:10 (DEBUG): Creating order to sell 184.03838844 BNB 2018-08-15 15:44:17 (DEBUG): [ORDER] statusChange: SUBMITTED isValidLot 10 true 2018-08-15 15:44:18 (DEBUG): [ORDER] statusChange: OPEN 2018-08-15 15:44:19 (DEBUG): Requested BNB/USDT trade data from Binance ... 2018-08-15 15:44:20 (DEBUG): Processing 10 new trades. From 2018-08-15 13:44:16 UTC to 2018-08-15 13:44:19 UTC. (a few seconds) 2018-08-15 15:44:21 (DEBUG): [ORDER] statusChange: MOVING isValidLot 10 true 2018-08-15 15:44:21 (DEBUG): [ORDER] statusChange: OPEN 2018-08-15 15:44:24 (DEBUG): [ORDER] statusChange: MOVING isValidLot 10 true 2018-08-15T13:44:25.836Z '[sticky order] FATAL ERROR' 'Error -2010: Account has insufficient balance for requested action.' 2018-08-15T13:44:25.836Z Error: Error -2010: Account has insufficient balance for requested action. at /home/chris/gekko-neural-USDTpair/exchange/wrappers/binance.js:94:15 at Request.request [as _callback] (/home/chris/gekko-neural-USDTpair/exchange/node_modules/binance/lib/rest.js:90:25) at Request.self.callback (/home/chris/gekko-neural-USDTpair/exchange/node_modules/request/request.js:185:22) at emitTwo (events.js:126:13) at Request.emit (events.js:214:7) at Request. (/home/chris/gekko-neural-USDTpair/exchange/node_modules/request/request.js:1157:10) at emitOne (events.js:116:13) at Request.emit (events.js:211:7) at IncomingMessage. (/home/chris/gekko-neural-USDTpair/exchange/node_modules/request/request.js:1079:12) at Object.onceWrapper (events.js:313:30) at emitNone (events.js:111:20) at IncomingMessage.emit (events.js:208:7) at endReadableNT (_stream_readable.js:1064:12) at args.(anonymous function) (/usr/lib/node_modules/pm2/node_modules/event-loop-inspector/index.js:133:29) at _combinedTickCallback (internal/process/next_tick.js:138:11) at process._tickDomainCallback (internal/process/next_tick.js:218:9) 2018-08-15 15:44:25 (DEBUG): [ORDER] statusChange: ERROR 2018-08-15 15:44:25 (DEBUG): Error: Error -2010: Account has insufficient balance for requested action. at /home/chris/gekko-neural-USDTpair/exchange/wrappers/binance.js:94:15 at Request.request [as _callback] (/home/chris/gekko-neural-USDTpair/exchange/node_modules/binance/lib/rest.js:90:25) at Request.self.callback (/home/chris/gekko-neural-USDTpair/exchange/node_modules/request/request.js:185:22) at emitTwo (events.js:126:13) at Request.emit (events.js:214:7) at Request. (/home/chris/gekko-neural-USDTpair/exchange/node_modules/request/request.js:1157:10) at emitOne (events.js:116:13) at Request.emit (events.js:211:7) at IncomingMessage. (/home/chris/gekko-neural-USDTpair/exchange/node_modules/request/request.js:1079:12) at Object.onceWrapper (events.js:313:30) at emitNone (events.js:111:20) at IncomingMessage.emit (events.js:208:7) at endReadableNT (_stream_readable.js:1064:12) at args.(anonymous function) (/usr/lib/node_modules/pm2/node_modules/event-loop-inspector/index.js:133:29) at _combinedTickCallback (internal/process/next_tick.js:138:11) at process._tickDomainCallback (internal/process/next_tick.js:218:9) 2018-08-15 15:44:29 (DEBUG): Requested BNB/USDT trade data from Binance ... 2018-08-15 15:44:30 (DEBUG): Processing 18 new trades. From 2018-08-15 13:44:24 UTC to 2018-08-15 13:44:28 UTC. (a few seconds) 2018-08-15 15:44:39 (DEBUG): Requested BNB/USDT trade data from Binance ... 2018-08-15 15:44:40 (DEBUG): Processing 36 new trades. From 2018-08-15 13:44:31 UTC to 2018-08-15 13:44:38 UTC. (a few seconds) 2018-08-15 15:44:49 (DEBUG): Requested BNB/USDT trade data from Binance ... 2018-08-15 15:44:50 (DEBUG): Processing 9 new trades. From 2018-08-15 13:44:41 UTC to 2018-08-15 13:44:49 UTC. (a few seconds) 2018-08-15 15:44:59 (DEBUG): Requested BNB/USDT trade data from Binance ...

cstegmann commented 6 years ago

@askmike Sorry to be such a pain, but it happened with the XLM/ETH Pair. I noticed that the amount in the this.oldOrder debugging seems to be correct at 178. I am not sure what's going on in the Binance Order History, it looks like it subtracted the 178 from the initial amount, it it could be something that Binance did after the bot tried to sell the previous amount. (https://imgur.com/tIL8Rkj)

Processing 4 new trades. From 2018-08-15 17:59:10 UTC to 2018-08-15 17:59:10 UTC. (a few seconds)
2018-08-15 19:59:13 (DEBUG):
     Current market: bear
     Percent change predicted: -0.8272697509990573
     Current price: 0.00076694
     Last buy price: 0.00075843
     Current position: long
2018-08-15 19:59:13 (INFO):     Trader Received advice to go short. Selling  XLM
isValidLot 0.01 true
2018-08-15 19:59:13 (DEBUG):    Creating order to sell 6945.885 XLM
2018-08-15 19:59:19 (DEBUG):    [ORDER] statusChange: SUBMITTED
isValidLot 0.01 true
2018-08-15 19:59:19 (DEBUG):    [ORDER] statusChange: OPEN
2018-08-15 19:59:22 (DEBUG):    Requested XLM/ETH trade data from Binance ...
2018-08-15 19:59:22 (DEBUG):    [ORDER] statusChange: MOVING
2018-08-15 19:59:23 (DEBUG):    No new trades.
isValidLot 0.01 true
2018-08-15 19:59:23 (DEBUG):    [ORDER] statusChange: OPEN
2018-08-15 19:59:26 (DEBUG):    [ORDER] statusChange: MOVING
isValidLot 0.01 true
2018-08-15 19:59:27 (DEBUG):    [ORDER] statusChange: OPEN
2018-08-15 19:59:32 (DEBUG):    Requested XLM/ETH trade data from Binance ...
2018-08-15 19:59:33 (DEBUG):    Processing 3 new trades. From 2018-08-15 17:59:23 UTC to 2018-08-15 17:59:27 UTC. (a few seconds)
2018-08-15 19:59:33 (DEBUG):    [ORDER] statusChange: MOVING
isValidLot 0.01 true
2018-08-15 19:59:34 (DEBUG):    [ORDER] statusChange: OPEN
2018-08-15 19:59:37 (DEBUG):    [ORDER] statusChange: MOVING
isValidLot 0.01 true
Binance said: "Account has insufficient balance", retrying once..
partial fill on old order? { err: undefined,
 res:
  { price: 0.0007633399999999999,
    amount: 178,
    date: moment("2018-08-15T19:59:37.403"),
    fees: { ETH: 0.00013587 },
    feePercent: 0.1 } }
Binance said: "Account has insufficient balance", retrying once..
2018-08-15T17:59:40.142Z '[sticky order] FATAL ERROR' 'Error -2010: Account has insufficient balance for requested action.'
2018-08-15T17:59:40.142Z { Error: Error -2010: Account has insufficient balance for requested action.
   at /home/chris/gekko-neural-ETHpair/exchange/wrappers/binance.js:96:15
   at Request.request [as _callback] (/home/chris/gekko-neural-ETHpair/exchange/node_modules/binance/lib/rest.js:90:25)
   at Request.self.callback (/home/chris/gekko-neural-ETHpair/exchange/node_modules/request/request.js:185:22)
   at emitTwo (events.js:126:13)
   at Request.emit (events.js:214:7)
   at Request.<anonymous> (/home/chris/gekko-neural-ETHpair/exchange/node_modules/request/request.js:1157:10)
   at emitOne (events.js:116:13)
   at Request.emit (events.js:211:7)
   at IncomingMessage.<anonymous> (/home/chris/gekko-neural-ETHpair/exchange/node_modules/request/request.js:1079:12)
   at Object.onceWrapper (events.js:313:30)
   at emitNone (events.js:111:20)
   at IncomingMessage.emit (events.js:208:7)
   at endReadableNT (_stream_readable.js:1064:12)
   at args.(anonymous function) (/usr/lib/node_modules/pm2/node_modules/event-loop-inspector/index.js:133:29)
   at _combinedTickCallback (internal/process/next_tick.js:138:11)
   at process._tickDomainCallback (internal/process/next_tick.js:218:9) retry: 1 }
2018-08-15 19:59:40 (DEBUG):    [ORDER] statusChange: ERROR
2018-08-15 19:59:40 (DEBUG):    { Error: Error -2010: Account has insufficient balance for requested action.
    at /home/chris/gekko-neural-ETHpair/exchange/wrappers/binance.js:96:15
    at Request.request [as _callback] (/home/chris/gekko-neural-ETHpair/exchange/node_modules/binance/lib/rest.js:90:25)
    at Request.self.callback (/home/chris/gekko-neural-ETHpair/exchange/node_modules/request/request.js:185:22)
    at emitTwo (events.js:126:13)
    at Request.emit (events.js:214:7)
    at Request.<anonymous> (/home/chris/gekko-neural-ETHpair/exchange/node_modules/request/request.js:1157:10)
    at emitOne (events.js:116:13)
    at Request.emit (events.js:211:7)
    at IncomingMessage.<anonymous> (/home/chris/gekko-neural-ETHpair/exchange/node_modules/request/request.js:1079:12)
    at Object.onceWrapper (events.js:313:30)
    at emitNone (events.js:111:20)
    at IncomingMessage.emit (events.js:208:7)
    at endReadableNT (_stream_readable.js:1064:12)
    at args.(anonymous function) (/usr/lib/node_modules/pm2/node_modules/event-loop-inspector/index.js:133:29)
    at _combinedTickCallback (internal/process/next_tick.js:138:11)
    at process._tickDomainCallback (internal/process/next_tick.js:218:9) retry: 1 }
partial fill on old order? { err: undefined,
  res:
   { price: 0.0007633399999999999,
     amount: 178,
     date: moment("2018-08-15T19:59:37.403"),
     fees: { ETH: 0.00013587 },
     feePercent: 0.1 } }
2018-08-15 19:59:42 (DEBUG):    Requested XLM/ETH trade data from Binance ...
askmike commented 6 years ago

Thanks for these logs! Definitely not a pain. With your logs I am now able to see clearly that the problem is that orders Gekko cancelled had partial fills. Working on a fix now.

askmike commented 6 years ago

@cuthulino @cstegmann I pushed a possible fix into the hotfix branch (see here #2450). That should catch the error and work around it. Unfortunately the error rarely happens so it's hard for me to debug it. I am running this code now nonetheless.

Would you mind also running it? And let me know if the log shows anything with [GB/insufficientFunds]?