Buy can execute during a sell that is current in process causing invalid profit/loss values.

station384 commented 6 years ago

System information

Have I written custom code (as opposed to using zenbot vanilla): No
OS Platform and Distribution (e.g., Linux Ubuntu 16.04): Current LTS Ubuntu
Zenbot version (commit ref, or version): current unstable
Zenbot branch: unstable
NodeJS version: latest
Python version (when using a python script):
Exact command to reproduce (include everything):
Did I make any changes to conf-sample.js?:

Describe the problem

During a sim/trade if a buy is issued by a strategy before a sell operation is completed the can result in invalid values in the current balance. example: 2018-06-07 08:59:00 16.7700 BNB-USDT -0.03% 716 55.37 ++ +16.7700 16.5926 16.7608 64.2946 69.5444 5 0 NEU +0.14% 2.95043996 BNB 0.05342807 USDT +14.66% -2.

2018-06-07 09:03:00 16.8299 BNB-USDT +0.35% 6546 57.81 ++ +16.8299 16.6047 16.7710 65.1391 66.5814 1 0 NEU +0.50% 2.95043996 BNB 0.05342807 USDT +15.05% -2.

2018-06-07 09:07:00 16.9097 BNB-USDT +0.47% 9248 60.77 ++ +16.9097 16.6127 16.7878 66.5175 66.2111 -1 -1 NEU sell 2.95043996 BNB 0.05342807 USDT +15.58% -2.

2018-06-07 09:11:00 16.9324 BNB-USDT +0.13% 15417 61.57 ++ +16.9324 16.6194 16.8152 67.6883 68.2481 0 1 NEU selling 2.95043996 BNB 0.05342807 USDT +15.73% -2.

2018-06-07 09:15:00 16.8905 BNB-USDT -0.25% 11934 59.27 ++ +16.8905 16.6291 16.8424 68.6429 71.4735 2 0 NEU buying 0.01043995 BNB 49.81243119 USDT+126.58% +91.6

2018-06-07 09:19:00 16.8999 BNB-USDT +0.05% 7717 59.62 ++ +16.8999 16.6490 16.8590 69.7947 76.7097 6 0 NEU buying 0.01043995 BNB 49.81243119 USDT+126.58% +91.5

2018-06-07 09:23:00 16.8600 BNB-USDT -0.24% 18350 57.45 ++ +16.8600 16.6756 16.8723 71.6489 80.6698 9 0 NEU bought 2.94749996 BNB 0.20643053 USDT+126.58% +92.0

If you notice the highlighted portion you can see the sell order hasn't completed before the buy order has executed. causing the huge change the percentage. I have seen this problem in sim, and occasionally during live trading.

Source code / Error logs

defkev commented 6 years ago

Recent change?

The current order should get cancelled on a signal switch, buy on sell and vice versa.

station384 commented 6 years ago

Not a recent change.

This has been in existence for awhile, I've just only recently been able to figure out why. I noticed it about 4 months ago when my profit/loss percentages went to +2000% while the bot was trading (zen was running the unstable branch at the time), since this output (the 2000%) was on the entire screen I couldn't scroll back and see when it happened. I didn't think much of it and just did a --reset_profit and start back at zero. It happened very, very rarely.

It didn't have much of an effect during live trading since buy and sell were still happening only the p/l percents were off.

This is a different case when running the backtesters, as they calculate their fitness using what the engine reports as the current balance. they end up rating a bad strategy as a wonderful (200% profit on 15 days of trading?! give me some of that), and it gets stuck using that bad strategy. Again this a rare occurrence, but not rare enough to not be noticed.

I've only been able to track down what is happening because I have a current setup that I can repeat it on, using a dataset of binance.BNB-USDT, and a custom strategy I've been working on.

I mainly put this ticket in for me to remember the circumstances as I was going to start looking into why, and to poke anyone else that may have an idea what is going on.

EDIT: And one more thing I just remembered. The Loss Prevention ( won't sell if the sell value is less than so much percent of purchase price) would trigger when a sell was triggered after the percent jump happened, even if it was in range.

defkev commented 6 years ago

Shot in the dark but could indeed be a problem with the balance reported.

station384 commented 6 years ago

@defkev

The current order should get cancelled on a signal switch, buy on sell and vice versa.

That is what I have found as well while looking thru the code, and I think it does. It just some where it is messing up one of the variables it uses to calculate the percents.
Notice the jump when the BNB amount goes from 2.95043996 +15.73% to 0.01043995 +126.58%. something happened between those 2 periods that changed a variable.

I'm going to be investigating more tonight, but the work day is calling and more fires to be put out.

station384 commented 6 years ago

The balance reported is correct, it matches up with what the exchange reports ( made sure of this when I first saw this happen. )

Just looking at the numbers it, it looks like its multiplying a negative and positive value when goes to sell, deducts the amount from the current asset amount, and doing an ABS on it when it does a buy. before the sell is complete. This is just a feeling due to the jump, I can't get that jump in percentage without doing what I'm thinking, unless a value is REALLY far off.

Still my point is, the balance at any given time it is reported, is the correct balance.

EDIT: I really should learn to proof read before hitting submit.

station384 commented 6 years ago

Looking at the series running up to the jump. I notice something else. there were multiple buys. I set the buy percentage to 99.75%, so after the first buy executed, there was enough capital to execute a second buy, and a even a third buy. then the sell happens. then the jump in percentage.

And I put in some debug code to report the signal status on calculate in the strategy, and it is reporting that it sold, it doesn't seem to report the sold if it happens in between. periods, So that is why it looks like a buy is being executed when a sell is still active.

I wonder if this has something to do with it.

defkev commented 6 years ago

it doesn't seem to report the sold if it happens in between

Doesn't getOrder() return status = 'done' for the order(s) in question or does it simply not request a getOrder() for the order, as we can only have one api_order at a time?

station384 commented 6 years ago

I think the problem is the multiple buys right after one another that is doing it.
this pattern seems to work.
buy -> complete -> sell -> compete -> buy -> complete -> sell -> complete. buy -> complete -> sell -> complete -> sell -> complete -> buy-> complete -> sell -> complete

but this seems to mess it up buy -> complete -> sell -> complete -> buy -> buying -> buy -> complete -> sell -> complete -> buy -> complete I think when it fails, there ends up being 2 open buy orders on the exchange, and it only tracks the last order created.

Expanding on this thought: So what I think happens. the first buy happens, which says by a large amount, then a send comes in saying buy a tiny amount. zen only tracks the last one, so when the last buy completes, we now have the sum of both orders when it was expecting say 0.1 BNB the exchange now reports we have 2 BNB, this would account for the 200% profit it is reporting.

station384 commented 6 years ago

I'm trying to test my theory, but I can't find in the engine where I should prevent a new trade if a current trade is in progress. ( want to trace from there )

defkev commented 6 years ago

As i wrote, the bot can't do multi-trading (more than one order at a time) in its current state.

The indicator meanings are:

buy/sell -> signal received, either from the strategy "on period" or from the user "on demand" by issung a limit/market buy/sell (key b/B or s/S)
buying/selling -> order is open, api_order exists and gets updated by getOrder() in cb(null, order)
bought/sold -> exchange reported order complete (usually status = 'd' or 'cd'), getOrder() sets order.status = 'done' and engine deletes api_order and adds it to my_trades

If the signal switches (buy will selling or sell will buying) the bot calls cancelOrder() but we imho never check this, as long as the callback kicks in we consider the trade to be indeed cancelled will it could just as well still be open hint

defkev commented 6 years ago

I just strolled through my bots and found a still open (partially filled) order on the exchange the bot responsible for is no longer aware of so this does indeed look like a (imho pretty severe) bug.

A buy order create this morning at 8:42 am, the bot was in 'buying' mode till 7:21 pm then a sell signal triggered (by the strategy) which got refused by the sell loss protection. Now i suppose the buy order never got cancelled on the exchange in the first place, for whatever reason, when the sell signal triggered, because it is cancelled for the bot (hitting c does nothing so the bot no longer knows about the order)

Now if this order gets filled the balance will change causing the bots profit calculation to go upside-down just like when you would do a trade outside the bot.

station384 commented 6 years ago

I think it is all working as expected. its that oddity where the 2 buy orders can overlap.
That is also why I think it so rare that it happens, usually the 1st buy will not leave though currency to allow for the second buy to happen and it never gets to the point of allowing 2 buys to occur for the majority of people. this is just a theory but I think this would show up a lot more if a buy percent (c.buy_pct = 99.75) was at 50.

And on my previous post, to clarify, I meant prevent a buy from occurring, if a buy is already occurring on reading it again "new trade" is a bit ambiguous.

defkev commented 6 years ago

The same can happen with 100% and deposit set once the price moved enough to make room for another buy.

Regardless the bot should never ever buy during an open buy, even with enough balance_currency, as he simply cannot track both orders at a time.

I'll look into it once i got some time.

defkev commented 6 years ago

Just caught this on my dev build with a deposit of $50:

2018-06-20 14:15:00  6740.80 BTC-USD   -0.11%        0     - 46.07    -0.0052   0.0041  selling  0.00500 BTC  16.26 USD  100.00 USD   16.26%   -0.05%   +0.02%
2018-06-20 14:18:29 - preparing buy order over 0.00741248 BTC of 49.9201 USD (100%) tradeable balance with a expected fee of 0.0798722 USD (0.16%)
2018-06-20 14:18:29 - placing buy order...
2018-06-20 14:18:19  6741.20 BTC-USD   +0.00%        0     - 46.44    -0.0044   0.0043   buying  0.00000 BTC  50.00 USD  133.67 USD   37.40%  +67.54%  +67.64%
...
2018-06-20 17:43:00  6747.60 BTC-USD   -0.11%        0    -- 43.22    -0.0036   0.0021  selling  0.00661 BTC   5.30 USD   89.09 USD    5.94%  +67.70%  +67.64%
2018-06-20 17:44:31 - preparing buy order over 0.00740511 BTC of 49.9201 USD (100%) tradeable balance with a expected fee of 0.0798722 USD (0.16%)
2018-06-20 17:44:31 - placing buy order...
2018-06-20 17:44:23  6747.40 BTC-USD   -0.01%        0    -- 42.81    -0.0036   0.0029   buying  0.00000 BTC  50.00 USD  133.71 USD   37.39%+157.32%+157.23%

Looks like the signal switch never triggered, causing cancel to never get called, resulting in profit to go crazy.

station384 commented 6 years ago

Nice. Always good to have repeatability from separate parties.

station384 commented 6 years ago

Just thought of something. For the condition, that I've been experiencing, the buy -> buy. we don't want to cancel the first buy, just stop the second buy from happening.

this is different from the buy->sell->buy where conditions when the market has changed to the point we no longer want to buy.

Not sure if you were on the same page as me in thought.

station384 commented 6 years ago

I currently have a workaround for the problem in the engine. I implemented it in the strategy.
It is isn't a fix for the problem, but it is a work around using the strategy till a true correction is implemented (which I have been failing at; hence the temp workaround).

For a sell I use this if (!s.api_order || (s.api_order && s.api_order.tradetype != 'sell' && s.api_order.status != 'open')) s.signal = 'sell' else s.signal == null For a buy I use this if (!s.api_order || (s.api_order && s.api_order.tradetype != 'buy' && s.api_order.status != 'open')) s.signal = 'buy' else s.signal == null

hampusboas commented 6 years ago

Is your fix implemented yet? I have the exact same issue. In two days my profit shoots in the sky after a few hours of live trading!

DeviaVir / zenbot