In early October someone opened an issue on Grafana Alloy. They ship container logs to Loki with loki.source.docker, through a docker-socket-proxy in front of the Docker socket. Every minute, every log stream dropped. The proxy logs showed each follow request ending at 60,018 ms and 60,002 ms. Setting refresh_interval = "65s" moved the cut to 65 seconds.

A setting that sounds like it controls how often to look for new containers was deciding how long a log stream could live. I wrote the fix, #7297, and it shipped in Alloy v1.21.0.

Over an http Docker host the log stream is cut every 60 seconds on v1.20.1; over unix or tcp, and on v1.21.0, it stays open

Where the timeout came from

In v1.20.1, when the Docker host is http:// or https://, the component builds its own HTTP client:

client.WithHTTPClient(&http.Client{ Transport: rt, Timeout: args.RefreshInterval, // 60s by default }) 

Go's http.Client.Timeout covers "connection time, any redirects, and reading the response body". A followed log stream is a body that never ends, so every GET /containers/{id}/logs?follow=1 dies at 60 seconds. unix:// and tcp:// hosts skip that branch and use a client with no timeout, which is why most people never saw it.

Why lines come back twice

Alloy reconnects about five seconds later and asks Docker for logs since the last timestamp it saw, stored in whole seconds. Docker's since filter is inclusive, so the last second of lines is sent again.

A reconnect asks for logs since a whole second, so the last second of lines reaches Loki twice

What to check

  • Search Alloy's logs for Client.Timeout or context cancellation while reading body.
  • Only http:// and https:// Docker hosts are affected.
  • Upgrade to Alloy v1.21.0 or later.

The full post has the side-by-side test of the old and fixed builds, two workarounds for older versions (one of them silently drops your TLS settings), and why Promtail still ships the same bug.

Read the full post on saipisey.com →