freqtrade / freqtrade

Free, open source crypto trading bot
https://www.freqtrade.io
GNU General Public License v3.0
28.79k stars 6.16k forks source link

Unable to create trade: Available balance is lower than stake amount #1780

Closed natanbarbosa15 closed 5 years ago

natanbarbosa15 commented 5 years ago

Step 1: Have you search for this issue before posting it?

Yes, found the issue but no solution.

Step 2: Describe your environment

Step 3: Describe the problem:

The BTC balance doesn't update after sell, only update in buy method.

Steps to reproduce:

  1. Start bot in live mode and put the stake amount more than 50% of your available balance.
  2. Wait bot finish the 1st trade closed and sold sucessfully.
  3. Wait bot search for new trade and find a buy signal.

Observed Results:

In 3 Step bot can't buy because the balance in bot is outdated, be like the balance not updated after the bot sell the 1st trade, and the balance will be lower than stake because the stake is more than 50% of your balance.

Relevant code exceptions or logs:

2019-04-18 22:34:09,688 - unknown - INFO - Searching pairs: ['MITH/BTC', 'ETH/BTC', 'XRP/BTC', 'BCH/BTC', 'ENJ/BTC', 'LTC/BTC', 'FET/BTC', 'EOS/BTC', 'ADA/BTC', 'BAT/BTC', 'CELR/BTC', 'REP/BTC', 'RVN/BTC', 'TRX/BTC', 'ZIL/BTC', 'WTC/BTC', 'VET/BTC', 'DGD/BTC', 'LEND/BTC', 'WABI/BTC', 'NANO/BTC', 'PHX/BTC', 'HOT/BTC', 'TNB/BTC', 'XMR/BTC', 'ICX/BTC', 'NEO/BTC', 'VIB/BTC', 'DENT/BTC', 'DASH/BTC']
2019-04-18 22:34:10,400 - freqtrade.freqtradebot - WARNING - Unable to create trade: Available balance(0.00018994 BTC) is lower than stake amount(0.003 BTC)
2019-04-18 22:34:14,693 - unknown - INFO - Searching pairs: ['MITH/BTC', 'ETH/BTC', 'XRP/BTC', 'BCH/BTC', 'ENJ/BTC', 'LTC/BTC', 'FET/BTC', 'EOS/BTC', 'ADA/BTC', 'BAT/BTC', 'CELR/BTC', 'REP/BTC', 'RVN/BTC', 'TRX/BTC', 'ZIL/BTC', 'WTC/BTC', 'VET/BTC', 'DGD/BTC', 'LEND/BTC', 'WABI/BTC', 'NANO/BTC', 'PHX/BTC', 'HOT/BTC', 'TNB/BTC', 'XMR/BTC', 'ICX/BTC', 'NEO/BTC', 'VIB/BTC', 'DENT/BTC', 'DASH/BTC']
2019-04-18 22:34:15,378 - freqtrade.freqtradebot - WARNING - Unable to create trade: Available balance(0.00018994 BTC) is lower than stake amount(0.003 BTC)

The real balance when this errors ocurred is 0.00318994 BTC, so the bot not updated after the last sell. I tried myself to fix this error adding the code below in "execute_sell" method in "freqtradebot.py" class:

self.wallets.update()

My complete "execute_sell" method in "freqtradebot.py" class is like this:

def execute_sell(self, trade: Trade, limit: float, sell_reason: SellType) -> None:

        sell_type = 'sell'
        if sell_reason in (SellType.STOP_LOSS, SellType.TRAILING_STOP_LOSS):
            sell_type = 'stoploss'

        # if stoploss is on exchange and we are on dry_run mode,
        # we consider the sell price stop price
        if self.config.get('dry_run', False) and sell_type == 'stoploss' \
           and self.strategy.order_types['stoploss_on_exchange']:
            limit = trade.stop_loss

        # First cancelling stoploss on exchange ...
        if self.strategy.order_types.get('stoploss_on_exchange') and trade.stoploss_order_id:
            self.exchange.cancel_order(trade.stoploss_order_id, trade.pair)

        # Execute sell and update trade record
        order_id = self.exchange.sell(pair=str(trade.pair),
                                      ordertype=self.strategy.order_types[sell_type],
                                      amount=trade.amount, rate=limit,
                                      time_in_force=self.strategy.order_time_in_force['sell']
                                      )['id']

        trade.open_order_id = order_id
        trade.close_rate_requested = limit
        trade.sell_reason = sell_reason.value
        Trade.session.flush()

    # Updating wallets
        self.wallets.update()

        self.notify_sell(trade)

With my hotfix the problem is gone.

xmatthias commented 5 years ago

How far apart did 1st sell and 2nd buy happen? what was the sell reason? (should be in telegram) would you happen to have the logs between the 1st sell and 2nd buy?

i am specifically looking for Wallets synced. - which should happen at info level after the sell occured.

Be carefull with the location of your hotfix - it'll only work if you use market orders, or if the limit order was immediately filled, but willl not apply if the limit-sell is filled a few instances later.

natanbarbosa15 commented 5 years ago

How far apart did 1st sell and 2nd buy happen?

The 2nd buy happen immediattely after 1st sell, and if buy signal lost when find another the situtation is same.

what was the sell reason? (should be in telegram)

The sell reason is "sell signal" is a experimental in config file.

would you happen to have the logs between the 1st sell and 2nd buy?

Sorry but i not used the log option when started the bot, but i will try to reproduce the same situation again with log enabled.

For now i will remove my hotfix, and try to reproduce the same scenario

natanbarbosa15 commented 5 years ago

I tested again without changes on code, and i found the problem again with log enabled, above is the moment when the bot is selling trade by "sell_signal":

2019-04-19 21:50:15,378 - freqtrade.freqtradebot - INFO - Using order book for selling...
2019-04-19 21:50:15,720 - freqtrade.freqtradebot - INFO -   order book asks top 1: 0.00015076
2019-04-19 21:50:17,298 - freqtrade.rpc.rpc_manager - INFO - Sending rpc message: {'type': sell, 'exchange': 'Binance', 'pair': 'EVX/BTC', 'gain': 'profit', 'limit': 0.00015076, 'amount': 20.0, 'open_rate': 0.00014879, 'current_rate': 0.00015068, 'profit_amount': 3.341e-05, 'profit_percent': 0.01121568, 'sell_reason': 'sell_signal', 'stake_currency': 'BTC', 'fiat_currency': 'BRL'}
2019-04-19 21:50:17,694 - freqtrade.freqtradebot - INFO - executed sell, reason: SellType.SELL_SIGNAL
2019-04-19 21:50:18,069 - freqtrade.wallets - INFO - Wallets synced.

The wallet is synced but before the order is fullfilled. The log below is when order is fullfilled:

2019-04-19 21:53:34,307 - freqtrade.freqtradebot - INFO - Found open order for Trade(id=4, pair=EVX/BTC, amount=20.00000000, open_rate=0.00014879, open_since=an hour ago)
2019-04-19 21:53:35,177 - freqtrade.persistence - INFO - Updating trade (id=4) ...
2019-04-19 21:53:35,179 - freqtrade.persistence - INFO - Marking Trade(id=4, pair=EVX/BTC, amount=20.00000000, open_rate=0.00014879, open_since=closed) as closed as the trade is fulfilled and found no open orders for it.
2019-04-19 21:53:35,181 - freqtrade.persistence - INFO - LIMIT_SELL has been fulfilled for Trade(id=4, pair=EVX/BTC, amount=20.00000000, open_rate=0.00014879, open_since=closed).
2019-04-19 21:53:39,281 - unknown - INFO - Searching pairs: ['ETH/BTC', 'ENJ/BTC', 'BCH/BTC', 'MITH/BTC', 'PHX/BTC', 'RVN/BTC', 'XRP/BTC', 'ADA/BTC', 'LTC/BTC', 'EOS/BTC', 'WTC/BTC', 'WABI/BTC', 'GTO/BTC', 'BAT/BTC', 'FET/BTC', 'TRX/BTC', 'QKC/BTC', 'EVX/BTC', 'MCO/BTC', 'NANO/BTC', 'CELR/BTC', 'IOST/BTC', 'WAVES/BTC', 'VET/BTC', 'XLM/BTC', 'ZIL/BTC', 'NEO/BTC', 'ARN/BTC', 'FUEL/BTC', 'DGD/BTC']
2019-04-19 21:53:43,967 - freqtrade.freqtradebot - INFO - Found no buy signals for whitelisted currencies. Trying again..

And after this the bot try to buy another trade but not work because outdated wallet:

2019-04-20 00:30:03,067 - unknown - INFO - Searching pairs: ['ENJ/BTC', 'ETH/BTC', 'PHX/BTC', 'BCH/BTC', 'RVN/BTC', 'MITH/BTC', 'XRP/BTC', 'LTC/BTC', 'ADA/BTC', 'WTC/BTC', 'EOS/BTC', 'WABI/BTC', 'BAT/BTC', 'GTO/BTC', 'FET/BTC', 'TRX/BTC', 'NANO/BTC', 'QKC/BTC', 'MCO/BTC', 'EVX/BTC', 'IOST/BTC', 'CELR/BTC', 'WAVES/BTC', 'VET/BTC', 'XLM/BTC', 'ZIL/BTC', 'FUEL/BTC', 'BCPT/BTC', 'ARN/BTC', 'VIB/BTC']
2019-04-20 00:30:16,027 - freqtrade.freqtradebot - WARNING - Unable to create trade: Available balance(0.00021334 BTC) is lower than stake amount(0.003 BTC)

I think the Wallets need to be synced again after the trade is fullfilled, but this problem only happen with "sell signal" or "LIMIT_SELL". On sell reason "trailing_stop_loss" and "MARKET_SELL" this problem not happening. Log below with "trailing_stop_loss" and "MARKET_SELL":

2019-04-19 19:52:18,114 - freqtrade.freqtradebot - INFO - Using order book for selling...
2019-04-19 19:52:18,454 - freqtrade.freqtradebot - INFO -   order book asks top 1: 0.00091400
2019-04-19 19:52:19,464 - freqtrade.rpc.rpc_manager - INFO - Sending rpc message: {'type': sell, 'exchange': 'Binance', 'pair': 'MCO/BTC', 'gain': 'loss', 'limit': 0.000914, 'amount': 3.28, 'open_rate': 0.000914, 'current_rate': 0.000913, 'profit_amount': -6e-06, 'profit_percent': -0.001998, 'sell_reason': 'trailing_stop_loss', 'stake_currency': 'BTC', 'fiat_currency': 'BRL'}
2019-04-19 19:52:19,866 - freqtrade.freqtradebot - INFO - executed sell, reason: SellType.TRAILING_STOP_LOSS
2019-04-19 19:52:20,236 - freqtrade.wallets - INFO - Wallets synced.
2019-04-19 19:52:21,234 - freqtrade.wallets - INFO - Wallets synced.
2019-04-19 19:52:22,940 - unknown - INFO - Searching pairs: ['ETH/BTC', 'MITH/BTC', 'BCH/BTC', 'ENJ/BTC', 'PHX/BTC', 'RVN/BTC', 'XRP/BTC', 'ADA/BTC', 'LTC/BTC', 'EOS/BTC', 'WTC/BTC', 'WABI/BTC', 'GTO/BTC', 'BAT/BTC', 'FET/BTC', 'TRX/BTC', 'EVX/BTC', 'MCO/BTC', 'QKC/BTC', 'NANO/BTC', 'CELR/BTC', 'WAVES/BTC', 'VET/BTC', 'ZIL/BTC', 'XLM/BTC', 'IOST/BTC', 'DGD/BTC', 'NEO/BTC', 'ARN/BTC', 'FUEL/BTC']
2019-04-19 19:52:22,975 - freqtrade.freqtradebot - INFO - Found open order for Trade(id=3, pair=MCO/BTC, amount=3.28000000, open_rate=0.00091400, open_since=17 minutes ago)
2019-04-19 19:52:24,237 - freqtrade.persistence - INFO - Updating trade (id=3) ...
2019-04-19 19:52:24,239 - freqtrade.persistence - INFO - Marking Trade(id=3, pair=MCO/BTC, amount=3.28000000, open_rate=0.00091400, open_since=closed) as closed as the trade is fulfilled and found no open orders for it.
2019-04-19 19:52:24,241 - freqtrade.persistence - INFO - MARKET_SELL has been fulfilled for Trade(id=3, pair=MCO/BTC, amount=3.28000000, open_rate=0.00091400, open_since=closed).
2019-04-19 19:52:27,944 - unknown - INFO - Searching pairs: ['ETH/BTC', 'MITH/BTC', 'BCH/BTC', 'ENJ/BTC', 'PHX/BTC', 'RVN/BTC', 'XRP/BTC', 'ADA/BTC', 'LTC/BTC', 'EOS/BTC', 'WTC/BTC', 'WABI/BTC', 'GTO/BTC', 'BAT/BTC', 'FET/BTC', 'TRX/BTC', 'EVX/BTC', 'MCO/BTC', 'QKC/BTC', 'NANO/BTC', 'CELR/BTC', 'WAVES/BTC', 'VET/BTC', 'ZIL/BTC', 'XLM/BTC', 'IOST/BTC', 'DGD/BTC', 'NEO/BTC', 'ARN/BTC', 'FUEL/BTC']
2019-04-19 19:52:32,871 - freqtrade.freqtradebot - INFO - Found no buy signals for whitelisted currencies. Trying again..

And on "MARKET_SELL" the Wallet is synced before order is fullfilled too, same as "LIMIT_SELL", but seconds before, so the order can be fullfiled before finish Wallets Sync.

I don't know if problem is with Wallet Syncing before order fullfiled or the problem is with "LIMIT_SELL".

mishaker commented 5 years ago

I think you are right, the wallet should be synced again when an order is fulfilled.

natanbarbosa15 commented 5 years ago

I fixed the code by syncing wallets in "update_trade_state" method in "freqtradebot" class, in the code below:

def update_trade_state(self, trade, action_order: dict = None):
        """
        Checks trades with open orders and updates the amount if necessary
        """
        # Get order details for actual price per unit
        if trade.open_order_id:
            # Update trade with order values
            logger.info('Found open order for %s', trade)
            order = action_order or self.exchange.get_order(trade.open_order_id, trade.pair)
            # Try update amount (binance-fix)
            try:
                new_amount = self.get_real_amount(trade, order)
                if order['amount'] != new_amount:
                    order['amount'] = new_amount
                    # Fee was applied, so set to 0
                    trade.fee_open = 0

            except OperationalException as exception:
                logger.warning("Could not update trade amount: %s", exception)

            trade.update(order)

            # Updating wallets
            self.wallets.update()

This method can handle all sell and buy reasons with open trades, and with Wallet updated every time by adding "self.wallets.update()".

And i got this output in log with LIMIT_SELL:

2019-04-21 02:50:14,011 - freqtrade.freqtradebot - INFO - Using order book for selling...
2019-04-21 02:50:14,346 - freqtrade.freqtradebot - INFO -   order book asks top 1: 0.00003699
2019-04-21 02:50:15,362 - freqtrade.rpc.rpc_manager - INFO - Sending rpc message: {'type': sell, 'exchange': 'Binance', 'pair': 'ENJ/BTC', 'gain': 'profit', 'limit': 3.699e-05, 'amount': 82.0, 'open_rate': 3.653e-05, 'current_rate': 3.695e-05, 'profit_amount': 3.169e-05, 'profit_percent': 0.01056923, 'sell_reason': 'sell_signal', 'stake_currency': 'BTC', 'fiat_currency': 'BRL'}
2019-04-21 02:50:16,638 - freqtrade.freqtradebot - INFO - executed sell, reason: SellType.SELL_SIGNAL
2019-04-21 02:50:17,010 - freqtrade.wallets - INFO - Wallets synced.
2019-04-21 02:50:18,010 - freqtrade.wallets - INFO - Wallets synced.
2019-04-21 02:50:18,013 - unknown - INFO - Searching pairs: ['BAT/BTC', 'ETH/BTC', 'FET/BTC', 'ENJ/BTC', 'RVN/BTC', 'ADA/BTC', 'BCH/BTC', 'XRP/BTC', 'LTC/BTC', 'IOST/BTC', 'WTC/BTC', 'EOS/BTC', 'TRX/BTC', 'KNC/BTC', 'MITH/BTC', 'EVX/BTC', 'NANO/BTC', 'QKC/BTC', 'PHX/BTC', 'CELR/BTC', 'XMR/BTC', 'WABI/BTC', 'NEO/BTC', 'QLC/BTC', 'WAVES/BTC', 'XLM/BTC', 'VET/BTC', 'ENG/BTC', 'ZIL/BTC', 'ICX/BTC']
2019-04-21 02:50:22,241 - freqtrade.freqtradebot - INFO - Found open order for Trade(id=8, pair=ENJ/BTC, amount=82.00000000, open_rate=0.00003653, open_since=2 hours ago)
2019-04-21 02:50:23,495 - freqtrade.persistence - INFO - Updating trade (id=8) ...
2019-04-21 02:50:23,497 - freqtrade.persistence - INFO - Marking Trade(id=8, pair=ENJ/BTC, amount=82.00000000, open_rate=0.00003653, open_since=closed) as closed as the trade is fulfilled and found no open orders for it.
2019-04-21 02:50:23,498 - freqtrade.persistence - INFO - LIMIT_SELL has been fulfilled for Trade(id=8, pair=ENJ/BTC, amount=82.00000000, open_rate=0.00003653, open_since=closed).
2019-04-21 02:50:23,994 - freqtrade.wallets - INFO - Wallets synced.

And i got this output in log with MARKET_SELL:

2019-04-21 03:24:08,996 - freqtrade.freqtradebot - INFO - Using order book for selling...
2019-04-21 03:24:09,326 - freqtrade.freqtradebot - INFO -   order book asks top 1: 0.00048950
2019-04-21 03:24:10,348 - freqtrade.rpc.rpc_manager - INFO - Sending rpc message: {'type': sell, 'exchange': 'Binance', 'pair': 'WTC/BTC', 'gain': 'profit', 'limit': 0.0004895, 'amount': 6.15, 'open_rate': 0.0004873, 'current_rate': 0.0004893, 'profit_amount': 7.52e-06, 'profit_percent': 0.00250765, 'sell_reason': 'trailing_stop_loss', 'stake_currency': 'BTC', 'fiat_currency': 'BRL'}
2019-04-21 03:24:11,592 - freqtrade.freqtradebot - INFO - executed sell, reason: SellType.TRAILING_STOP_LOSS
2019-04-21 03:24:11,954 - freqtrade.wallets - INFO - Wallets synced.
2019-04-21 03:24:12,950 - freqtrade.wallets - INFO - Wallets synced.
2019-04-21 03:24:13,820 - unknown - INFO - Searching pairs: ['BAT/BTC', 'ETH/BTC', 'FET/BTC', 'ENJ/BTC', 'RVN/BTC', 'ADA/BTC', 'BCH/BTC', 'XRP/BTC', 'LTC/BTC', 'IOST/BTC', 'WTC/BTC', 'TRX/BTC', 'EOS/BTC', 'KNC/BTC', 'MITH/BTC', 'EVX/BTC', 'NANO/BTC', 'QKC/BTC', 'CELR/BTC', 'PHX/BTC', 'XMR/BTC', 'NEO/BTC', 'WABI/BTC', 'XLM/BTC', 'WAVES/BTC', 'QLC/BTC', 'VET/BTC', 'ZIL/BTC', 'ENG/BTC', 'ICX/BTC']
2019-04-21 03:24:13,850 - freqtrade.freqtradebot - INFO - Found open order for Trade(id=9, pair=WTC/BTC, amount=6.15000000, open_rate=0.00048730, open_since=33 minutes ago)
2019-04-21 03:24:14,714 - freqtrade.freqtradebot - WARNING - Amount 6.1499999999999995 does not match amount 6.15
2019-04-21 03:24:14,716 - freqtrade.freqtradebot - WARNING - Could not update trade amount: Half bought? Amounts don't match
2019-04-21 03:24:14,724 - freqtrade.persistence - INFO - Updating trade (id=9) ...
2019-04-21 03:24:14,726 - freqtrade.persistence - INFO - Marking Trade(id=9, pair=WTC/BTC, amount=6.15000000, open_rate=0.00048730, open_since=closed) as closed as the trade is fulfilled and found no open orders for it.
2019-04-21 03:24:14,728 - freqtrade.persistence - INFO - MARKET_SELL has been fulfilled for Trade(id=9, pair=WTC/BTC, amount=6.15000000, open_rate=0.00048730, open_since=closed).
2019-04-21 03:24:15,229 - freqtrade.wallets - INFO - Wallets synced.

No more Warnings received with this fix, and Wallets is always updated.

xmatthias commented 5 years ago

The problem is not sell-signal - but limit orders (therefore it doesn't impact market orders).

The fix you added is basically what i had in mind - would really appreciate if you could do a PR for it...... I'm just not certain if we should check if the trade was really closed before updating wallet or not.

The trade could still be open after calling trade.update() - and the same method is also used on "buy". Assuming a trade is "half-filled" - or still waiting for buyers - we would refresh the wallet once per trade per iteration - which could lead to bans in unfortunate scenarios.

xmatthias commented 5 years ago

This was fixed in #1787, therefore i'll close this.