diff --git a/lumibot/backtesting/backtesting_broker.py b/lumibot/backtesting/backtesting_broker.py index 82a6a8b37..78f7a495b 100644 --- a/lumibot/backtesting/backtesting_broker.py +++ b/lumibot/backtesting/backtesting_broker.py @@ -98,7 +98,7 @@ def _update_datetime(self, update_dt, cash=None, portfolio_value=None): self.data_source._update_datetime(new_datetime, cash=cash, portfolio_value=portfolio_value) if self.option_source: self.option_source._update_datetime(new_datetime, cash=cash, portfolio_value=portfolio_value) - logger.debug(f"Current backtesting datetime {self.datetime}") + logger.info(f"Current backtesting datetime {self.datetime}") # =========Clock functions===================== diff --git a/lumibot/strategies/_strategy.py b/lumibot/strategies/_strategy.py index 1888eed18..711657ef9 100644 --- a/lumibot/strategies/_strategy.py +++ b/lumibot/strategies/_strategy.py @@ -884,7 +884,7 @@ def run_backtest( save_logfile=False, use_quote_data=False, show_progress_bar=True, - quiet_logs=True, + quiet_logs=False, trader_class=Trader, **kwargs, ): @@ -1515,4 +1515,4 @@ def backtest( trader_class=trader_class, **kwargs, ) - return results \ No newline at end of file + return results diff --git a/lumibot/traders/trader.py b/lumibot/traders/trader.py index b079951b5..b0f066597 100644 --- a/lumibot/traders/trader.py +++ b/lumibot/traders/trader.py @@ -25,7 +25,7 @@ def __init__(self, logfile="", backtest=False, debug=False, strategies=None, qui strategies: list A list of strategies to run. If not specified, you must add strategies using trader.add_strategy(strategy) quiet_logs: bool - Whether to quiet noisy logs by setting the log level to ERROR. Defaults to True. + Whether to quiet backtest logs by setting the log level to ERROR. Defaults to False. """ # Check if the logfile is a valid path if logfile: @@ -35,8 +35,11 @@ def __init__(self, logfile="", backtest=False, debug=False, strategies=None, qui # Setting debug and _logfile parameters and setting global log format self.debug = debug self.backtest = backtest - self.log_format = logging.Formatter("%(asctime)s | %(name)s | %(levelname)s | %(message)s") - self.quiet_logs = quiet_logs + std_format = "%(asctime)s: %(levelname)s: %(message)s" + debug_format = "%(asctime)s: %(name)s: %(levelname)s: %(message)s" + log_format = std_format if not self.debug else debug_format + self.log_format = logging.Formatter(log_format) + self.quiet_logs = quiet_logs # Turns off all logging execpt for error messages in backtesting if logfile: self.logfile = Path(logfile) @@ -172,11 +175,6 @@ def _set_logger(self): logging.getLogger("apscheduler.scheduler").setLevel(logging.ERROR) logging.getLogger("apscheduler.executors.default").setLevel(logging.ERROR) logging.getLogger("lumibot.data_sources.yahoo_data").setLevel(logging.ERROR) - - if self.quiet_logs: - logging.getLogger("asyncio").setLevel(logging.ERROR) - logging.getLogger("lumibot.backtesting.backtesting_broker").setLevel(logging.ERROR) - logger = logging.getLogger() for handler in logger.handlers: @@ -189,12 +187,18 @@ def _set_logger(self): if self.debug: logger.setLevel(logging.DEBUG) - elif self.quiet_logs: - logger.setLevel(logging.ERROR) - for handler in logger.handlers: - if handler.__class__.__name__ == "StreamHandler": - handler.setLevel(logging.ERROR) + elif self.is_backtest_broker: + logger.setLevel(logging.INFO) + + # Quiet logs turns off all backtesting logging except for error messages + if self.quiet_logs: + logger.setLevel(logging.ERROR) + + # Ensure console has minimal logging to keep things clean during backtesting + stream_handler.setLevel(logging.ERROR) + else: + # Live trades should always have full logging. logger.setLevel(logging.INFO) # Setting file logging diff --git a/tests/test_logging.py b/tests/test_logging.py index c335ff697..b835548c0 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -13,52 +13,6 @@ def test_logging(self, caplog): logger.info("This is an info message") assert "This is an info message" in caplog.text - def test_backtest_produces_no_logs_by_default(self, caplog): - caplog.set_level(logging.INFO) - backtesting_start = datetime.datetime(2023, 1, 2) - backtesting_end = datetime.datetime(2023, 1, 4) - - LifecycleLogger.backtest( - YahooDataBacktesting, - backtesting_start, - backtesting_end, - parameters={"sleeptime": "1D", "market": "NYSE"}, - show_plot=False, - save_tearsheet=False, - show_tearsheet=False, - show_indicators=False, - save_logfile=False, - ) - # count that this contains 3 new lines. Its an easy proxy for the number of log messages and avoids - # the issue where the datetime is always gonna be different. - assert caplog.text.count("\n") == 3 - assert "Starting backtest...\n" in caplog.text - assert "Backtesting starting...\n" in caplog.text - assert "Backtesting finished\n" in caplog.text - - def test_run_backtest_produces_no_logs_by_default(self, caplog): - caplog.set_level(logging.INFO) - backtesting_start = datetime.datetime(2023, 1, 2) - backtesting_end = datetime.datetime(2023, 1, 4) - - LifecycleLogger.run_backtest( - YahooDataBacktesting, - backtesting_start, - backtesting_end, - parameters={"sleeptime": "1D", "market": "NYSE"}, - show_plot=False, - save_tearsheet=False, - show_tearsheet=False, - show_indicators=False, - save_logfile=False, - ) - # count that this contains 3 new lines. Its an easy proxy for the number of log messages and avoids - # the issue where the datetime is always gonna be different. - assert caplog.text.count("\n") == 3 - assert "Starting backtest...\n" in caplog.text - assert "Backtesting starting...\n" in caplog.text - assert "Backtesting finished\n" in caplog.text - def test_backtest_produces_no_logs_when_quiet_logs_is_true(self, caplog): caplog.set_level(logging.INFO) backtesting_start = datetime.datetime(2023, 1, 2) @@ -79,10 +33,11 @@ def test_backtest_produces_no_logs_when_quiet_logs_is_true(self, caplog): ) # count that this contains 3 new lines. Its an easy proxy for the number of log messages and avoids # the issue where the datetime is always gonna be different. - assert caplog.text.count("\n") == 3 + assert caplog.text.count("\n") == 4 assert "Starting backtest...\n" in caplog.text assert "Backtesting starting...\n" in caplog.text assert "Backtesting finished\n" in caplog.text + assert "Backtest took " in caplog.text def test_backtest_produces_logs_when_quiet_logs_is_false(self, caplog): caplog.set_level(logging.INFO) @@ -103,7 +58,7 @@ def test_backtest_produces_logs_when_quiet_logs_is_false(self, caplog): quiet_logs=False, ) - assert caplog.text.count("\n") == 9 + assert caplog.text.count("\n") >= 9 assert "Starting backtest...\n" in caplog.text assert "Backtesting starting...\n" in caplog.text assert "before_market_opens called\n" in caplog.text @@ -111,4 +66,4 @@ def test_backtest_produces_logs_when_quiet_logs_is_false(self, caplog): assert "on_trading_iteration called\n" in caplog.text assert "before_market_closes called\n" in caplog.text assert "after_market_closes called\n" in caplog.text - assert "Backtesting finished\n" in caplog.text \ No newline at end of file + assert "Backtesting finished\n" in caplog.text