#19 Miscategorized log messages

open
  1. @spacegirl.ing opened

    I've accumulated a few cases where I think log messages could be better categorized into different log levels.

    1. Chain breaks during backfill/ingestion (i.e. the "chain break detected, triggering backfill" message): This is currently logged as a warning, but given that in my understanding chain breaks are really just regular behavior while syncing, I would argue that log should instead be a debug message. Because it's a warning, it's frequently logged while backfilling and pretty much spams the log output, which is a little inconvenient.
    2. Startup/database recovery ("recovering LSM-tree" messages): When starting up Hydrant with an existing database on disk, there is not really any info-level logging that the database is still being loaded/processed. Instead, there the occasional internal "recovering LSM-tree" messages which don't provide a clear look at the recovery progress. I would argue that those recovery messages should be considered debug-level, and that some info-level logging when database recovery begins and ends would be helpful.
    3. Backfill queue progress: The crawler does log "throttled: pending queue full" every 60s while idle, but I think that only reflects whether new repos are being discovered and not whether the backfill worker is actually draining the queue. Periodic backfill queue/worker progress summaries would be great to distinguish normal behavior from a stalled backfill worker or something.
  2. @ptr.pet

    1 & 2 makes sense, i think i had 1 as warn because i was debugging things... for 3 we already do have events per sec is that not enough? or you want to distinguish from firehose vs backfill events?

  3. @spacegirl.ing

    Yes the latter, distinguishing firehose and backfill events and progress. Often I'll see that the logs have literally only said "throttled: pending queue full" for hours and its unclear whether Hydrant is still operating correctly.

  4. @spacegirl.ing

    Case in point:

    2026-07-18T13:23:27.697419Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:24:27.697634Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:25:27.697228Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:26:27.697717Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:27:27.696935Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:28:27.697554Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:29:27.697710Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:30:27.697377Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:31:27.697643Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:32:27.697225Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:33:27.697651Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:34:27.697293Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:35:27.697137Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:36:27.697468Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:37:27.697429Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:38:27.697537Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:39:27.697252Z  INFO hydrant::crawler: throttled: pending queue full
    2026-07-18T13:40:27.697170Z  INFO hydrant::crawler: throttled: pending queue full
    

    These logs tell me that the queue is full, but nothing about if it is being drained and at what rate.

  5. @ptr.pet

    pushed commit for this should be better now

  6. to comment, sign in