History database collection from IBKR stalls on head timestamps

Technical Help
#1

Hi Brian,

I update my IBKR history databases each afternoon, and some days (not all), the collection stalls indefinitely. The log update looks like this:

    quantrocket_history_1|┌──────────────────────────────────┐
    quantrocket_history_1|│ ibkr-daily-db processing stages: │
    quantrocket_history_1|│ head timestamps            84    │
    quantrocket_history_1|│ historical data             0    │
    quantrocket_history_1|│ waiting for responses       0    │
    quantrocket_history_1|│ bar processing              0    │
    quantrocket_history_1|│ database storage            0    │
    quantrocket_history_1|│ completed                9922    │
    quantrocket_history_1|└──────────────────────────────────┘
    quantrocket_history_1|┌────────────────────────────────────────────────┐
    quantrocket_history_1|│ ibkr-daily-db completion report:               │
    quantrocket_history_1|│ successful completions                    9454 │
    quantrocket_history_1|│ data unavailable                           468 │
    quantrocket_history_1|│ partial completions before no response       0 │
    quantrocket_history_1|│ no permission                                0 │
    quantrocket_history_1|│ security not found (error 200)               2 │
    quantrocket_history_1|│ head timestamp errors/timeouts               0 │
    quantrocket_history_1|└────────────────────────────────────────────────┘

It looks like the routine is stuck on processing head timestamps? This process isn't described in the docs - would appreciate any tips on how to prevent the stall from happening (as it cascades and prevents other cron jobs from executing in the history container).

#2

What was happening in the logs before it stalled?

#3

I couldn't capture any other details before what I posted, since the process had been stalling for so long - just the same update boxes every few minutes.

During the update, I glanced at the line by line responses for each IBKR call. Nothing that looked like an error, but I didn't watch the whole update. I'll grep for 'head timestamp' during the next update and report back.

EDIT: I forgot I could just download the log file. Below is the history container activity right before the stall begins. Happy to upload the entire log file of the update if needed, but this forum tool only allows uploads of images.

2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - ┌──────────────────────────────────┐
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - │ ibkr-daily-db processing stages: │
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - │ head timestamps            84    │
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - │ historical data            19    │
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - │ waiting for responses       5    │
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - │ bar processing              0    │
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - │ database storage            0    │
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - │ completed                9898    │
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - └──────────────────────────────────┘
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - ┌────────────────────────────────────────────────┐
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - │ ibkr-daily-db completion report:               │
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - │ successful completions                    9430 │
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - │ data unavailable                           468 │
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - │ partial completions before no response       0 │
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - │ no permission                                0 │
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - │ security not found (error 200)               2 │
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - │ head timestamp errors/timeouts               0 │
2021-08-23 14:49:15 PDT| <14>1 2021-08-23T21:49:15Z 99829619269b quantrocket_history_1 8006 - - └────────────────────────────────────────────────┘
2021-08-23 14:49:16 PDT| <14>1 2021-08-23T21:49:16Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg1 historical data request for 33 Y of 1 day ADJUSTED_LAST for MHF STK (sid FIBBG000BBQ9P7) ending now
2021-08-23 14:49:18 PDT| <14>1 2021-08-23T21:49:18Z 99829619269b quantrocket_history_1 8006 - - ┌───────────────────────────────────────┐
2021-08-23 14:49:18 PDT| <14>1 2021-08-23T21:49:18Z 99829619269b quantrocket_history_1 8006 - - │ ibkr-daily-db IBKR response times:    │
2021-08-23 14:49:18 PDT| <14>1 2021-08-23T21:49:18Z 99829619269b quantrocket_history_1 8006 - - │           all    ibg3    ibg4    ibg1 │
2021-08-23 14:49:18 PDT| <14>1 2021-08-23T21:49:18Z 99829619269b quantrocket_history_1 8006 - - │ count  9636.0  3273.0  3154.0  3209.0 │
2021-08-23 14:49:18 PDT| <14>1 2021-08-23T21:49:18Z 99829619269b quantrocket_history_1 8006 - - │ mean      0.1     0.1     0.1     0.1 │
2021-08-23 14:49:18 PDT| <14>1 2021-08-23T21:49:18Z 99829619269b quantrocket_history_1 8006 - - │ std       0.9     0.8     1.0     0.9 │
2021-08-23 14:49:18 PDT| <14>1 2021-08-23T21:49:18Z 99829619269b quantrocket_history_1 8006 - - │ min       0.0     0.0     0.1     0.1 │
2021-08-23 14:49:18 PDT| <14>1 2021-08-23T21:49:18Z 99829619269b quantrocket_history_1 8006 - - │ 25%       0.1     0.1     0.1     0.1 │
2021-08-23 14:49:18 PDT| <14>1 2021-08-23T21:49:18Z 99829619269b quantrocket_history_1 8006 - - │ 50%       0.1     0.1     0.1     0.1 │
2021-08-23 14:49:18 PDT| <14>1 2021-08-23T21:49:18Z 99829619269b quantrocket_history_1 8006 - - │ 75%       0.1     0.1     0.1     0.1 │
2021-08-23 14:49:18 PDT| <14>1 2021-08-23T21:49:18Z 99829619269b quantrocket_history_1 8006 - - │ max      36.7    29.7    36.7    30.4 │
2021-08-23 14:49:18 PDT| <14>1 2021-08-23T21:49:18Z 99829619269b quantrocket_history_1 8006 - - └───────────────────────────────────────┘
2021-08-23 14:49:40 PDT| <14>1 2021-08-23T21:49:40Z 99829619269b quantrocket_history_1 8006 - - Processing 6991 raw bars from IBKR for HIO STK (sid FIBBG000BLHMB1)
2021-08-23 14:49:40 PDT| <14>1 2021-08-23T21:49:40Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg3 historical data request for 30 Y of 1 day ADJUSTED_LAST for MMU STK (sid FIBBG000BC1FN0) ending now
2021-08-23 14:49:40 PDT| <14>1 2021-08-23T21:49:40Z 99829619269b quantrocket_history_1 8006 - - Saving 6991 historical bars for 1 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:49:46 PDT| <14>1 2021-08-23T21:49:46Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg4 historical data request for 29 Y of 1 day ADJUSTED_LAST for MNP STK (sid FIBBG000BDNFK7) ending now
2021-08-23 14:49:46 PDT| <14>1 2021-08-23T21:49:46Z 99829619269b quantrocket_history_1 8006 - - Processing 5851 raw bars from IBKR for HIX STK (sid FIBBG000BP8B71)
2021-08-23 14:49:46 PDT| <14>1 2021-08-23T21:49:46Z 99829619269b quantrocket_history_1 8006 - - Processing 2723 raw bars from IBKR for HYI STK (sid FIBBG000BG4925)
2021-08-23 14:49:46 PDT| <14>1 2021-08-23T21:49:46Z 99829619269b quantrocket_history_1 8006 - - Saving 5851 historical bars for 1 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:49:46 PDT| <14>1 2021-08-23T21:49:46Z 99829619269b quantrocket_history_1 8006 - - Processing 3060 raw bars from IBKR for IGI STK (sid FIBBG000J3NX77)
2021-08-23 14:49:47 PDT| <14>1 2021-08-23T21:49:47Z 99829619269b quantrocket_history_1 8006 - - Processing 152 raw bars from IBKR for LANDM STK (sid FIBBG00YVVGVL3)
2021-08-23 14:49:48 PDT| <14>1 2021-08-23T21:49:48Z 99829619269b quantrocket_history_1 8006 - - Saving 5935 historical bars for 3 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:49:57 PDT| <14>1 2021-08-23T21:49:57Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg3 historical data request for 16 Y of 1 day ADJUSTED_LAST for NHF STK (sid FIBBG000ND9C36) ending now
2021-08-23 14:49:58 PDT| <14>1 2021-08-23T21:49:58Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg4 historical data request for 3 Y of 1 day ADJUSTED_LAST for OCCIP STK (sid FIBBG00NNR38S3) ending now
2021-08-23 14:49:59 PDT| <14>1 2021-08-23T21:49:59Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg4 historical data request for 42 Y of 1 day ADJUSTED_LAST for PAI STK (sid FIBBG000BQR5D4) ending now
2021-08-23 14:50:06 PDT| <14>1 2021-08-23T21:50:06Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg1 historical data request for 22 Y of 1 day ADJUSTED_LAST for PFD STK (sid FIBBG000BDMG71) ending now
2021-08-23 14:50:06 PDT| <14>1 2021-08-23T21:50:06Z 99829619269b quantrocket_history_1 8006 - - Processing 8252 raw bars from IBKR for MHF STK (sid FIBBG000BBQ9P7)
2021-08-23 14:50:06 PDT| <14>1 2021-08-23T21:50:06Z 99829619269b quantrocket_history_1 8006 - - Processing 7329 raw bars from IBKR for MMU STK (sid FIBBG000BC1FN0)
2021-08-23 14:50:06 PDT| <14>1 2021-08-23T21:50:06Z 99829619269b quantrocket_history_1 8006 - - Saving 8252 historical bars for 1 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:50:06 PDT| <14>1 2021-08-23T21:50:06Z 99829619269b quantrocket_history_1 8006 - - Processing 7117 raw bars from IBKR for MNP STK (sid FIBBG000BDNFK7)
2021-08-23 14:50:08 PDT| <14>1 2021-08-23T21:50:08Z 99829619269b quantrocket_history_1 8006 - - Saving 14446 historical bars for 2 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:50:12 PDT| <14>1 2021-08-23T21:50:12Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg1 historical data request for 30 Y of 1 day ADJUSTED_LAST for PFO STK (sid FIBBG000BG13Q5) ending now
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - ┌──────────────────────────────────┐
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - │ ibkr-daily-db processing stages: │
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - │ head timestamps            84    │
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - │ historical data            11    │
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - │ waiting for responses       5    │
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - │ bar processing              0    │
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - │ database storage            0    │
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - │ completed                9906    │
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - └──────────────────────────────────┘
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - ┌────────────────────────────────────────────────┐
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - │ ibkr-daily-db completion report:               │
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - │ successful completions                    9438 │
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - │ data unavailable                           468 │
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - │ partial completions before no response       0 │
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - │ no permission                                0 │
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - │ security not found (error 200)               2 │
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - │ head timestamp errors/timeouts               0 │
2021-08-23 14:50:16 PDT| <14>1 2021-08-23T21:50:16Z 99829619269b quantrocket_history_1 8006 - - └────────────────────────────────────────────────┘
2021-08-23 14:50:29 PDT| <14>1 2021-08-23T21:50:29Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg1 historical data request for 34 Y of 1 day ADJUSTED_LAST for PIM STK (sid FIBBG000BR6QG6) ending now
2021-08-23 14:50:39 PDT| <14>1 2021-08-23T21:50:39Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg3 historical data request for 33 Y of 1 day ADJUSTED_LAST for PMM STK (sid FIBBG000C14561) ending now
2021-08-23 14:50:39 PDT| <14>1 2021-08-23T21:50:39Z 99829619269b quantrocket_history_1 8006 - - Processing 3815 raw bars from IBKR for NHF STK (sid FIBBG000ND9C36)
2021-08-23 14:50:39 PDT| <14>1 2021-08-23T21:50:39Z 99829619269b quantrocket_history_1 8006 - - Processing 610 raw bars from IBKR for OCCIP STK (sid FIBBG00NNR38S3)
2021-08-23 14:50:39 PDT| <14>1 2021-08-23T21:50:39Z 99829619269b quantrocket_history_1 8006 - - Saving 3815 historical bars for 1 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:50:40 PDT| <14>1 2021-08-23T21:50:40Z 99829619269b quantrocket_history_1 8006 - - Saving 610 historical bars for 1 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:50:48 PDT| <14>1 2021-08-23T21:50:48Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg4 historical data request for 29 Y of 1 day ADJUSTED_LAST for PMO STK (sid FIBBG000BHDPQ1) ending now
2021-08-23 14:50:49 PDT| <14>1 2021-08-23T21:50:49Z 99829619269b quantrocket_history_1 8006 - - Processing 10430 raw bars from IBKR for PAI STK (sid FIBBG000BQR5D4)
2021-08-23 14:50:49 PDT| <14>1 2021-08-23T21:50:49Z 99829619269b quantrocket_history_1 8006 - - Processing 5530 raw bars from IBKR for PFD STK (sid FIBBG000BDMG71)
2021-08-23 14:50:49 PDT| <14>1 2021-08-23T21:50:49Z 99829619269b quantrocket_history_1 8006 - - Saving 10430 historical bars for 1 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:50:49 PDT| <14>1 2021-08-23T21:50:49Z 99829619269b quantrocket_history_1 8006 - - Processing 7439 raw bars from IBKR for PFO STK (sid FIBBG000BG13Q5)
2021-08-23 14:50:50 PDT| <14>1 2021-08-23T21:50:50Z 99829619269b quantrocket_history_1 8006 - - Saving 12969 historical bars for 2 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:50:53 PDT| <14>1 2021-08-23T21:50:53Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg3 historical data request for 34 Y of 1 day ADJUSTED_LAST for PPT STK (sid FIBBG000BRK0T3) ending now
2021-08-23 14:51:05 PDT| <14>1 2021-08-23T21:51:05Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg4 historical data request for 30 Y of 1 day ADJUSTED_LAST for SBI STK (sid FIBBG000BSY105) ending now
2021-08-23 14:51:08 PDT| <14>1 2021-08-23T21:51:08Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg1 historical data request for 3 Y of 1 day ADJUSTED_LAST for TEAF STK (sid FIBBG00NPWMLR1) ending now
2021-08-23 14:51:08 PDT| <14>1 2021-08-23T21:51:08Z 99829619269b quantrocket_history_1 8006 - - Processing 8399 raw bars from IBKR for PIM STK (sid FIBBG000BR6QG6)
2021-08-23 14:51:08 PDT| <14>1 2021-08-23T21:51:08Z 99829619269b quantrocket_history_1 8006 - - Processing 8190 raw bars from IBKR for PMM STK (sid FIBBG000C14561)
2021-08-23 14:51:08 PDT| <14>1 2021-08-23T21:51:08Z 99829619269b quantrocket_history_1 8006 - - Saving 8399 historical bars for 1 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:51:09 PDT| <14>1 2021-08-23T21:51:09Z 99829619269b quantrocket_history_1 8006 - - Processing 7113 raw bars from IBKR for PMO STK (sid FIBBG000BHDPQ1)
2021-08-23 14:51:10 PDT| <14>1 2021-08-23T21:51:10Z 99829619269b quantrocket_history_1 8006 - - Saving 15303 historical bars for 2 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:51:10 PDT| <14>1 2021-08-23T21:51:10Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg1 historical data request for 13 Y of 1 day ADJUSTED_LAST for TPZ STK (sid FIBBG000Q9RX90) ending now
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - ┌──────────────────────────────────┐
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - │ ibkr-daily-db processing stages: │
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - │ head timestamps            84    │
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - │ historical data             4    │
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - │ waiting for responses       4    │
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - │ bar processing              0    │
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - │ database storage            0    │
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - │ completed                9914    │
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - └──────────────────────────────────┘
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - ┌────────────────────────────────────────────────┐
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - │ ibkr-daily-db completion report:               │
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - │ successful completions                    9446 │
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - │ data unavailable                           468 │
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - │ partial completions before no response       0 │
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - │ no permission                                0 │
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - │ security not found (error 200)               2 │
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - │ head timestamp errors/timeouts               0 │
2021-08-23 14:51:16 PDT| <14>1 2021-08-23T21:51:16Z 99829619269b quantrocket_history_1 8006 - - └────────────────────────────────────────────────┘
2021-08-23 14:51:17 PDT| <14>1 2021-08-23T21:51:17Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg1 historical data request for 62 D of 1 day ADJUSTED_LAST for WDI STK (sid FIBBG00WF4D4T0) ending now
2021-08-23 14:51:17 PDT| <14>1 2021-08-23T21:51:17Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg1 historical data request for 20 Y of 1 day ADJUSTED_LAST for WEA STK (sid FIBBG000BPYDK3) ending now
2021-08-23 14:51:35 PDT| <14>1 2021-08-23T21:51:35Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg1 historical data request for 18 Y of 1 day ADJUSTED_LAST for WIA STK (sid FIBBG000BRVNX6) ending now
2021-08-23 14:51:40 PDT| <14>1 2021-08-23T21:51:40Z 99829619269b quantrocket_history_1 8006 - - Issuing to ibg3 historical data request for 18 Y of 1 day ADJUSTED_LAST for WIW STK (sid FIBBG000BSK789) ending now
2021-08-23 14:51:40 PDT| <14>1 2021-08-23T21:51:40Z 99829619269b quantrocket_history_1 8006 - - Processing 8443 raw bars from IBKR for PPT STK (sid FIBBG000BRK0T3)
2021-08-23 14:51:40 PDT| <14>1 2021-08-23T21:51:40Z 99829619269b quantrocket_history_1 8006 - - Saving 8443 historical bars for 1 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:51:47 PDT| <14>1 2021-08-23T21:51:47Z 99829619269b quantrocket_history_1 8006 - - Processing 7362 raw bars from IBKR for SBI STK (sid FIBBG000BSY105)
2021-08-23 14:51:47 PDT| <14>1 2021-08-23T21:51:47Z 99829619269b quantrocket_history_1 8006 - - Processing 608 raw bars from IBKR for TEAF STK (sid FIBBG00NPWMLR1)
2021-08-23 14:51:47 PDT| <14>1 2021-08-23T21:51:47Z 99829619269b quantrocket_history_1 8006 - - Saving 7362 historical bars for 1 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:51:47 PDT| <14>1 2021-08-23T21:51:47Z 99829619269b quantrocket_history_1 8006 - - Processing 3039 raw bars from IBKR for TPZ STK (sid FIBBG000Q9RX90)
2021-08-23 14:51:47 PDT| <14>1 2021-08-23T21:51:47Z 99829619269b quantrocket_history_1 8006 - - Processing 41 raw bars from IBKR for WDI STK (sid FIBBG00WF4D4T0)
2021-08-23 14:51:47 PDT| <14>1 2021-08-23T21:51:47Z 99829619269b quantrocket_history_1 8006 - - Processing 4886 raw bars from IBKR for WEA STK (sid FIBBG000BPYDK3)
2021-08-23 14:51:49 PDT| <14>1 2021-08-23T21:51:49Z 99829619269b quantrocket_history_1 8006 - - Saving 8574 historical bars for 4 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:52:06 PDT| <14>1 2021-08-23T21:52:06Z 99829619269b quantrocket_history_1 8006 - - Processing 4506 raw bars from IBKR for WIA STK (sid FIBBG000BRVNX6)
2021-08-23 14:52:06 PDT| <14>1 2021-08-23T21:52:06Z 99829619269b quantrocket_history_1 8006 - - Processing 4403 raw bars from IBKR for WIW STK (sid FIBBG000BSK789)
2021-08-23 14:52:06 PDT| <14>1 2021-08-23T21:52:06Z 99829619269b quantrocket_history_1 8006 - - Saving 4506 historical bars for 1 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:52:07 PDT| <14>1 2021-08-23T21:52:07Z 99829619269b quantrocket_history_1 8006 - - Saving 4403 historical bars for 1 securities to quantrocket.v2.history.ibkr-daily-db.sqlite
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - ┌──────────────────────────────────┐
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - │ ibkr-daily-db processing stages: │
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - │ head timestamps            84    │
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - │ historical data             0    │
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - │ waiting for responses       0    │
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - │ bar processing              0    │
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - │ database storage            0    │
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - │ completed                9922    │
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - └──────────────────────────────────┘
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - ┌────────────────────────────────────────────────┐
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - │ ibkr-daily-db completion report:               │
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - │ successful completions                    9454 │
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - │ data unavailable                           468 │
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - │ partial completions before no response       0 │
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - │ no permission                                0 │
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - │ security not found (error 200)               2 │
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - │ head timestamp errors/timeouts               0 │
2021-08-23 14:52:16 PDT| <14>1 2021-08-23T21:52:16Z 99829619269b quantrocket_history_1 8006 - - └────────────────────────────────────────────────┘
2021-08-23 14:52:19 PDT| <14>1 2021-08-23T21:52:19Z 99829619269b quantrocket_history_1 8006 - - ┌───────────────────────────────────────┐
2021-08-23 14:52:19 PDT| <14>1 2021-08-23T21:52:19Z 99829619269b quantrocket_history_1 8006 - - │ ibkr-daily-db IBKR response times:    │
2021-08-23 14:52:19 PDT| <14>1 2021-08-23T21:52:19Z 99829619269b quantrocket_history_1 8006 - - │           all    ibg3    ibg4    ibg1 │
2021-08-23 14:52:19 PDT| <14>1 2021-08-23T21:52:19Z 99829619269b quantrocket_history_1 8006 - - │ count  9657.0  3279.0  3160.0  3218.0 │
2021-08-23 14:52:19 PDT| <14>1 2021-08-23T21:52:19Z 99829619269b quantrocket_history_1 8006 - - │ mean      0.2     0.2     0.2     0.2 │
2021-08-23 14:52:19 PDT| <14>1 2021-08-23T21:52:19Z 99829619269b quantrocket_history_1 8006 - - │ std       1.6     1.6     1.7     1.6 │
2021-08-23 14:52:19 PDT| <14>1 2021-08-23T21:52:19Z 99829619269b quantrocket_history_1 8006 - - │ min       0.0     0.0     0.1     0.1 │
2021-08-23 14:52:19 PDT| <14>1 2021-08-23T21:52:19Z 99829619269b quantrocket_history_1 8006 - - │ 25%       0.1     0.1     0.1     0.1 │
2021-08-23 14:52:19 PDT| <14>1 2021-08-23T21:52:19Z 99829619269b quantrocket_history_1 8006 - - │ 50%       0.1     0.1     0.1     0.1 │
2021-08-23 14:52:19 PDT| <14>1 2021-08-23T21:52:19Z 99829619269b quantrocket_history_1 8006 - - │ 75%       0.1     0.1     0.1     0.1 │
2021-08-23 14:52:19 PDT| <14>1 2021-08-23T21:52:19Z 99829619269b quantrocket_history_1 8006 - - │ max      49.7    48.3    49.7    49.7 │
2021-08-23 14:52:19 PDT| <14>1 2021-08-23T21:52:19Z 99829619269b quantrocket_history_1 8006 - - └───────────────────────────────────────┘
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - ┌──────────────────────────────────┐
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - │ ibkr-daily-db processing stages: │
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - │ head timestamps            84    │
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - │ historical data             0    │
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - │ waiting for responses       0    │
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - │ bar processing              0    │
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - │ database storage            0    │
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - │ completed                9922    │
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - └──────────────────────────────────┘
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - ┌────────────────────────────────────────────────┐
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - │ ibkr-daily-db completion report:               │
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - │ successful completions                    9454 │
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - │ data unavailable                           468 │
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - │ partial completions before no response       0 │
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - │ no permission                                0 │
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - │ security not found (error 200)               2 │
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - │ head timestamp errors/timeouts               0 │
2021-08-23 14:53:16 PDT| <14>1 2021-08-23T21:53:16Z 99829619269b quantrocket_history_1 8006 - - └────────────────────────────────────────────────┘
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - ┌──────────────────────────────────┐
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - │ ibkr-daily-db processing stages: │
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - │ head timestamps            84    │
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - │ historical data             0    │
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - │ waiting for responses       0    │
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - │ bar processing              0    │
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - │ database storage            0    │
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - │ completed                9922    │
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - └──────────────────────────────────┘
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - ┌────────────────────────────────────────────────┐
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - │ ibkr-daily-db completion report:               │
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - │ successful completions                    9454 │
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - │ data unavailable                           468 │
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - │ partial completions before no response       0 │
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - │ no permission                                0 │
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - │ security not found (error 200)               2 │
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - │ head timestamp errors/timeouts               0 │
2021-08-23 14:54:16 PDT| <14>1 2021-08-23T21:54:16Z 99829619269b quantrocket_history_1 8006 - - └────────────────────────────────────────────────┘
#4

What’s further back in the logs related to head timestamps?

The implication of your logs is perhaps that there is no head timestamp worker to handle the requests in the queue, so they’re just sitting there. But I can’t reproduce this and I don’t know why that would happen or why it would happen to you with some frequency and not to anyone else. If the head timestamp worker died for some reason, there should be a traceback in the detailed logs, and it should bubble up to the main thread and also get logged in the standard logs.

#5

I haven't seen anything in the logs related to workers dying - which container would the worker log message come from?

In other operations when workers have died unexpectedly, it's been memory issues. I'm running 16GB on an EC2 instance, so not sure why memory would be constrained, but I'll look for it next time it happens. For now, I've fixed by scheduling a collection cancel after the expected collection time, to ensure that other cron jobs continue.

#6

Still seeing this head timestamp error on some days without any sign of workers dying. Below is a longer log which might shed some light. The number of head timestamps to process actually goes to 0 (at 2021-09-21 14:17:23 PDT), before going back up to 2 (2021-09-21 14:18:24 PDT), where it stalls indefinitely.

Between these two status updates, the container prints Saving 2897846 historical bars for 2055 securities to quantrocket.v2.history.ibkr-minute-db.sqlite (at 2021-09-21 14:17:46 PDT).

Perhaps the workers expired or were killed when head timestamps hit 0, so that none existed to handle the two cases that were added back at the end?

2021-09-21 14:17:22 PDT| <14>1 2021-09-21T21:17:22Z 99829619269b quantrocket_history_1 4923 - - Processing 1209 raw bars from IBKR for VFMV STK (sid FIBBG00K26BWT5)
2021-09-21 14:17:22 PDT| <14>1 2021-09-21T21:17:22Z 99829619269b quantrocket_history_1 4923 - - Processing 1857 raw bars from IBKR for VFQY STK (sid FIBBG00K269MY4)
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - Processing 1912 raw bars from IBKR for VFVA STK (sid FIBBG00K26B596)
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VG STK (sid FIBBG000BRB5D9)
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VGI STK (sid FIBBG002293GD0)
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VGII STK (sid FIBBG010S20KT7)
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - Processing 993 raw bars from IBKR for VGII U STK (sid FIBBG00Z8MST65)
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VGIT STK (sid FIBBG000PX0963)
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - ┌───────────────────────────────────┐
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - │ ibkr-minute-db processing stages: │
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - │ head timestamps             0     │
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - │ historical data             0     │
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - │ waiting for responses       0     │
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - │ bar processing            613     │
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - │ database storage         1933     │
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - │ completed                7347     │
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - └───────────────────────────────────┘
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - ┌────────────────────────────────────────────────┐
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - │ ibkr-minute-db completion report:              │
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - │ successful completions                    6937 │
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - │ data unavailable                           409 │
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - │ partial completions before no response       2 │
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - │ no permission                                0 │
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - │ security not found (error 200)               6 │
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - │ head timestamp errors/timeouts               0 │
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - └────────────────────────────────────────────────┘
2021-09-21 14:17:23 PDT| <14>1 2021-09-21T21:17:23Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VGK STK (sid FIBBG000HT8SM3)
2021-09-21 14:17:24 PDT| <14>1 2021-09-21T21:17:24Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VGLT STK (sid FIBBG000PX0M82)
2021-09-21 14:17:24 PDT| <14>1 2021-09-21T21:17:24Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VGM STK (sid FIBBG000CQLM15)
2021-09-21 14:17:24 PDT| <14>1 2021-09-21T21:17:24Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VGR STK (sid FIBBG000CXKKZ8)
2021-09-21 14:17:24 PDT| <14>1 2021-09-21T21:17:24Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VGSH STK (sid FIBBG000PWZXV6)
2021-09-21 14:17:24 PDT| <14>1 2021-09-21T21:17:24Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VGT STK (sid FIBBG000HSZQ76)
2021-09-21 14:17:24 PDT| <14>1 2021-09-21T21:17:24Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VGZ STK (sid FIBBG000F2BG19)
2021-09-21 14:17:24 PDT| <14>1 2021-09-21T21:17:24Z 99829619269b quantrocket_history_1 4923 - - Processing 1152 raw bars from IBKR for VHAQ STK (sid FIBBG00Z3YMM47)
...
...
2021-09-21 14:17:42 PDT| <14>1 2021-09-21T21:17:42Z 99829619269b quantrocket_history_1 4923 - - Processing 1924 raw bars from IBKR for VPCB STK (sid FIBBG00Z1H93Z9)
2021-09-21 14:17:43 PDT| <14>1 2021-09-21T21:17:43Z 99829619269b quantrocket_history_1 4923 - - Processing 1094 raw bars from IBKR for VPCBU STK (sid FIBBG00Z0HRMW1)
2021-09-21 14:17:43 PDT| <14>1 2021-09-21T21:17:43Z 99829619269b quantrocket_history_1 4923 - - Processing 1897 raw bars from IBKR for VPCC STK (sid FIBBG00Z483VQ0)
2021-09-21 14:17:44 PDT| <14>1 2021-09-21T21:17:44Z 99829619269b quantrocket_history_1 4923 - - Processing 1350 raw bars from IBKR for VPCC U STK (sid FIBBG00Z3KTLD2)
2021-09-21 14:17:46 PDT| <14>1 2021-09-21T21:17:46Z 99829619269b quantrocket_history_1 4923 - - Saving 2897846 historical bars for 2055 securities to quantrocket.v2.history.ibkr-minute-db.sqlite
2021-09-21 14:17:46 PDT| <14>1 2021-09-21T21:17:46Z 99829619269b quantrocket_history_1 4923 - - Processing 1944 raw bars from IBKR for VPG STK (sid FIBBG000PRQ0V9)
2021-09-21 14:17:47 PDT| <14>1 2021-09-21T21:17:47Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VPL STK (sid FIBBG000HTCFY3)
2021-09-21 14:17:47 PDT| <14>1 2021-09-21T21:17:47Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VPN STK (sid FIBBG00Y056CB8)
2021-09-21 14:17:47 PDT| <14>1 2021-09-21T21:17:47Z 99829619269b quantrocket_history_1 4923 - - Processing 1567 raw bars from IBKR for VPOP STK (sid FIBBG00YPSWSF3)
...
...
2021-09-21 14:18:23 PDT| <14>1 2021-09-21T21:18:23Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VVPR STK (sid FIBBG00FNFTYM7)
2021-09-21 14:18:23 PDT| <14>1 2021-09-21T21:18:23Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VVR STK (sid FIBBG000BS65V3)
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VVV STK (sid FIBBG003DNHV56)
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VWE STK (sid FIBBG00QQFW1Z4)
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - ┌───────────────────────────────────┐
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - │ ibkr-minute-db processing stages: │
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - │ head timestamps             2     │
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - │ historical data             0     │
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - │ waiting for responses       0     │
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - │ bar processing            413     │
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - │ database storage         2133     │
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - │ completed                7347     │
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - └───────────────────────────────────┘
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - ┌────────────────────────────────────────────────┐
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - │ ibkr-minute-db completion report:              │
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - │ successful completions                    6937 │
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - │ data unavailable                           409 │
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - │ partial completions before no response       2 │
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - │ no permission                                0 │
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - │ security not found (error 200)               6 │
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - │ head timestamp errors/timeouts               0 │
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - └────────────────────────────────────────────────┘
2021-09-21 14:18:24 PDT| <14>1 2021-09-21T21:18:24Z 99829619269b quantrocket_history_1 4923 - - Processing 1170 raw bars from IBKR for VWID STK (sid FIBBG00HY5VYY7)
2021-09-21 14:18:25 PDT| <14>1 2021-09-21T21:18:25Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VWO STK (sid FIBBG000HT88C8)
2021-09-21 14:18:25 PDT| <14>1 2021-09-21T21:18:25Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VWOB STK (sid FIBBG004N1LXS7)
2021-09-21 14:18:25 PDT| <14>1 2021-09-21T21:18:25Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VWTR STK (sid FIBBG000F2ZGC1)
2021-09-21 14:18:26 PDT| <14>1 2021-09-21T21:18:26Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VXF STK (sid FIBBG000LNZ4P1)
2021-09-21 14:18:26 PDT| <14>1 2021-09-21T21:18:26Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VXRT STK (sid FIBBG000DR0RZ7)
2021-09-21 14:18:26 PDT| <14>1 2021-09-21T21:18:26Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VXUS STK (sid FIBBG001F8JPC4)
2021-09-21 14:18:27 PDT| <14>1 2021-09-21T21:18:27Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VXX STK (sid FIBBG00JQ5JWB5)
2021-09-21 14:18:27 PDT| <14>1 2021-09-21T21:18:27Z 99829619269b quantrocket_history_1 4923 - - Processing 1932 raw bars from IBKR for VXZ STK (sid FIBBG00JQ5LMQ8)
2021-09-21 14:18:27 PDT| <14>1 2021-09-21T21:18:27Z 99829619269b quantrocket_history_1 4923 - - Processing 1933 raw bars from IBKR for VYGG STK (sid FIBBG00Y6V2640)
2021-09-21 14:18:28 PDT| <14>1 2021-09-21T21:18:28Z 99829619269b quantrocket_history_1 4923 - - Processing 977 raw bars from IBKR for VYGG U STK (sid FIBBG00XD300T4)
2021-09-21 14:18:28 PDT| <14>1 2021-09-21T21:18:28Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VYGR STK (sid FIBBG005ZSY233)
2021-09-21 14:18:29 PDT| <14>1 2021-09-21T21:18:29Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VYM STK (sid FIBBG000QBYWJ8)
2021-09-21 14:18:29 PDT| <14>1 2021-09-21T21:18:29Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VYMI STK (sid FIBBG00C868SC8)
2021-09-21 14:18:29 PDT| <14>1 2021-09-21T21:18:29Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VYNE STK (sid FIBBG00H5W8GM8)
2021-09-21 14:18:30 PDT| <14>1 2021-09-21T21:18:30Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VYNT STK (sid FIBBG000MCFBY0)
2021-09-21 14:18:30 PDT| <14>1 2021-09-21T21:18:30Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VZ STK (sid FIBBG000HS77T5)
2021-09-21 14:18:30 PDT| <14>1 2021-09-21T21:18:30Z 99829619269b quantrocket_history_1 4923 - - ┌────────────────────────────────────────┐
2021-09-21 14:18:30 PDT| <14>1 2021-09-21T21:18:30Z 99829619269b quantrocket_history_1 4923 - - │ ibkr-minute-db IBKR response times:    │
2021-09-21 14:18:30 PDT| <14>1 2021-09-21T21:18:30Z 99829619269b quantrocket_history_1 4923 - - │            all    ibg1    ibg4    ibg3 │
2021-09-21 14:18:30 PDT| <14>1 2021-09-21T21:18:30Z 99829619269b quantrocket_history_1 4923 - - │ count  10176.0  3127.0  3527.0  3522.0 │
2021-09-21 14:18:30 PDT| <14>1 2021-09-21T21:18:30Z 99829619269b quantrocket_history_1 4923 - - │ mean       0.4     0.4     0.4     0.4 │
2021-09-21 14:18:30 PDT| <14>1 2021-09-21T21:18:30Z 99829619269b quantrocket_history_1 4923 - - │ std        1.2     1.0     1.1     1.3 │
2021-09-21 14:18:30 PDT| <14>1 2021-09-21T21:18:30Z 99829619269b quantrocket_history_1 4923 - - │ min        0.0     0.1     0.1     0.0 │
2021-09-21 14:18:30 PDT| <14>1 2021-09-21T21:18:30Z 99829619269b quantrocket_history_1 4923 - - │ 25%        0.2     0.2     0.2     0.2 │
2021-09-21 14:18:30 PDT| <14>1 2021-09-21T21:18:30Z 99829619269b quantrocket_history_1 4923 - - │ 50%        0.2     0.3     0.2     0.2 │
2021-09-21 14:18:30 PDT| <14>1 2021-09-21T21:18:30Z 99829619269b quantrocket_history_1 4923 - - │ 75%        0.3     0.4     0.3     0.3 │
2021-09-21 14:18:30 PDT| <14>1 2021-09-21T21:18:30Z 99829619269b quantrocket_history_1 4923 - - │ max       23.9    18.4    19.3    23.9 │
2021-09-21 14:18:30 PDT| <14>1 2021-09-21T21:18:30Z 99829619269b quantrocket_history_1 4923 - - └────────────────────────────────────────┘
2021-09-21 14:18:31 PDT| <14>1 2021-09-21T21:18:31Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for VZIO STK (sid FIBBG00ZHDJVK4)
2021-09-21 14:18:31 PDT| <14>1 2021-09-21T21:18:31Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for W STK (sid FIBBG001B17MV2)
2021-09-21 14:18:33 PDT| <14>1 2021-09-21T21:18:33Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for WAB STK (sid FIBBG000BDD940)
2021-09-21 14:18:34 PDT| <14>1 2021-09-21T21:18:34Z 99829619269b quantrocket_history_1 4923 - - Processing 1950 raw bars from IBKR for WABC STK (sid FIBBG000DD3KP1)
#7

Unfortunately I don’t have an insight here. Your logs as provided don’t actually prove that this is the same issue as before (I don’t see the stall), and this is minute data while that was daily data which might matter. When price adjustments are detected, a security’s history is deleted and it is added to the historical request queue for re-collection, or, if there is no head timestamp (which there should always be if a security gets to this point), to the head timestamp queue. Perhaps that is how you end up with something in the head timestamp queue again. But all in all, pretty confusing what might be going on.

#8

The stall happens, I just didn't post the repeated update for brevity's sake. Unfortunately, I'm still getting this error on certain days unpredictably. It sometimes happens with daily data, sometimes with minute data (both of which I update daily). I have filtered/scoured the logs and don't see any messages that would hint at what's happening.

For now, my workaround using cancel has made this a low priority, but it's a fairly consistent occurrence.