Skip to content

Commit

Permalink
Improve backtesting logs
Browse files Browse the repository at this point in the history
  • Loading branch information
hroff-1902 committed Sep 10, 2019
1 parent f987e6e commit 35580b1
Show file tree
Hide file tree
Showing 3 changed files with 69 additions and 66 deletions.
44 changes: 25 additions & 19 deletions freqtrade/optimize/backtesting.py
Original file line number Diff line number Diff line change
Expand Up @@ -239,14 +239,16 @@ def _get_sell_trade_entry(
stake_amount: float, max_open_trades: int) -> Optional[BacktestResult]:

trade = Trade(
pair=pair,
open_rate=buy_row.open,
open_date=buy_row.date,
stake_amount=stake_amount,
amount=stake_amount / buy_row.open,
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
for sell_row in partial_ticker:
if max_open_trades > 0:
Expand Down Expand Up @@ -289,23 +291,25 @@ def _get_sell_trade_entry(
if partial_ticker:
# no sell condition found - trade stil open at end of backtest period
sell_row = partial_ticker[-1]
btr = BacktestResult(pair=pair,
profit_percent=trade.calc_profit_percent(rate=sell_row.open),
profit_abs=trade.calc_profit(rate=sell_row.open),
open_time=buy_row.date,
close_time=sell_row.date,
trade_duration=int((
sell_row.date - buy_row.date).total_seconds() // 60),
open_index=buy_row.Index,
close_index=sell_row.Index,
open_at_end=True,
open_rate=buy_row.open,
close_rate=sell_row.open,
sell_reason=SellType.FORCE_SELL
)
logger.debug('Force_selling still open trade %s with %s perc - %s', btr.pair,
btr.profit_percent, btr.profit_abs)
return btr
bt_res = BacktestResult(pair=pair,
profit_percent=trade.calc_profit_percent(rate=sell_row.open),
profit_abs=trade.calc_profit(rate=sell_row.open),
open_time=buy_row.date,
close_time=sell_row.date,
trade_duration=int((
sell_row.date - buy_row.date).total_seconds() // 60),
open_index=buy_row.Index,
close_index=sell_row.Index,
open_at_end=True,
open_rate=buy_row.open,
close_rate=sell_row.open,
sell_reason=SellType.FORCE_SELL
)
logger.debug(f"'{pair}' - Force selling still open trade, "
f"profit percent: {bt_res.profit_percent}, "
f"profit abs: {bt_res.profit_abs}")

return bt_res
return None

def backtest(self, args: Dict) -> DataFrame:
Expand Down Expand Up @@ -384,6 +388,8 @@ def backtest(self, args: Dict) -> DataFrame:
max_open_trades)

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
trades.append(trade_entry)
else:
Expand Down
52 changes: 21 additions & 31 deletions freqtrade/persistence.py
Original file line number Diff line number Diff line change
@@ -1,7 +1,6 @@
"""
This module contains the class to persist trades into SQLite
"""

import logging
from datetime import datetime
from decimal import Decimal
Expand All @@ -19,8 +18,10 @@

from freqtrade import OperationalException


logger = logging.getLogger(__name__)


_DECL_BASE: Any = declarative_base()
_SQL_DOCS_URL = 'http://docs.sqlalchemy.org/en/latest/core/engines.html#database-urls'

Expand Down Expand Up @@ -209,7 +210,8 @@ class Trade(_DECL_BASE):
ticker_interval = Column(Integer, nullable=True)

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}, '
f'open_rate={self.open_rate:.8f}, open_since={open_since})')
Expand Down Expand Up @@ -250,7 +252,6 @@ def adjust_stop_loss(self, current_price: float, stoploss: float, initial: bool
:param initial: Called to initiate stop_loss.
Skips everything if self.stop_loss is already set.
"""

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
return
Expand All @@ -259,7 +260,7 @@ def adjust_stop_loss(self, current_price: float, stoploss: float, initial: bool

# no stop loss assigned yet
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_pct = -1 * abs(stoploss)
self.initial_stop_loss = new_loss
Expand All @@ -269,21 +270,21 @@ def adjust_stop_loss(self, current_price: float, stoploss: float, initial: bool
# evaluate if the stop loss needs to be updated
else:
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_pct = -1 * abs(stoploss)
self.stoploss_last_update = datetime.utcnow()
logger.debug("adjusted stop loss")
else:
logger.debug("keeping current stop loss")
logger.debug(f"'{self.pair}' - Keeping current stoploss...")

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"stop loss is at: {self.initial_stop_loss:.8f} initial "
f"stop at {self.stop_loss:.8f}. "
f"trailing stop loss saved us: "
f"stoploss is at: {self.initial_stop_loss:.8f}, "
f"initial stop at {self.stop_loss:.8f}. "
f"Trailing stoploss saved us: "
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:
"""
Expand Down Expand Up @@ -331,24 +332,19 @@ def close(self, rate: float) -> None:
self
)

def calc_open_trade_price(
self,
fee: Optional[float] = None) -> float:
def calc_open_trade_price(self, fee: Optional[float] = None) -> float:
"""
Calculate the open_rate including fee.
:param fee: fee to use on the open rate (optional).
If rate is not set self.fee will be used
:return: Price in of the open trade incl. Fees
"""

buy_trade = (Decimal(self.amount) * Decimal(self.open_rate))
fees = buy_trade * Decimal(fee or self.fee_open)
return float(buy_trade + fees)

def calc_close_trade_price(
self,
rate: Optional[float] = None,
fee: Optional[float] = None) -> float:
def calc_close_trade_price(self, rate: Optional[float] = None,
fee: Optional[float] = None) -> float:
"""
Calculate the close_rate including fee
:param fee: fee to use on the close rate (optional).
Expand All @@ -357,18 +353,15 @@ def calc_close_trade_price(
If rate is not set self.close_rate will be used
:return: Price in BTC of the open trade
"""

if rate is None and not self.close_rate:
return 0.0

sell_trade = (Decimal(self.amount) * Decimal(rate or self.close_rate))
fees = sell_trade * Decimal(fee or self.fee_close)
return float(sell_trade - fees)

def calc_profit(
self,
rate: Optional[float] = None,
fee: Optional[float] = None) -> float:
def calc_profit(self, rate: Optional[float] = None,
fee: Optional[float] = None) -> float:
"""
Calculate the absolute profit in stake currency between Close and Open trade
:param fee: fee to use on the close rate (optional).
Expand All @@ -385,18 +378,15 @@ def calc_profit(
profit = close_trade_price - open_trade_price
return float(f"{profit:.8f}")

def calc_profit_percent(
self,
rate: Optional[float] = None,
fee: Optional[float] = None) -> float:
def calc_profit_percent(self, rate: Optional[float] = None,
fee: Optional[float] = None) -> float:
"""
Calculates the profit in percentage (including fee).
:param rate: rate to compare with (optional).
If rate is not set self.close_rate will be used
:param fee: fee to use on the close rate (optional).
:return: profit in percentage as float
"""

open_trade_price = self.calc_open_trade_price()
close_trade_price = self.calc_close_trade_price(
rate=(rate or self.close_rate),
Expand Down Expand Up @@ -436,8 +426,8 @@ def stoploss_reinitialization(desired_stoploss):
and trade.initial_stop_loss_pct != desired_stoploss):
# Stoploss value got changed

logger.info(f"Stoploss for {trade} needs adjustment.")
logger.info(f"Stoploss for {trade} needs adjustment...")
# Force reset of stoploss
trade.stop_loss = None
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}.")
39 changes: 23 additions & 16 deletions freqtrade/strategy/interface.py
Original file line number Diff line number Diff line change
Expand Up @@ -202,7 +202,6 @@ def _analyze_ticker_internal(self, dataframe: DataFrame, metadata: dict) -> Data
:param metadata: Metadata dictionary with additional data (e.g. 'pair')
:return: DataFrame with ticker data and indicator data
"""

pair = str(metadata.get('pair'))

# Test if seen this pair and last candle before.
Expand Down Expand Up @@ -292,7 +291,6 @@ def should_sell(self, trade: Trade, rate: float, date: datetime, buy: bool,
:param force_stoploss: Externally provided stoploss
:return: True if trade should be sold, False otherwise
"""

# Set current rate to low for backtesting sell
current_rate = low or rate
current_profit = trade.calc_profit_percent(current_rate)
Expand All @@ -304,6 +302,8 @@ def should_sell(self, trade: Trade, rate: float, date: datetime, buy: bool,
force_stoploss=force_stoploss, high=high)

if stoplossflag.sell_flag:
logger.debug(f"'{trade.pair}' - Stoploss hit. Selling "
f"(sell_type={stoplossflag.sell_type})...")
return stoplossflag

# Set current rate to high for backtesting sell
Expand All @@ -312,22 +312,30 @@ def should_sell(self, trade: Trade, rate: float, date: datetime, buy: bool,
experimental = self.config.get('experimental', {})

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)

# 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):
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)

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:
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)

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)

# 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)

def stop_loss_reached(self, current_rate: float, trade: Trade,
Expand All @@ -338,7 +346,6 @@ def stop_loss_reached(self, current_rate: float, trade: Trade,
decides to sell or not
:param current_profit: current profit in percent
"""

trailing_stop = self.config.get('trailing_stop', False)
stop_loss_value = force_stoploss if force_stoploss else self.stoploss

Expand All @@ -359,7 +366,7 @@ def stop_loss_reached(self, current_rate: float, trade: Trade,
if 'trailing_stop_positive' in self.config and high_profit > sl_offset:
# Ignore mypy error check in configuration that this is a float
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}%")

trade.adjust_stop_loss(high or current_rate, stop_loss_value)
Expand All @@ -369,20 +376,20 @@ def stop_loss_reached(self, current_rate: float, trade: Trade,
(trade.stop_loss >= current_rate) and
(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 trade.initial_stop_loss != trade.stop_loss:
selltype = SellType.TRAILING_STOP_LOSS
sell_type = SellType.TRAILING_STOP_LOSS
logger.debug(
f"HIT STOP: current price at {current_rate:.6f}, "
f"stop loss is {trade.stop_loss:.6f}, "
f"initial stop loss was at {trade.initial_stop_loss:.6f}, "
f"'{trade.pair}' - HIT STOP: current price at {current_rate:.6f}, "
f"stoploss is {trade.stop_loss:.6f}, "
f"initial stoploss was at {trade.initial_stop_loss:.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=selltype)
return SellCheckTuple(sell_flag=True, sell_type=sell_type)

return SellCheckTuple(sell_flag=False, sell_type=SellType.NONE)

Expand Down

0 comments on commit 35580b1

Please sign in to comment.