Merge pull request #887 from Lumiwealth/fix/backtest-datetime-normalization

Normalize datetime handling before backtests

Author: grzesir

lumibot/strategies/_strategy.py

@@ -1388,12 +1388,6 @@ def run_backtest(
         if use_other_option_source and not isinstance(optionsource_class, type):
             raise ValueError(f"`optionsource_class` must be a class. You passed in {optionsource_class}")
 
-        self.verify_backtest_inputs(backtesting_start, backtesting_end)
-
-        if not self.IS_BACKTESTABLE:
-            get_logger(__name__).warning(f"Strategy {name + ' ' if name is not None else ''}cannot be " f"backtested at the moment")
-            return None
-
         try:
             backtesting_start = to_datetime_aware(backtesting_start)
             backtesting_end = to_datetime_aware(backtesting_end)
@@ -1405,6 +1399,12 @@ def run_backtest(
             )
             return None
 
+        self.verify_backtest_inputs(backtesting_start, backtesting_end)
+
+        if not self.IS_BACKTESTABLE:
+            get_logger(__name__).warning(f"Strategy {name + ' ' if name is not None else ''}cannot be " f"backtested at the moment")
+            return None
+
         if BACKTESTING_QUIET_LOGS is not None:
             quiet_logs = BACKTESTING_QUIET_LOGS
 
@@ -1628,18 +1628,21 @@ def verify_backtest_inputs(cls, backtesting_start, backtesting_end):
         if not isinstance(backtesting_end, datetime.datetime):
             raise ValueError(f"`backtesting_end` must be a datetime object. You passed in {backtesting_end}")
 
+        start_dt = to_datetime_aware(backtesting_start)
+        end_dt = to_datetime_aware(backtesting_end)
+
         # Check that backtesting end is after backtesting start
-        if backtesting_end <= backtesting_start:
+        if end_dt <= start_dt:
             raise ValueError(
                 f"`backtesting_end` must be after `backtesting_start`. You passed in "
-                f"{backtesting_end} and {backtesting_start}"
+                f"{end_dt} and {start_dt}"
             )
 
         # Check that backtesting_end is not in the future
-        now = datetime.datetime.now(backtesting_end.tzinfo) if backtesting_end.tzinfo else datetime.datetime.now()
-        if backtesting_end > now:
+        now = datetime.datetime.now(end_dt.tzinfo) if end_dt.tzinfo else datetime.datetime.now()
+        if end_dt > now:
             raise ValueError(
-                f"`backtesting_end` cannot be in the future. You passed in {backtesting_end}, now is {now}"
+                f"`backtesting_end` cannot be in the future. You passed in {end_dt}, now is {now}"
             )
 
     def send_update_to_cloud(self):

lumibot/strategies/strategy_executor.py

@@ -13,8 +13,6 @@
 from apscheduler.jobstores.memory import MemoryJobStore
 from apscheduler.schedulers.background import BackgroundScheduler
 from apscheduler.triggers.cron import CronTrigger
-from termcolor import colored
-
 from lumibot.constants import LUMIBOT_DEFAULT_PYTZ
 from lumibot.entities import Asset, Order
 from lumibot.entities import Asset
@@ -1166,7 +1164,7 @@ def _strategy_sleep(self):
                 # For live trading, stop when market closes
                 return False
 
-        self.strategy.log_message(colored(f"Sleeping for {strategy_sleeptime} seconds", color="blue"))
+        self.strategy.logger.debug("Sleeping for %s seconds", strategy_sleeptime)
 
         # Run process orders at the market close time first (if not continuous market)
         if not is_continuous_market:

lumibot/tools/thetadata_helper.py

@@ -311,7 +311,13 @@ def get_price_data(
     )
 
     if cache_file.exists():
-        logger.info(f"\nLoading '{datastyle}' pricing data for {asset} / {quote_asset} with '{timespan}' timespan from cache file...")
+        logger.debug(
+            "\nLoading '%s' pricing data for %s / %s with '%s' timespan from cache file...",
+            datastyle,
+            asset,
+            quote_asset,
+            timespan,
+        )
         df_cached = load_cache(cache_file)
         if df_cached is not None and not df_cached.empty:
             df_all = df_cached.copy() # Make a copy so we can check the original later for differences
@@ -372,7 +378,7 @@ def get_price_data(
     )
     if not missing_dates:
         if df_all is not None and not df_all.empty:
-            logger.info("ThetaData cache HIT for %s %s %s (%d rows).", asset, timespan, datastyle, len(df_all))
+            logger.debug("ThetaData cache HIT for %s %s %s (%d rows).", asset, timespan, datastyle, len(df_all))
             # DEBUG-LOG: Cache hit
             logger.debug(
                 "[THETA][DEBUG][CACHE][HIT] asset=%s timespan=%s datastyle=%s rows=%d start=%s end=%s",

setup.py

@@ -5,7 +5,7 @@
 
 setuptools.setup(
     name="lumibot",
-    version="4.2.3",
+    version="4.2.4",
     author="Robert Grzesik",
     author_email="rob@lumiwealth.com",
     description="Backtesting and Trading Library, Made by Lumiwealth",

tests/test_backtesting_datetime_normalization.py

@@ -0,0 +1,90 @@
+import datetime
+from unittest.mock import patch
+
+import pytest
+
+from lumibot.strategies import Strategy
+from lumibot.strategies._strategy import _Strategy
+
+
+class MinimalStrategy(Strategy):
+    """No-op strategy used for backtest scaffolding."""
+
+    def initialize(self):
+        self.sleeptime = "1D"
+
+    def on_trading_iteration(self):
+        pass
+
+
+class DummyDataSource:
+    """Lightweight datasource stub capturing the start/end datetimes."""
+
+    SOURCE = "dummy"
+
+    def __init__(self, datetime_start=None, datetime_end=None, **kwargs):
+        self.datetime_start = datetime_start
+        self.datetime_end = datetime_end
+        self._data_store = {}
+
+
+class DummyTrader:
+    """Trader stub that records strategies and returns canned results."""
+
+    def __init__(self, *args, **kwargs):
+        self._strategies = []
+
+    def add_strategy(self, strategy):
+        self._strategies.append(strategy)
+
+    def run_all(self, **_kwargs):
+        return {strategy.name: {"dummy": True} for strategy in self._strategies}
+
+
+class _EarlyExit(Exception):
+    """Signal to stop run_backtest after the datasource is constructed."""
+
+
+def test_verify_backtest_inputs_accepts_mixed_timezones():
+    """Regression: verify_backtest_inputs must not crash on naive vs aware inputs."""
+    naive_start = datetime.datetime(2025, 1, 1)
+    aware_end = datetime.datetime(2025, 9, 30, tzinfo=datetime.timezone.utc)
+
+    # Should not raise
+    _Strategy.verify_backtest_inputs(naive_start, aware_end)
+
+
+def test_run_backtest_normalizes_mixed_timezones():
+    """Strategy.run_backtest should normalize naive/aware datetimes before validation."""
+    naive_start = datetime.datetime(2025, 1, 1)
+    aware_end = datetime.datetime(2025, 9, 30, tzinfo=datetime.timezone.utc)
+
+    captured = {}
+
+    class CapturingDataSource(DummyDataSource):
+        def __init__(self, datetime_start=None, datetime_end=None, **kwargs):
+            super().__init__(datetime_start=datetime_start, datetime_end=datetime_end, **kwargs)
+            captured["start"] = self.datetime_start
+            captured["end"] = self.datetime_end
+
+    def broker_factory(data_source, *args, **kwargs):
+        captured["data_source"] = data_source
+        raise _EarlyExit
+
+    with patch("lumibot.strategies._strategy.BacktestingBroker", side_effect=broker_factory), \
+         patch("lumibot.strategies._strategy.Trader", DummyTrader):
+        with pytest.raises(_EarlyExit):
+            MinimalStrategy.run_backtest(
+                CapturingDataSource,
+                backtesting_start=naive_start,
+                backtesting_end=aware_end,
+                show_plot=False,
+                show_tearsheet=False,
+                show_indicators=False,
+                show_progress_bar=False,
+                save_logfile=False,
+                save_stats_file=False,
+            )
+
+    assert "start" in captured and captured["start"].tzinfo is not None
+    assert "end" in captured and captured["end"].tzinfo is not None