fix(apache): Aggregator gegen Zeitstempel-Kollisionen + README korrigiert
Die vorige Massnahme (log_time statt ts) war NICHT ausreichend. Ursache ist tiefer: Telegraf schreibt pro Sammelzyklus EINEN Zeitstempel fuer den ganzen Batch, und Remote Write kann nur Millisekunden. Zwei Requests derselben Serie in derselben Millisekunde -> Prometheus lehnt den ganzen Batch ab -> FIFO-Kopf sitzt fest -> Node liefert gar nichts mehr (derselbe eingefrorene Timestamp alle ~15s im Log). Ein Zeitstempel-Trick kann das nicht loesen. Aggregation schon: basicstats fasst alle Metriken einer Serie pro 60s zu einem Punkt zusammen. Gemessen an 2000 echten x22-Zeilen: 2000 Punkte -> 4 Punkte, 0 Kollisionen, Requests vollstaendig gezaehlt (1997). VERSION 1.2.0, damit der Auto-Updater den Fix ausrollt.
This commit is contained in:
mm committed
1 parent
a9d9b92499
commit
6d0d0bd900
2 files changed
+50
-42
No files matched your search
@@ -87,64 +87,72 @@ Jede Serie trägt ein `path`-Tag, damit man in Grafana nach Datei filtert. Über
|
|||||||
|
|
||||||
**Zusätzlich** wird die `CustomLog`-Direktive aus `/etc/apache2` bzw. `/etc/httpd` ausgewertet — die verlässlichste Quelle, `${APACHE_LOG_DIR}` wird aufgelöst.
|
**Zusätzlich** wird die `CustomLog`-Direktive aus `/etc/apache2` bzw. `/etc/httpd` ausgewertet — die verlässlichste Quelle, `${APACHE_LOG_DIR}` wird aufgelöst.
|
||||||
|
|
||||||
### Sekunden-Kollisionen: der stille Totalausfall
|
### Zeitstempel-Kollisionen: der stille Totalausfall
|
||||||
|
|
||||||
**Symptom.** Ein Node liefert **gar nichts** mehr — nicht nur die Apache-Metriken,
|
**Symptom.** Ein Node liefert **gar nichts** mehr — nicht nur die Apache-Metriken,
|
||||||
sondern auch `system_uptime`, CPU, Disk. Andere Nodes laufen normal.
|
sondern auch `system_uptime`, CPU, Disk. Andere Nodes laufen normal.
|
||||||
|
|
||||||
**Ursache.** Access-Logs haben nur **Sekunden**-Auflösung:
|
**Erkennungsmerkmal.** Im Prometheus-Log wiederholt sich **derselbe eingefrorene
|
||||||
|
Timestamp** alle ~15 s:
|
||||||
|
|
||||||
```
|
```
|
||||||
138.199.15.193 - - [14/Sep/2026:01:16:49 +0200] "GET /image/x HTTP/1.1" 200 25454
|
duplicate sample for timestamp 1789343466232; overrides not allowed:
|
||||||
|
existing 43930, new value 51608
|
||||||
|
series="{__name__=\"apache_access_resp_bytes\", path=\"…/pixtasia.de/access.log\",
|
||||||
|
resp_code=\"200\", verb=\"GET\"}"
|
||||||
```
|
```
|
||||||
|
|
||||||
Telegraf übernimmt einen erkannten Zeitstempel als **Sample-Zeit**. Treffen
|
Derselbe Wert über Minuten heißt: **ein vergifteter Batch sitzt im FIFO-Kopf und
|
||||||
mehrere Zeilen auf dieselbe Sekunde, vergibt es `+1 ms` Aufschlag pro Zeile.
|
wird endlos wiederholt** — nicht ein neuer Fehler pro Intervall.
|
||||||
Bei hoher Last läuft dieser Aufschlag in die nächste Sekunde und kollidiert mit
|
|
||||||
echten Zeilen derselben Serie:
|
|
||||||
|
|
||||||
```
|
**Ursache.** Telegraf schreibt pro Sammelzyklus einen Batch, dessen Metriken alle
|
||||||
duplicate sample for timestamp 1789340156000; overrides not allowed:
|
denselben Zeitstempel tragen. Remote Write kennt nur **Millisekunden**. Treffen
|
||||||
existing 25646, new value 14178
|
zwei Requests derselben Serie (`path` + `resp_code` + `verb`) in dieselbe
|
||||||
```
|
Millisekunde, lehnt Prometheus den **ganzen Batch** ab. Telegrafs Puffer ist
|
||||||
|
FIFO: der Batch bleibt am Kopf stehen und blockiert jede weitere Serie — deshalb
|
||||||
|
fehlt am Ende die ganze Node.
|
||||||
|
|
||||||
Prometheus weist den Batch ab. Telegraf **wiederholt ihn endlos** — die
|
**Lösung: Aggregation statt Zeitstempel-Trick.** Ein Zeitstempel-Trick kann das
|
||||||
Remote-Write-Queue steht, und weil sie blockiert, kommt vom ganzen Node kein
|
nicht beheben — feiner als Millisekunden geht Remote Write nicht. Ein Aggregator
|
||||||
Sample mehr an.
|
fasst alle Metriken einer Serie pro Intervall zu **einem** Punkt zusammen; damit
|
||||||
|
ist eine Kollision strukturell unmöglich, unabhängig von der Last:
|
||||||
**Gemessen** an echten x22-Logs (2000 Zeilen): **286 Kollisionen**, 1098 statt
|
|
||||||
2000 eindeutige Zeitstempel.
|
|
||||||
|
|
||||||
**Fix.** Im eigenen Grok-Muster heißt das Zeitfeld **`log_time`** statt `ts`:
|
|
||||||
|
|
||||||
```toml
|
```toml
|
||||||
grok_custom_patterns = '''
|
[[aggregators.basicstats]]
|
||||||
APACHE_LINE (?:%{HOSTNAME:vh}(?::%{NUMBER:vport})? )?%{IPORHOST:client_ip} %{USER:ident} %{USER:auth} \[%{HTTPDATE:log_time}\] ...
|
|
||||||
'''
|
|
||||||
```
|
|
||||||
|
|
||||||
Telegraf erkennt kein Zeitfeld mehr und stempelt mit **eigener Uhr in
|
|
||||||
Nanosekunden**. Die Log-Zeit bleibt als Feld erhalten. Gemessen: 2000 von 2000
|
|
||||||
Samples, **0 Kollisionen**.
|
|
||||||
|
|
||||||
Damit `resp_code` und `verb` weiterhin **Tags** sind (das eingebaute Muster
|
|
||||||
liefert sie als Tags, ein eigenes Muster als Felder — sonst brechen Panels, die
|
|
||||||
danach filtern):
|
|
||||||
|
|
||||||
```toml
|
|
||||||
[[processors.converter]]
|
|
||||||
namepass = ["apache_access"]
|
namepass = ["apache_access"]
|
||||||
order = 1
|
period = "60s"
|
||||||
[processors.converter.fields]
|
drop_original = true # zwingend — sonst sind die Einzelwerte zurück
|
||||||
tag = ["resp_code", "verb"]
|
stats = ["count", "sum", "mean"]
|
||||||
```
|
```
|
||||||
|
|
||||||
**Diagnose.** `--diagnose` zeigt ein `E!` bzw. die Fehlerzeile; zentral im
|
**Gemessen an 2000 echten x22-Zeilen:**
|
||||||
Prometheus-Log:
|
|
||||||
|
| | Punkte | Kollisionen |
|
||||||
|
|---|---|---|
|
||||||
|
| ohne Aggregator | 2000 | Risiko pro Zelle |
|
||||||
|
| **mit Aggregator** | **4** | **0** |
|
||||||
|
|
||||||
|
Die Requests werden dabei vollständig gezählt (1997 von 2000 — Differenz durch
|
||||||
|
das Zeitfenster).
|
||||||
|
|
||||||
|
**Entstehende Metriken** (Telegraf stellt den Feldnamen voran):
|
||||||
|
|
||||||
|
| Metrik | Bedeutung |
|
||||||
|
|---|---|
|
||||||
|
| `apache_access_resp_bytes_count` | Requests je Gruppe — **das brauchen die Panels** |
|
||||||
|
| `apache_access_resp_bytes_sum` | übertragene Bytes je Gruppe |
|
||||||
|
| `apache_access_resp_bytes_mean` | mittlere Antwortgröße |
|
||||||
|
|
||||||
|
`resp_code` und `verb` bleiben **Tags** und damit Gruppenschlüssel — dafür sorgt
|
||||||
|
`processors.converter` oben im File (das eingebaute Muster liefert sie als Tags,
|
||||||
|
ein eigenes Muster als Felder; ohne den Converter brächen Filter nach `resp_code`).
|
||||||
|
|
||||||
|
**Diagnose.**
|
||||||
|
|
||||||
```sh
|
```sh
|
||||||
docker logs observability-prometheus 2>&1 | grep -c "duplicate sample"
|
# derselbe Timestamp mehrfach = vergifteter Batch
|
||||||
docker logs observability-prometheus 2>&1 | grep -c "Out of order"
|
docker logs observability-prometheus 2>&1 \
|
||||||
|
| grep "duplicate sample" | grep -oE "timestamp [0-9]+" | sort | uniq -c | tail
|
||||||
```
|
```
|
||||||
|
|
||||||
### Leserechte: der stille Killer
|
### Leserechte: der stille Killer
|
||||||
|
|||||||
Reference in new issue
Block a user