Puzzleshot #024 - Tailed logs with DuckDB

This puzzle we asked DuckDB the same question we asked awk in #023 — requests and errors per minute — and then pushed it onto a log that’s still being written.

Part 1 — requests and errors per minute:

duckdb -c "
  SELECT
    strftime(date_trunc('minute', (d || ' ' || t)::TIMESTAMP), '%H:%M') AS minute,
    count(*) AS requests,
    count(*) FILTER (WHERE status >= 500) AS errors
  FROM read_csv('access.log', delim=' ', header=false,
       columns={'d':'VARCHAR','t':'VARCHAR','method':'VARCHAR','path':'VARCHAR','status':'INTEGER'})
  GROUP BY 1
  ORDER BY 1
"

The log is space-delimited with no header, so we name the columns ourselves. date_trunc(‘minute’, …) rounds each timestamp down to its minute, and GROUP BY does the counting. The FILTER clause counts only the rows that match inside an aggregate, so we get total requests and just the errors in one pass, without a CASE WHEN.

The numbers match what the awk pipeline printed in #023 — with one difference. DuckDB returns one more row. The awk version only printed a minute once a later timestamp arrived to close it, so the final minute never appeared. DuckDB reads the whole finished file, so every minute is there.

Part 2 — rolling error rate:

duckdb -c "
  WITH per_minute AS (
    SELECT
      date_trunc('minute', (d || ' ' || t)::TIMESTAMP) AS minute,
      count(*) AS requests,
      count(*) FILTER (WHERE status >= 500) AS errors
    FROM read_csv('access.log', delim=' ', header=false,
         columns={'d':'VARCHAR','t':'VARCHAR','method':'VARCHAR','path':'VARCHAR','status':'INTEGER'})
    GROUP BY 1
  )
  SELECT
    strftime(minute, '%H:%M') AS minute,
    requests,
    errors,
    round(100.0 * sum(errors) OVER w / sum(requests) OVER w, 1) AS error_pct_3min
  FROM per_minute
  WINDOW w AS (ORDER BY minute RANGE BETWEEN INTERVAL 2 MINUTE PRECEDING AND CURRENT ROW)
  ORDER BY minute
"

The window w covers the current minute and the two before it. We divide the sum of errors by the sum of requests across that window, rather than averaging the per-minute percentages, so a busy minute counts for more than a quiet one.

Why RANGE and not ROWS:

ROWS BETWEEN 2 PRECEDING counts rows, not minutes. A minute with no traffic produces no row at all (GROUP BY only returns minutes that exist), so a row-based window silently reaches back further than three minutes. RANGE BETWEEN INTERVAL 2 MINUTE PRECEDING works on the timestamps themselves. When I removed one minute from the log, the row-based window summed 89 requests at 10:03 where the time-based one summed 59.

Bonus — the live log:

DuckDB can query a file that’s still being written. Save the part 1 query in per_minute.sql, add ignore_errors=true to read_csv, and re-run it in a loop:

while true; do duckdb -f per_minute.sql; sleep 5; done

Each run is a snapshot of whatever has been written so far. Closed minutes are final, and the newest minute is partial. A few things to know:

• Piping tail -F straight into DuckDB doesn’t work. read_csv reads stdin until the stream ends, so nothing prints until tail exits.
• Every run re-reads the whole file, so the cost grows with the log.
• If a run catches a half-written last line, the default settings fail with a CSV sniffing error. ignore_errors=true skips that row, and it will be complete on the next run.
• The newest minute is shown incomplete, where the awk version held it back until it was closed. Which is better depends on who’s reading the numbers.

The broader point:

Polling isn’t streaming. tail and awk answer “what’s happening now?” by remembering as they go, while DuckDB answers it by asking again from scratch. DuckDB is the better fit for questions about a log — rolling windows, comparisons, anything you’d write SQL for. awk is the better fit for “tell me as it happens.”