Du baust zentrales Logging auf, schaust dir nach dem ersten Tag die Top-Verursacher an — und ein einzelner Host zieht fast das gesamte Budget. Kein Fehler im Log, kein Crash, kein Retry-Loop. Nur ein Sync-Client, der bei jedem Lauf minutiös jede einzelne Datei protokolliert, die er anschaut.

TL;DR

  • nextcloud-sync@.service lief ohne -s (--silent) und schrieb 13.503 Zeilen / 8,51 MB pro Lauf ins Journal — bei einem 5-Minuten-Timer.
  • Ergebnis: 92 % der an diesem Tag gespeicherten Log-Menge der ganzen Flotte stammten aus dieser einen User-Unit eines Hosts. Als Live-Ingest-Rate maß dieser Host allein 87,53 MB/h (die 255 MB/Tag sind die komprimierte, gespeicherte Menge — nicht der Roheingang).
  • Fix: -s + Environment=LANG=C.UTF-8 in der systemd-Unit. Nachher: 0–4 Zeilen / 265 Bytes pro Lauf, Fehler bleiben weiter sichtbar.

Das Problem

Wir sammeln seit Kurzem alle Logs der Infrastruktur zentral in Loki (14 Tage Retention). Nach dem ersten vollen Tag Betrieb: 255 MB Logs gespeichert, verteilt über alle Hosts. Davon kamen 92 % von einem einzigen Host — und dort fast ausschließlich aus unit=user@1000.service.

Kein Alarm war rot. Kein Dienst war down. Die Loki-Metrik loki_discarded_samples_total zeigte zwar 541.466 verworfene Zeilen (greater_than_max_sample_age) — das stellte sich bei näherem Hinsehen als unabhängiger, zeitlich klar abgegrenzter Positions-/Backfill-Vorfall einer Promtail-Instanz heraus, nicht als Symptom des aktuellen Ingest-Problems. Das eigentliche Problem war simpler: ein Dienst, der bei jedem Lauf viel zu viel redet.

Die Diagnose

Erster Schritt: welcher Stream frisst das Budget. LogQL-Abfrage auf Byte-Summe pro Host/Unit:

sum(bytes_over_time({host="cloud-leia"}[1h])) by (unit)

user@1000.service dominierte klar vor allem anderen Journal-Traffic des Hosts. Journal-Felder des Streams gaben die konkrete Quelle preis:

_SYSTEMD_UNIT=user@1000.service
_SYSTEMD_USER_UNIT=nextcloud-sync@deathstar.service
SYSLOG_IDENTIFIER=nextcloudcmd

Eine User-Unit, oneshot, per Timer alle 5 Minuten gestartet — der Nextcloud-CLI-Sync-Client nextcloudcmd. Fast jede Zeile trug den Log-Typ nextcloud.sync.discovery: eine Zeile pro Datei, die der Client beim Abgleich anschaut — unabhängig davon, ob sich an der Datei etwas geändert hat.

Bevor der Fix angefasst wurde, kurz geprüft, ob die Geschwätzigkeit ein Symptom für ein echtes Problem war: Sync-Datenbank-Status valid=true, nur ein einziger (alter) Conflict-Eintrag. Kein Fehler, kein Endlos-Retry — reines INFO-Logging auf Default-Verbosity.

Die Ursache

Das Perfide: Der Dienst tat exakt das, wofür er gebaut ist. nextcloudcmd loggt standardmäßig auf INFO-Level, und INFO heißt bei einem Sync-Client „jede angefasste Datei, jeder Discovery-Schritt". Bei einem Nextcloud-Baum mit mehreren tausend Dateien ergibt das bei jedem der 5-Minuten-Läufe dieselbe Menge an Log-Zeilen — ob sich eine einzige Datei geändert hat oder keine.

Die Zahlen aus dem Vergleich:

LaufZeilenGröße
Ohne -s (Default)13.5038,51 MB
Mit -s0–4265 B

Hochgerechnet auf den 5-Minuten-Timer macht das den Unterschied zwischen 87,53 MB/h (davon 86,19 MB allein user@1000.service) und rund 1,4 MB/h nach dem Fix — gemessen als 0,34 MB in einem 15-Minuten-Fenster.

Die Unit lief komplett fehlerfrei. Das ist der Teil, der beim ersten Blick auf die Loki-Zahlen verwirrt: Man sucht reflexhaft nach einem Crash-Loop oder einem fehlgeschlagenen Retry — hier war es ein funktionierender Dienst mit falscher Log-Verbosity.

Die Lösung

Fix an der Quelle, nicht am Loki-Ingest-Limit. Die User-Unit liegt unter ~/.config/systemd/user/nextcloud-sync@.service:

Vorher:

[Service]
Type=oneshot
ExecStart=/usr/bin/nextcloudcmd -n --non-interactive --exclude %h/nextcloud/sync-exclude.lst --path /%i %h/Nextcloud/%i https://nextcloud.deathstar.lan

Nachher:

[Service]
Type=oneshot
Environment=LANG=C.UTF-8
ExecStart=/usr/bin/nextcloudcmd -s -n --non-interactive --exclude %h/nextcloud/sync-exclude.lst --path /%i %h/Nextcloud/%i https://nextcloud.deathstar.lan

Zwei Änderungen:

  1. -s (--silent) unterdrückt genau das geschwätzige nextcloud.sync.discovery-INFO-Logging — Fehler und Konflikte bleiben trotzdem sichtbar.
  2. Environment=LANG=C.UTF-8 fixiert die Locale für den oneshot-Lauf (verhindert, dass die Ausgabe unter einer undefinierten/abweichenden Locale der Session unterschiedlich formatiert wird).

Backup vor der Änderung, dann reload:

cp ~/.config/systemd/user/nextcloud-sync@.service ~/.config/systemd/user/nextcloud-sync@.service.bak-20260928
systemctl --user daemon-reload

Der Timer selbst (nextcloud-sync@.timer) bleibt unverändert — 5-Minuten-Intervall:

[Timer]
OnBootSec=1min
OnUnitActiveSec=5min

Verify — Fehler bleiben sichtbar: Testlauf gegen eine absichtlich falsche URL lieferte exit=1 + Fehlermeldung, trotz -s. Das war der entscheidende Check vor dem Rollout: -s darf niemals bedeuten, dass ein echter Sync-Fehler lautlos verschwindet — es filtert nur die Erfolgs-Protokollierung pro Datei.

Verify — Byte-Rückgang:

sum(bytes_over_time({host="cloud-leia"}[1h])) by (unit)

Nach dem Fix fällt user@1000.service komplett aus dem Top-Ranking der Streams. Der nächste reguläre Timer-Lauf zeigte Result=success bei 0 geloggten Zeilen.

Lessons Learned

  • „Hoher Ingest" heißt nicht automatisch „Fehler". Der naheliegende erste Gedanke bei einem dominanten Log-Stream ist ein Crash-Loop. Hier lief alles wie vorgesehen — nur auf der falschen Verbosity-Stufe. Erst die Journal-Felder (SYSLOG_IDENTIFIER, _SYSTEMD_USER_UNIT) zeigen, welcher konkrete Prozess dahintersteckt.
  • CLI-Tools mit Default-INFO-Logging sind in Automatisierung gefährlich. nextcloudcmd ist nicht der einzige Kandidat — jeder CLI-Sync- oder Backup-Client, der standardmäßig jede Datei protokolliert, skaliert sein Log-Volumen linear mit der Dateianzahl, nicht mit der Änderungsrate. Bei einem 5-Minuten-Timer multipliziert sich das brutal.
  • Vor dem Deploy prüfen, ob „silent" wirklich silent genug ist — aber Fehler durchlässt. Ein -s-Flag, das versehentlich auch echte Fehler verschluckt, wäre schlimmer als das ursprüngliche Problem gewesen. Der Negativtest (falsche URL → exit=1 sichtbar) war deshalb Pflicht, nicht optional.
  • Zwei Baustellen nicht vermischen. Die 541k discarded Samples (greater_than_max_sample_age) sahen auf den ersten Blick nach demselben Thema aus, waren aber ein unabhängiger Promtail-Positionsdatei-Vorfall mit eigener, zeitlich klar eingegrenzter Ursache. Separate Root-Cause-Analysen für scheinbar verwandte Symptome ersparen falsche Korrelationen.

Verwandtes Thema — wenn Logging selbst zur Ressourcen-Last wird, nicht nur zum Ingest-Problem: UCS 5: ASAN-Bug lässt journald bei Policy-Updates explodieren.

Checkliste

  • Top-Verursacher im zentralen Logging per sum(bytes_over_time(...)) by (unit) oder gleichwertiger Query identifiziert, bevor an Limits/Retention gedreht wird
  • Journal-Felder (SYSLOG_IDENTIFIER, _SYSTEMD_UNIT, _SYSTEMD_USER_UNIT) geprüft, um den tatsächlichen Prozess zu identifizieren — nicht nur den Host
  • Geprüft, ob die Geschwätzigkeit ein echtes Problem anzeigt (DB-Status, Conflicts, Retries) oder reines Default-Logging ist
  • CLI-Tools in zeitgesteuerten Units auf Silent-/Quiet-Flags geprüft, bevor sie produktiv per Timer laufen
  • Nach -s/--quiet: Negativtest mit absichtlichem Fehler — Fehler müssen sichtbar bleiben
  • Backup der Unit-Datei vor Änderung (.bak-YYYYMMDD) + daemon-reload
  • Byte-Rückgang nach Fix tatsächlich in der Logging-Plattform verifiziert, nicht nur „sollte jetzt besser sein"
  • Scheinbar verwandte Symptome (hier: discarded samples) separat auf eigene Root Cause geprüft, nicht pauschal demselben Fix zugeschrieben