Improve backtesting logs
This commit is contained in:
		| @@ -239,14 +239,16 @@ class Backtesting(object): | |||||||
|             stake_amount: float, max_open_trades: int) -> Optional[BacktestResult]: |             stake_amount: float, max_open_trades: int) -> Optional[BacktestResult]: | ||||||
|  |  | ||||||
|         trade = Trade( |         trade = Trade( | ||||||
|  |             pair=pair, | ||||||
|             open_rate=buy_row.open, |             open_rate=buy_row.open, | ||||||
|             open_date=buy_row.date, |             open_date=buy_row.date, | ||||||
|             stake_amount=stake_amount, |             stake_amount=stake_amount, | ||||||
|             amount=stake_amount / buy_row.open, |             amount=stake_amount / buy_row.open, | ||||||
|             fee_open=self.fee, |             fee_open=self.fee, | ||||||
|             fee_close=self.fee |             fee_close=self.fee, | ||||||
|  |             is_open=True, | ||||||
|         ) |         ) | ||||||
|  |         logger.debug(f"'{pair}' - Backtesting emulates creation of new trade: {trade}.") | ||||||
|         # calculate win/lose forwards from buy point |         # calculate win/lose forwards from buy point | ||||||
|         for sell_row in partial_ticker: |         for sell_row in partial_ticker: | ||||||
|             if max_open_trades > 0: |             if max_open_trades > 0: | ||||||
| @@ -289,7 +291,7 @@ class Backtesting(object): | |||||||
|         if partial_ticker: |         if partial_ticker: | ||||||
|             # no sell condition found - trade stil open at end of backtest period |             # no sell condition found - trade stil open at end of backtest period | ||||||
|             sell_row = partial_ticker[-1] |             sell_row = partial_ticker[-1] | ||||||
|             btr = BacktestResult(pair=pair, |             bt_res = BacktestResult(pair=pair, | ||||||
|                                     profit_percent=trade.calc_profit_percent(rate=sell_row.open), |                                     profit_percent=trade.calc_profit_percent(rate=sell_row.open), | ||||||
|                                     profit_abs=trade.calc_profit(rate=sell_row.open), |                                     profit_abs=trade.calc_profit(rate=sell_row.open), | ||||||
|                                     open_time=buy_row.date, |                                     open_time=buy_row.date, | ||||||
| @@ -303,9 +305,11 @@ class Backtesting(object): | |||||||
|                                     close_rate=sell_row.open, |                                     close_rate=sell_row.open, | ||||||
|                                     sell_reason=SellType.FORCE_SELL |                                     sell_reason=SellType.FORCE_SELL | ||||||
|                                     ) |                                     ) | ||||||
|             logger.debug('Force_selling still open trade %s with %s perc - %s', btr.pair, |             logger.debug(f"'{pair}' - Force selling still open trade, " | ||||||
|                          btr.profit_percent, btr.profit_abs) |                          f"profit percent: {bt_res.profit_percent}, " | ||||||
|             return btr |                          f"profit abs: {bt_res.profit_abs}") | ||||||
|  |  | ||||||
|  |             return bt_res | ||||||
|         return None |         return None | ||||||
|  |  | ||||||
|     def backtest(self, args: Dict) -> DataFrame: |     def backtest(self, args: Dict) -> DataFrame: | ||||||
| @@ -384,6 +388,8 @@ class Backtesting(object): | |||||||
|                                                          max_open_trades) |                                                          max_open_trades) | ||||||
|  |  | ||||||
|                 if trade_entry: |                 if trade_entry: | ||||||
|  |                     logger.debug(f"'{pair}' - Locking pair till " | ||||||
|  |                                  f"close_time={trade_entry.close_time}") | ||||||
|                     lock_pair_until[pair] = trade_entry.close_time |                     lock_pair_until[pair] = trade_entry.close_time | ||||||
|                     trades.append(trade_entry) |                     trades.append(trade_entry) | ||||||
|                 else: |                 else: | ||||||
|   | |||||||
| @@ -1,7 +1,6 @@ | |||||||
| """ | """ | ||||||
| This module contains the class to persist trades into SQLite | This module contains the class to persist trades into SQLite | ||||||
| """ | """ | ||||||
|  |  | ||||||
| import logging | import logging | ||||||
| from datetime import datetime | from datetime import datetime | ||||||
| from decimal import Decimal | from decimal import Decimal | ||||||
| @@ -19,8 +18,10 @@ from sqlalchemy.pool import StaticPool | |||||||
|  |  | ||||||
| from freqtrade import OperationalException | from freqtrade import OperationalException | ||||||
|  |  | ||||||
|  |  | ||||||
| logger = logging.getLogger(__name__) | logger = logging.getLogger(__name__) | ||||||
|  |  | ||||||
|  |  | ||||||
| _DECL_BASE: Any = declarative_base() | _DECL_BASE: Any = declarative_base() | ||||||
| _SQL_DOCS_URL = 'http://docs.sqlalchemy.org/en/latest/core/engines.html#database-urls' | _SQL_DOCS_URL = 'http://docs.sqlalchemy.org/en/latest/core/engines.html#database-urls' | ||||||
|  |  | ||||||
| @@ -209,7 +210,8 @@ class Trade(_DECL_BASE): | |||||||
|     ticker_interval = Column(Integer, nullable=True) |     ticker_interval = Column(Integer, nullable=True) | ||||||
|  |  | ||||||
|     def __repr__(self): |     def __repr__(self): | ||||||
|         open_since = arrow.get(self.open_date).humanize() if self.is_open else 'closed' |         open_since = (f"{arrow.get(self.open_date).strftime('%Y-%m-%d %H:%M:%S')} " | ||||||
|  |                      f"({arrow.get(self.open_date).humanize()})" ) if self.is_open else 'closed' | ||||||
|  |  | ||||||
|         return (f'Trade(id={self.id}, pair={self.pair}, amount={self.amount:.8f}, ' |         return (f'Trade(id={self.id}, pair={self.pair}, amount={self.amount:.8f}, ' | ||||||
|                 f'open_rate={self.open_rate:.8f}, open_since={open_since})') |                 f'open_rate={self.open_rate:.8f}, open_since={open_since})') | ||||||
| @@ -250,7 +252,6 @@ class Trade(_DECL_BASE): | |||||||
|         :param initial: Called to initiate stop_loss. |         :param initial: Called to initiate stop_loss. | ||||||
|             Skips everything if self.stop_loss is already set. |             Skips everything if self.stop_loss is already set. | ||||||
|         """ |         """ | ||||||
|  |  | ||||||
|         if initial and not (self.stop_loss is None or self.stop_loss == 0): |         if initial and not (self.stop_loss is None or self.stop_loss == 0): | ||||||
|             # Don't modify if called with initial and nothing to do |             # Don't modify if called with initial and nothing to do | ||||||
|             return |             return | ||||||
| @@ -259,7 +260,7 @@ class Trade(_DECL_BASE): | |||||||
|  |  | ||||||
|         # no stop loss assigned yet |         # no stop loss assigned yet | ||||||
|         if not self.stop_loss: |         if not self.stop_loss: | ||||||
|             logger.debug("assigning new stop loss") |             logger.debug(f"'{self.pair}' - Assigning new stoploss...") | ||||||
|             self.stop_loss = new_loss |             self.stop_loss = new_loss | ||||||
|             self.stop_loss_pct = -1 * abs(stoploss) |             self.stop_loss_pct = -1 * abs(stoploss) | ||||||
|             self.initial_stop_loss = new_loss |             self.initial_stop_loss = new_loss | ||||||
| @@ -269,21 +270,21 @@ class Trade(_DECL_BASE): | |||||||
|         # evaluate if the stop loss needs to be updated |         # evaluate if the stop loss needs to be updated | ||||||
|         else: |         else: | ||||||
|             if new_loss > self.stop_loss:  # stop losses only walk up, never down! |             if new_loss > self.stop_loss:  # stop losses only walk up, never down! | ||||||
|  |                 logger.debug(f"'{self.pair}' - Adjusting stoploss...") | ||||||
|                 self.stop_loss = new_loss |                 self.stop_loss = new_loss | ||||||
|                 self.stop_loss_pct = -1 * abs(stoploss) |                 self.stop_loss_pct = -1 * abs(stoploss) | ||||||
|                 self.stoploss_last_update = datetime.utcnow() |                 self.stoploss_last_update = datetime.utcnow() | ||||||
|                 logger.debug("adjusted stop loss") |  | ||||||
|             else: |             else: | ||||||
|                 logger.debug("keeping current stop loss") |                 logger.debug(f"'{self.pair}' - Keeping current stoploss...") | ||||||
|  |  | ||||||
|         logger.debug( |         logger.debug( | ||||||
|             f"{self.pair} - current price {current_price:.8f}, " |             f"'{self.pair}' - Stoploss adjusted. Current price {current_price:.8f}, " | ||||||
|             f"bought at {self.open_rate:.8f} and calculated " |             f"bought at {self.open_rate:.8f} and calculated " | ||||||
|             f"stop loss is at: {self.initial_stop_loss:.8f} initial " |             f"stoploss is at: {self.initial_stop_loss:.8f}, " | ||||||
|             f"stop at {self.stop_loss:.8f}. " |             f"initial stop at {self.stop_loss:.8f}. " | ||||||
|             f"trailing stop loss saved us: " |             f"Trailing stoploss saved us: " | ||||||
|             f"{float(self.stop_loss) - float(self.initial_stop_loss):.8f} " |             f"{float(self.stop_loss) - float(self.initial_stop_loss):.8f} " | ||||||
|             f"and max observed rate was {self.max_rate:.8f}") |             f"and max observed rate was {self.max_rate:.8f}.") | ||||||
|  |  | ||||||
|     def update(self, order: Dict) -> None: |     def update(self, order: Dict) -> None: | ||||||
|         """ |         """ | ||||||
| @@ -331,23 +332,18 @@ class Trade(_DECL_BASE): | |||||||
|             self |             self | ||||||
|         ) |         ) | ||||||
|  |  | ||||||
|     def calc_open_trade_price( |     def calc_open_trade_price(self, fee: Optional[float] = None) -> float: | ||||||
|             self, |  | ||||||
|             fee: Optional[float] = None) -> float: |  | ||||||
|         """ |         """ | ||||||
|         Calculate the open_rate including fee. |         Calculate the open_rate including fee. | ||||||
|         :param fee: fee to use on the open rate (optional). |         :param fee: fee to use on the open rate (optional). | ||||||
|         If rate is not set self.fee will be used |         If rate is not set self.fee will be used | ||||||
|         :return: Price in of the open trade incl. Fees |         :return: Price in of the open trade incl. Fees | ||||||
|         """ |         """ | ||||||
|  |  | ||||||
|         buy_trade = (Decimal(self.amount) * Decimal(self.open_rate)) |         buy_trade = (Decimal(self.amount) * Decimal(self.open_rate)) | ||||||
|         fees = buy_trade * Decimal(fee or self.fee_open) |         fees = buy_trade * Decimal(fee or self.fee_open) | ||||||
|         return float(buy_trade + fees) |         return float(buy_trade + fees) | ||||||
|  |  | ||||||
|     def calc_close_trade_price( |     def calc_close_trade_price(self, rate: Optional[float] = None, | ||||||
|             self, |  | ||||||
|             rate: Optional[float] = None, |  | ||||||
|                                fee: Optional[float] = None) -> float: |                                fee: Optional[float] = None) -> float: | ||||||
|         """ |         """ | ||||||
|         Calculate the close_rate including fee |         Calculate the close_rate including fee | ||||||
| @@ -357,7 +353,6 @@ class Trade(_DECL_BASE): | |||||||
|         If rate is not set self.close_rate will be used |         If rate is not set self.close_rate will be used | ||||||
|         :return: Price in BTC of the open trade |         :return: Price in BTC of the open trade | ||||||
|         """ |         """ | ||||||
|  |  | ||||||
|         if rate is None and not self.close_rate: |         if rate is None and not self.close_rate: | ||||||
|             return 0.0 |             return 0.0 | ||||||
|  |  | ||||||
| @@ -365,9 +360,7 @@ class Trade(_DECL_BASE): | |||||||
|         fees = sell_trade * Decimal(fee or self.fee_close) |         fees = sell_trade * Decimal(fee or self.fee_close) | ||||||
|         return float(sell_trade - fees) |         return float(sell_trade - fees) | ||||||
|  |  | ||||||
|     def calc_profit( |     def calc_profit(self, rate: Optional[float] = None, | ||||||
|             self, |  | ||||||
|             rate: Optional[float] = None, |  | ||||||
|                     fee: Optional[float] = None) -> float: |                     fee: Optional[float] = None) -> float: | ||||||
|         """ |         """ | ||||||
|         Calculate the absolute profit in stake currency between Close and Open trade |         Calculate the absolute profit in stake currency between Close and Open trade | ||||||
| @@ -385,9 +378,7 @@ class Trade(_DECL_BASE): | |||||||
|         profit = close_trade_price - open_trade_price |         profit = close_trade_price - open_trade_price | ||||||
|         return float(f"{profit:.8f}") |         return float(f"{profit:.8f}") | ||||||
|  |  | ||||||
|     def calc_profit_percent( |     def calc_profit_percent(self, rate: Optional[float] = None, | ||||||
|             self, |  | ||||||
|             rate: Optional[float] = None, |  | ||||||
|                             fee: Optional[float] = None) -> float: |                             fee: Optional[float] = None) -> float: | ||||||
|         """ |         """ | ||||||
|         Calculates the profit in percentage (including fee). |         Calculates the profit in percentage (including fee). | ||||||
| @@ -396,7 +387,6 @@ class Trade(_DECL_BASE): | |||||||
|         :param fee: fee to use on the close rate (optional). |         :param fee: fee to use on the close rate (optional). | ||||||
|         :return: profit in percentage as float |         :return: profit in percentage as float | ||||||
|         """ |         """ | ||||||
|  |  | ||||||
|         open_trade_price = self.calc_open_trade_price() |         open_trade_price = self.calc_open_trade_price() | ||||||
|         close_trade_price = self.calc_close_trade_price( |         close_trade_price = self.calc_close_trade_price( | ||||||
|             rate=(rate or self.close_rate), |             rate=(rate or self.close_rate), | ||||||
| @@ -436,8 +426,8 @@ class Trade(_DECL_BASE): | |||||||
|                and trade.initial_stop_loss_pct != desired_stoploss): |                and trade.initial_stop_loss_pct != desired_stoploss): | ||||||
|                 # Stoploss value got changed |                 # Stoploss value got changed | ||||||
|  |  | ||||||
|                 logger.info(f"Stoploss for {trade} needs adjustment.") |                 logger.info(f"Stoploss for {trade} needs adjustment...") | ||||||
|                 # Force reset of stoploss |                 # Force reset of stoploss | ||||||
|                 trade.stop_loss = None |                 trade.stop_loss = None | ||||||
|                 trade.adjust_stop_loss(trade.open_rate, desired_stoploss) |                 trade.adjust_stop_loss(trade.open_rate, desired_stoploss) | ||||||
|                 logger.info(f"new stoploss: {trade.stop_loss}, ") |                 logger.info(f"New stoploss: {trade.stop_loss}.") | ||||||
|   | |||||||
| @@ -202,7 +202,6 @@ class IStrategy(ABC): | |||||||
|         :param metadata: Metadata dictionary with additional data (e.g. 'pair') |         :param metadata: Metadata dictionary with additional data (e.g. 'pair') | ||||||
|         :return: DataFrame with ticker data and indicator data |         :return: DataFrame with ticker data and indicator data | ||||||
|         """ |         """ | ||||||
|  |  | ||||||
|         pair = str(metadata.get('pair')) |         pair = str(metadata.get('pair')) | ||||||
|  |  | ||||||
|         # Test if seen this pair and last candle before. |         # Test if seen this pair and last candle before. | ||||||
| @@ -292,7 +291,6 @@ class IStrategy(ABC): | |||||||
|         :param force_stoploss: Externally provided stoploss |         :param force_stoploss: Externally provided stoploss | ||||||
|         :return: True if trade should be sold, False otherwise |         :return: True if trade should be sold, False otherwise | ||||||
|         """ |         """ | ||||||
|  |  | ||||||
|         # Set current rate to low for backtesting sell |         # Set current rate to low for backtesting sell | ||||||
|         current_rate = low or rate |         current_rate = low or rate | ||||||
|         current_profit = trade.calc_profit_percent(current_rate) |         current_profit = trade.calc_profit_percent(current_rate) | ||||||
| @@ -304,6 +302,8 @@ class IStrategy(ABC): | |||||||
|                                               force_stoploss=force_stoploss, high=high) |                                               force_stoploss=force_stoploss, high=high) | ||||||
|  |  | ||||||
|         if stoplossflag.sell_flag: |         if stoplossflag.sell_flag: | ||||||
|  |             logger.debug(f"'{trade.pair}' - Stoploss hit. Selling " | ||||||
|  |                          f"(sell_type={stoplossflag.sell_type})...") | ||||||
|             return stoplossflag |             return stoplossflag | ||||||
|  |  | ||||||
|         # Set current rate to high for backtesting sell |         # Set current rate to high for backtesting sell | ||||||
| @@ -312,22 +312,30 @@ class IStrategy(ABC): | |||||||
|         experimental = self.config.get('experimental', {}) |         experimental = self.config.get('experimental', {}) | ||||||
|  |  | ||||||
|         if buy and experimental.get('ignore_roi_if_buy_signal', False): |         if buy and experimental.get('ignore_roi_if_buy_signal', False): | ||||||
|             logger.debug('Buy signal still active - not selling.') |             logger.debug(f"'{trade.pair}' - Buy signal still active. Not selling " | ||||||
|  |                          f"(sell_type=SellType.NONE)...") | ||||||
|             return SellCheckTuple(sell_flag=False, sell_type=SellType.NONE) |             return SellCheckTuple(sell_flag=False, sell_type=SellType.NONE) | ||||||
|  |  | ||||||
|         # Check if minimal roi has been reached and no longer in buy conditions (avoiding a fee) |         # Check if minimal roi has been reached and no longer in buy conditions (avoiding a fee) | ||||||
|         if self.min_roi_reached(trade=trade, current_profit=current_profit, current_time=date): |         if self.min_roi_reached(trade=trade, current_profit=current_profit, current_time=date): | ||||||
|             logger.debug('Required profit reached. Selling..') |             logger.debug(f"'{trade.pair}' - Required profit reached. Selling " | ||||||
|  |                          f"(sell_type=SellType.ROI)...") | ||||||
|             return SellCheckTuple(sell_flag=True, sell_type=SellType.ROI) |             return SellCheckTuple(sell_flag=True, sell_type=SellType.ROI) | ||||||
|  |  | ||||||
|         if experimental.get('sell_profit_only', False): |         if experimental.get('sell_profit_only', False): | ||||||
|             logger.debug('Checking if trade is profitable..') |             logger.debug(f"'{trade.pair}' - Checking if trade is profitable...") | ||||||
|             if trade.calc_profit(rate=rate) <= 0: |             if trade.calc_profit(rate=rate) <= 0: | ||||||
|  |                 logger.debug(f"'{trade.pair}' - Trade is not profitable. Not selling " | ||||||
|  |                              f"(sell_type=SellType.NONE)...") | ||||||
|                 return SellCheckTuple(sell_flag=False, sell_type=SellType.NONE) |                 return SellCheckTuple(sell_flag=False, sell_type=SellType.NONE) | ||||||
|  |  | ||||||
|         if sell and not buy and experimental.get('use_sell_signal', False): |         if sell and not buy and experimental.get('use_sell_signal', False): | ||||||
|             logger.debug('Sell signal received. Selling..') |             logger.debug(f"'{trade.pair}' - Sell signal received. Selling " | ||||||
|  |                          f"(sell_type=SellType.SELL_SIGNAL)...") | ||||||
|             return SellCheckTuple(sell_flag=True, sell_type=SellType.SELL_SIGNAL) |             return SellCheckTuple(sell_flag=True, sell_type=SellType.SELL_SIGNAL) | ||||||
|  |  | ||||||
|  |         # This one is noisy, commented out... | ||||||
|  | #        logger.debug(f"'{trade.pair}' - Not selling (sell_type=SellType.NONE)...") | ||||||
|         return SellCheckTuple(sell_flag=False, sell_type=SellType.NONE) |         return SellCheckTuple(sell_flag=False, sell_type=SellType.NONE) | ||||||
|  |  | ||||||
|     def stop_loss_reached(self, current_rate: float, trade: Trade, |     def stop_loss_reached(self, current_rate: float, trade: Trade, | ||||||
| @@ -338,7 +346,6 @@ class IStrategy(ABC): | |||||||
|         decides to sell or not |         decides to sell or not | ||||||
|         :param current_profit: current profit in percent |         :param current_profit: current profit in percent | ||||||
|         """ |         """ | ||||||
|  |  | ||||||
|         trailing_stop = self.config.get('trailing_stop', False) |         trailing_stop = self.config.get('trailing_stop', False) | ||||||
|         stop_loss_value = force_stoploss if force_stoploss else self.stoploss |         stop_loss_value = force_stoploss if force_stoploss else self.stoploss | ||||||
|  |  | ||||||
| @@ -359,7 +366,7 @@ class IStrategy(ABC): | |||||||
|                 if 'trailing_stop_positive' in self.config and high_profit > sl_offset: |                 if 'trailing_stop_positive' in self.config and high_profit > sl_offset: | ||||||
|                     # Ignore mypy error check in configuration that this is a float |                     # Ignore mypy error check in configuration that this is a float | ||||||
|                     stop_loss_value = self.config.get('trailing_stop_positive')  # type: ignore |                     stop_loss_value = self.config.get('trailing_stop_positive')  # type: ignore | ||||||
|                     logger.debug(f"using positive stop loss: {stop_loss_value} " |                     logger.debug(f"'{trade.pair}' - Using positive stoploss: {stop_loss_value} " | ||||||
|                                  f"offset: {sl_offset:.4g} profit: {current_profit:.4f}%") |                                  f"offset: {sl_offset:.4g} profit: {current_profit:.4f}%") | ||||||
|  |  | ||||||
|                 trade.adjust_stop_loss(high or current_rate, stop_loss_value) |                 trade.adjust_stop_loss(high or current_rate, stop_loss_value) | ||||||
| @@ -369,20 +376,20 @@ class IStrategy(ABC): | |||||||
|             (trade.stop_loss >= current_rate) and |             (trade.stop_loss >= current_rate) and | ||||||
|                 (not self.order_types.get('stoploss_on_exchange'))): |                 (not self.order_types.get('stoploss_on_exchange'))): | ||||||
|  |  | ||||||
|             selltype = SellType.STOP_LOSS |             sell_type = SellType.STOP_LOSS | ||||||
|  |  | ||||||
|             # If initial stoploss is not the same as current one then it is trailing. |             # If initial stoploss is not the same as current one then it is trailing. | ||||||
|             if trade.initial_stop_loss != trade.stop_loss: |             if trade.initial_stop_loss != trade.stop_loss: | ||||||
|                 selltype = SellType.TRAILING_STOP_LOSS |                 sell_type = SellType.TRAILING_STOP_LOSS | ||||||
|                 logger.debug( |                 logger.debug( | ||||||
|                     f"HIT STOP: current price at {current_rate:.6f}, " |                     f"'{trade.pair}' - HIT STOP: current price at {current_rate:.6f}, " | ||||||
|                     f"stoploss is {trade.stop_loss:.6f}, " |                     f"stoploss is {trade.stop_loss:.6f}, " | ||||||
|                     f"initial stoploss was at {trade.initial_stop_loss:.6f}, " |                     f"initial stoploss was at {trade.initial_stop_loss:.6f}, " | ||||||
|                     f"trade opened at {trade.open_rate:.6f}") |                     f"trade opened at {trade.open_rate:.6f}") | ||||||
|                 logger.debug(f"trailing stop saved {trade.stop_loss - trade.initial_stop_loss:.6f}") |                 logger.debug(f"'{trade.pair}' - Trailing stop saved " | ||||||
|  |                              f"{trade.stop_loss - trade.initial_stop_loss:.6f}") | ||||||
|  |  | ||||||
|             logger.debug('Stop loss hit.') |             return SellCheckTuple(sell_flag=True, sell_type=sell_type) | ||||||
|             return SellCheckTuple(sell_flag=True, sell_type=selltype) |  | ||||||
|  |  | ||||||
|         return SellCheckTuple(sell_flag=False, sell_type=SellType.NONE) |         return SellCheckTuple(sell_flag=False, sell_type=SellType.NONE) | ||||||
|  |  | ||||||
|   | |||||||
		Reference in New Issue
	
	Block a user