So, im noticing my QCAlgorithm is take verry long to init for a backtest. Or at least thats what the logs are telling me.. Im running this on a Mabook M1 Max, and pulling 3 years of minute data. However, as you can see in the logs, it takes 8min to even start to run the Initialize function..

It looks like its doing some serious work to spool up the QCAlgorithm and im wondering what its doing and why? I cant see what amount of work should require this amount of time and computation, I mean this takes up around 70% of the total computation time of my algorithm. 

What can i do to reduce this significant overhead? 

 

Snippet of the start of the QCAlgorithm, this is before any of my code starts to run…. 

  1. class Algorithm(QCAlgorithm):
  2. def Initialize(self):
  3. self.Debug('!! STARTING QCAlgorithm !!')
  4. ...

 

And the logs, notice the timestamp from start till the “STARTING QCAlgorithm” log:

  1. 2024-06-05T10:18:11.7331387Z TRACE:: Engine.Main(): LEAN ALGORITHMIC TRADING ENGINE v2.5.0.0 Mode: DEBUG (64bit) Host: Nicks-MBP
  2. 2024-06-05T10:18:11.7360021Z TRACE:: Engine.Main(): Started 10:18 AM
  3. 2024-06-05T10:18:11.7408818Z TRACE:: Config.Get(): Configuration key not found. Key: lean-manager-type - Using default value: LocalLeanManager
  4. 2024-06-05T10:18:11.7538791Z TRACE:: JobQueue.NextJob(): Selected /LeanCLI/main.py
  5. 2024-06-05T10:18:11.7991597Z TRACE:: Config.GetValue(): scheduled-event-leaky-bucket-capacity - Using default value: 120
  6. 2024-06-05T10:18:11.7995320Z TRACE:: Config.GetValue(): scheduled-event-leaky-bucket-time-interval-minutes - Using default value: 1440
  7. 2024-06-05T10:18:11.8001345Z TRACE:: Config.GetValue(): scheduled-event-leaky-bucket-refill-amount - Using default value: 18
  8. 2024-06-05T10:18:11.8010785Z TRACE:: Config.GetValue(): storage-limit - Using default value: 10737418240
  9. 2024-06-05T10:18:11.8012984Z TRACE:: Config.GetValue(): storage-permissions - Using default value: 3
  10. 2024-06-05T10:18:11.8015027Z TRACE:: Config.Get(): Configuration key not found. Key: optimization-id - Using default value:
  11. 2024-06-05T10:18:11.8017297Z TRACE:: Config.Get(): Configuration key not found. Key: backtest-name - Using default value: local
  12. 2024-06-05T10:18:11.8031025Z TRACE:: Config.Get(): Configuration key not found. Key: data-channel - Using default value:
  13. 2024-06-05T10:18:11.8033547Z TRACE:: Config.Get(): Configuration key not found. Key: python-venv - Using default value:
  14. 2024-06-05T10:18:11.8035987Z TRACE:: Config.Get(): Configuration key not found. Key: out-of-sample-max-end-date - Using default value:
  15. 2024-06-05T10:18:11.8037973Z TRACE:: Config.GetValue(): out-of-sample-days - Using default value: 0
  16. 2024-06-05T10:18:11.8046617Z TRACE:: Config.Get(): Configuration key not found. Key: data-permission-manager - Using default value: DataPermissionManager
  17. 2024-06-05T10:18:11.8227957Z TRACE:: Config.GetValue(): zip-data-cache-provider - Using default value: 10
  18. 2024-06-05T10:18:11.8248271Z TRACE:: Config.Get(): Configuration key not found. Key: fundamental-data-provider - Using default value: CoarseFundamentalDataProvider
  19. 2024-06-05T10:18:11.8283000Z TRACE:: AlgorithmManager.CreateTokenBucket(): Initializing LeakyBucket: Capacity: 120 RefillAmount: 18 TimeInterval: 1440
  20. 2024-06-05T10:18:11.8290367Z TRACE:: Config.GetValue(): algorithm-manager-time-loop-maximum - Using default value: 20
  21. 2024-06-05T10:18:11.8407874Z TRACE:: Engine.Run(): Resource limits '0' CPUs. 2147483647 MB RAM.
  22. 2024-06-05T10:18:11.8417901Z TRACE:: TextSubscriptionDataSourceReader.SetCacheSize(): Setting cache size to 71582788 items
  23. 2024-06-05T10:18:11.8757568Z TRACE:: Config.GetValue(): downloader-data-update-period - Using default value: 7
  24. 2024-06-05T10:18:12.1592147Z TRACE:: Config.GetValue(): algorithm-creation-timeout - Using default value: 90
  25. 2024-06-05T10:18:12.1610056Z TRACE:: PythonInitializer.Initialize(): start...
  26. 2024-06-05T10:18:12.8989352Z TRACE:: PythonInitializer.Initialize(): ended
  27. 2024-06-05T10:18:12.9001878Z TRACE:: AlgorithmPythonWrapper(): Python version 3.11.8 | packaged by conda-forge | (main, Feb 16 2024, 20:39:38) [GCC 12.3.0]: Importing python module main
  28. 2024-06-05T10:18:15.9321830Z TRACE:: AlgorithmPythonWrapper(): main successfully imported.
  29. 2024-06-05T10:18:15.9333594Z TRACE:: AlgorithmPythonWrapper(): Creating IAlgorithm instance.
  30. 2024-06-05T10:18:16.0078509Z TRACE:: Config.GetValue(): mute-python-library-logging - Using default value: True
  31. 2024-06-05T10:18:16.0095393Z TRACE:: LocalObjectStore.Initialize(): Storage Root: /Storage. StorageFileCount 9999999. StorageLimit 10240MB
  32. 2024-06-05T10:18:16.0139510Z TRACE:: Config.GetValue(): zip-data-cache-provider - Using default value: 10
  33. 2024-06-05T10:18:16.0190366Z TRACE:: HistoryProviderManager.Initialize(): history providers [SubscriptionDataReaderHistoryProvider]
  34. 2024-06-05T10:18:16.0203435Z TRACE:: BacktestingSetupHandler.Setup(): Setting up job: UID: 275814, PID: 0, Version: 2.5.0.0, Source: WebIDE
  35. 2024-06-05T10:18:16.0243732Z TRACE:: Config.Get(): Configuration key not found. Key: security-data-feeds - Using default value:
  36. 2024-06-05T10:18:16.0362156Z TRACE:: SecurityPortfolioManager.SetAccountCurrency(): setting account currency to USDT
  37. 2024-06-05T10:18:16.0459516Z TRACE:: Config.Get(): Configuration key not found. Key: reserved-words-prefix - Using default value: @
  38. 2024-06-05T10:18:16.2066269Z TRACE:: Config.GetValue(): data-feed-workers-count - Using default value: 10
  39. 2024-06-05T10:18:16.2086538Z TRACE:: Config.GetValue(): data-feed-max-work-weight - Using default value: 400
  40. 2024-06-05T10:18:16.2088863Z TRACE:: WeightedWorkScheduler(): will use 10 workers and MaxWorkWeight is 400
  41. 2024-06-05T10:19:16.1136068Z TRACE:: Isolator.ExecuteWithTimeLimit(): Used: 1089, Sample: 1092, App: 4950, CurrentTimeStepElapsed: 00:00.000. CPU: 101%
  42. 2024-06-05T10:19:17.6867145Z TRACE:: Event Name "Training: Now: 2023-08-14T00:00:00.0000000Z", scheduled to run.
  43. 2024-06-05T10:19:17.7416744Z TRACE:: BaseSetupHandler.SetupCurrencyConversions():
  44. Account Type: Margin
  45. Symbol Quantity Conversion = Value in USDT
  46. USDT: 10000.00 @ 1.00 = 10000
  47. USD: $ 0.00 @ 1.00 = 0
  48. BTC: 0.00 @ 29293.30 = 0.0
  49. -------------------------------------------------
  50. CashBook Total Value: 10000.0
  51. 2024-06-05T10:19:17.7430493Z TRACE:: Total margin information: TotalMarginUsed: 0.00, MarginRemaining: 10000.00
  52. 2024-06-05T10:19:17.7438259Z TRACE:: SetUp Backtesting: User: 275814 ProjectId: 0 AlgoId: 1922862025
  53. 2024-06-05T10:19:17.7446366Z TRACE:: Dates: Start: 08/14/2023 End: 10/19/2023 Cash: ¤10,000.00 MaximumRuntime: 100.00:00:00 MaxOrders: 2147483647
  54. 2024-06-05T10:19:17.7463985Z TRACE:: BacktestingResultHandler(): Sample Period Set: 24.12
  55. 2024-06-05T10:19:17.7471504Z TRACE:: Config.GetValue(): forward-console-messages - Using default value: True
  56. 2024-06-05T10:19:17.7476460Z TRACE:: JOB HANDLERS:
  57. DataFeed: QuantConnect.Lean.Engine.DataFeeds.FileSystemDataFeed
  58. Setup: QuantConnect.Lean.Engine.Setup.BacktestingSetupHandler
  59. RealTime: QuantConnect.Lean.Engine.RealTime.BacktestingRealTimeHandler
  60. Results: QuantConnect.Lean.Engine.Results.BacktestingResultHandler
  61. Transactions: QuantConnect.Lean.Engine.TransactionHandlers.BacktestingTransactionHandler
  62. Object Store: QuantConnect.Lean.Engine.Storage.LocalObjectStore
  63. History Provider: QuantConnect.Lean.Engine.HistoricalData.HistoryProviderManager
  64. Brokerage: QuantConnect.Brokerages.Backtesting.BacktestingBrokerage
  65. Data Provider: QuantConnect.Lean.Engine.DataFeeds.DefaultDataProvider
  66. 2024-06-05T10:19:17.7697602Z TRACE:: Event Name "Daily Sampling", scheduled to run.
  67. 2024-06-05T10:19:17.7705703Z TRACE:: AlgorithmManager.Run(): Begin DataStream - Start: 8/14/2023 12:00:00 AM Stop: 10/19/2023 11:59:59 PM Time: 8/14/2023 12:00:00 AM Warmup: False
  68. 2024-06-05T10:19:17.8074014Z TRACE:: UniverseSelection.AddPendingInternalDataFeeds(): Adding internal benchmark data feed BTCUSDT,#0,BTCUSDT,Hour,TradeBar,Trade,Adjusted,OpenInterest,Internal
  69. 2024-06-05T10:19:17.8129128Z TRACE:: Debug: Launching analysis for 1922862025 with LEAN Engine v2.5.0.0
  70. 2024-06-05T10:20:17.8536165Z TRACE:: Isolator.ExecuteWithTimeLimit(): Used: 958, Sample: 1531, App: 6192, CurrentTimeStepElapsed: 00:58.089. CPU: 230%
  71. 2024-06-05T10:20:18.0325015Z TRACE:: LeakyBucket.TryConsume(1): Successfully consumed tokens. Available: 119
  72. 2024-06-05T10:21:17.8818183Z TRACE:: LeakyBucket.TryConsume(1): Successfully consumed tokens. Available: 118
  73. 2024-06-05T10:21:18.4167744Z TRACE:: Isolator.ExecuteWithTimeLimit(): Used: 1322, Sample: 1531, App: 6292, CurrentTimeStepElapsed: 01:58.652. CPU: 227%
  74. 2024-06-05T10:22:18.0319385Z TRACE:: LeakyBucket.TryConsume(1): Successfully consumed tokens. Available: 117
  75. 2024-06-05T10:22:18.4819859Z TRACE:: Isolator.ExecuteWithTimeLimit(): Used: 1455, Sample: 1531, App: 6326, CurrentTimeStepElapsed: 02:58.718. CPU: 229%
  76. 2024-06-05T10:23:17.8833913Z TRACE:: LeakyBucket.TryConsume(1): Successfully consumed tokens. Available: 116
  77. 2024-06-05T10:23:18.5446680Z TRACE:: Isolator.ExecuteWithTimeLimit(): Used: 1503, Sample: 1531, App: 6361, CurrentTimeStepElapsed: 03:58.780. CPU: 234%
  78. 2024-06-05T10:24:18.0426491Z TRACE:: LeakyBucket.TryConsume(1): Successfully consumed tokens. Available: 115
  79. 2024-06-05T10:24:18.6082266Z TRACE:: Isolator.ExecuteWithTimeLimit(): Used: 1521, Sample: 1531, App: 6380, CurrentTimeStepElapsed: 04:58.844. CPU: 248%
  80. 2024-06-05T10:25:17.8997984Z TRACE:: LeakyBucket.TryConsume(1): Successfully consumed tokens. Available: 114
  81. 2024-06-05T10:25:18.6736093Z TRACE:: Isolator.ExecuteWithTimeLimit(): Used: 1528, Sample: 1532, App: 6377, CurrentTimeStepElapsed: 05:58.909. CPU: 234%
  82. 2024-06-05T10:26:18.0388527Z TRACE:: LeakyBucket.TryConsume(1): Successfully consumed tokens. Available: 113
  83. 2024-06-05T10:26:18.7359449Z TRACE:: Isolator.ExecuteWithTimeLimit(): Used: 1530, Sample: 1532, App: 6392, CurrentTimeStepElapsed: 06:58.971. CPU: 310%
  84. 2024-06-05T10:26:19.9147910Z TRACE:: Debug: !! STARTING QCAlgorithm !!
  85. 2024-06-05T10:26:19.9150695Z TRACE:: Debug: Changing account currency from USD to USDT...
+ Expand

 

 

 

Author

Nick Grobler

June 2024