fix(archive): Error-Logs ohne Zeitzone wurden STILL verworfen + Backfill-Skript
BEFUND (echter Datenverlust, gemessen gegen KeyHelp-Formate):
KeyHelp/Debian schreiben error.log im Access-Format, aber OHNE Zeitzone:
[01/Sep/2026:10:00:05] [core:error] [pid 9] AH00124: ...
TS_FORMATS kannte nur "%d/%b/%Y:%H:%M:%S %z" (MIT Zone). parse_ts() gab None,
hour wurde "unknown", und der Schreiber ueberspringt unknown-Zeilen:
apache_archive_errors_total fehlte KOMPLETT — kein Fehler, kein Log, Panel leer.
Genau die stille Fehlerklasse, die nicht passieren darf.
FIX:
- Format "%d/%b/%Y:%H:%M:%S" (ohne Zone) ergaenzt.
- Unparsbare Zeitstempel werden GEZAEHLT und laut gemeldet (Domain + Beispiel +
Hinweis auf TS_FORMATS) statt still zu verschwinden.
- Neu: scripts/x22-log-backfill.sh — messen (read-only) und parsen in einem
Aufruf, mit Selbstpruefung (Einheiten, Zukunft, Domain-Anzahl) VOR der
Uebergabe und dem sicheren Import-Befehl am Ende.
Verifiziert im Container gegen echte KeyHelp-Formate inkl. rotierter .1 und
.gz-Datei: Messmodus aendert nichts (MD5-Vergleich), Backfill erzeugt alle
fuenf Metriken inkl. errors_total{level=error} und {level=warn}.
This commit is contained in:
1 parent
7d3ce17c53
commit
194fa98f97
2 files changed
+186
-4
No files matched your search
@@ -65,7 +65,22 @@ RE_LINE = re.compile(
|
|||||||
)
|
)
|
||||||
RE_ERR = re.compile(r'^\[(?P<ts>[^\]]+)\] \[(?P<mod>[^\]:]+):(?P<lvl>\w+)\]')
|
RE_ERR = re.compile(r'^\[(?P<ts>[^\]]+)\] \[(?P<mod>[^\]:]+):(?P<lvl>\w+)\]')
|
||||||
|
|
||||||
TS_FORMATS = ["%d/%b/%Y:%H:%M:%S %z", "%a %b %d %H:%M:%S.%f %Y", "%a %b %d %H:%M:%S %Y"]
|
TS_FORMATS = [
|
||||||
|
# access.log (Apache Access, MIT Zeitzone)
|
||||||
|
"%d/%b/%Y:%H:%M:%S %z",
|
||||||
|
# ERROR-LOGS OHNE ZEITZONE — der Apache-Standard in error.log:
|
||||||
|
# [Mon Sep 14 00:10:01.123456 2026] [core:error] ...
|
||||||
|
# [Mon Sep 14 00:10:01 2026] [php:warn] ...
|
||||||
|
"%a %b %d %H:%M:%S.%f %Y",
|
||||||
|
"%a %b %d %H:%M:%S %Y",
|
||||||
|
# KeyHelp/Debian schreiben error.log AUCH im Access-Format, aber OHNE
|
||||||
|
# Zeitzone: [01/Sep/2026:10:00:05] [core:error] ...
|
||||||
|
# Fehlte hier bisher -> parse_ts() gab None -> hour="unknown" -> die
|
||||||
|
# Error-Metrik wurde STILL verworfen (kein Fehler, kein Log, das Panel
|
||||||
|
# blieb leer). Real gemessen: error.log-Zeilen landeten nur in
|
||||||
|
# log_lines_total, apache_archive_errors_total fehlte komplett.
|
||||||
|
"%d/%b/%Y:%H:%M:%S",
|
||||||
|
]
|
||||||
|
|
||||||
# Metriknamen, die das Skript erzeugt — auch fuer den Import-Loader relevant.
|
# Metriknamen, die das Skript erzeugt — auch fuer den Import-Loader relevant.
|
||||||
METRICS = [
|
METRICS = [
|
||||||
@@ -112,6 +127,9 @@ def collect(patterns):
|
|||||||
clients = defaultdict(set) # (hour, domain) -> {ip}
|
clients = defaultdict(set) # (hour, domain) -> {ip}
|
||||||
errors = defaultdict(int) # (hour, domain, level) -> count
|
errors = defaultdict(int) # (hour, domain, level) -> count
|
||||||
lines = defaultdict(int) # (domain, kind) -> count
|
lines = defaultdict(int) # (domain, kind) -> count
|
||||||
|
# Zeitstempel, die KEIN Format getroffen haben. Frueher still verworfen —
|
||||||
|
# dadurch fehlte die Error-Metrik komplett, ohne Fehlermeldung.
|
||||||
|
unparsed_ts = defaultdict(int) # (domain, roh) -> count
|
||||||
|
|
||||||
for path in files:
|
for path in files:
|
||||||
domain = os.path.basename(os.path.dirname(path)) or os.path.basename(path)
|
domain = os.path.basename(os.path.dirname(path)) or os.path.basename(path)
|
||||||
@@ -146,10 +164,15 @@ def collect(patterns):
|
|||||||
lines[(domain, "error")] += 1
|
lines[(domain, "error")] += 1
|
||||||
ts = parse_ts(m.group("ts"))
|
ts = parse_ts(m.group("ts"))
|
||||||
hour = ts.strftime("%Y-%m-%dT%H:00:00Z") if ts else "unknown"
|
hour = ts.strftime("%Y-%m-%dT%H:00:00Z") if ts else "unknown"
|
||||||
errors[(hour, domain, m.group("lvl").lower())] += 1
|
if ts:
|
||||||
|
errors[(hour, domain, m.group("lvl").lower())] += 1
|
||||||
|
else:
|
||||||
|
# NICHT still verwerfen: ein unparsbarer Zeitstempel hat
|
||||||
|
# vorher die ganze Error-Metrik gekostet, ohne jede Spur.
|
||||||
|
unparsed_ts[(domain, m.group("ts")[:40])] += 1
|
||||||
continue
|
continue
|
||||||
lines[(domain, "unparsed")] += 1
|
lines[(domain, "unparsed")] += 1
|
||||||
return files, requests, bytes_by_domain, bytes_by_hour, clients, errors, lines
|
return files, requests, bytes_by_domain, bytes_by_hour, clients, errors, lines, unparsed_ts
|
||||||
|
|
||||||
|
|
||||||
def write_openmetrics(path, node, requests, bytes_by_domain, bytes_by_hour, clients, errors, lines):
|
def write_openmetrics(path, node, requests, bytes_by_domain, bytes_by_hour, clients, errors, lines):
|
||||||
@@ -258,7 +281,8 @@ def main():
|
|||||||
|
|
||||||
os.makedirs(args.out, exist_ok=True)
|
os.makedirs(args.out, exist_ok=True)
|
||||||
print(f"[1/5] Logs einlesen …")
|
print(f"[1/5] Logs einlesen …")
|
||||||
files, requests, bytes_by_domain, bytes_by_hour, clients, errors, lines = collect(PATTERNS)
|
(files, requests, bytes_by_domain, bytes_by_hour,
|
||||||
|
clients, errors, lines, unparsed_ts) = collect(PATTERNS)
|
||||||
if not files:
|
if not files:
|
||||||
print("Keine Logdateien gefunden. Muster:", ", ".join(PATTERNS[:4]), file=sys.stderr)
|
print("Keine Logdateien gefunden. Muster:", ", ".join(PATTERNS[:4]), file=sys.stderr)
|
||||||
return 1
|
return 1
|
||||||
@@ -266,6 +290,17 @@ def main():
|
|||||||
print(f" {len(files)} Dateien, {total_lines:,} Zeilen")
|
print(f" {len(files)} Dateien, {total_lines:,} Zeilen")
|
||||||
print(f" {sum(requests.values()):,} Zugriffe, {sum(errors.values()):,} Fehlereintraege")
|
print(f" {sum(requests.values()):,} Zugriffe, {sum(errors.values()):,} Fehlereintraege")
|
||||||
|
|
||||||
|
# Unparsbare Zeitstempel LAUT melden. Sie kosteten frueher die ganze
|
||||||
|
# Error-Metrik, ohne dass irgendwo etwas stand.
|
||||||
|
if unparsed_ts:
|
||||||
|
n = sum(unparsed_ts.values())
|
||||||
|
print(f" WARNUNG: {n:,} Eintraege mit unlesbarem Zeitstempel — "
|
||||||
|
f"diese fehlen in den Zeitreihen (nicht in den Rohdaten).", file=sys.stderr)
|
||||||
|
for (dom, raw), cnt in sorted(unparsed_ts.items(), key=lambda x: -x[1])[:5]:
|
||||||
|
print(f" {cnt:>6}x domain={dom} Beispiel: {raw}", file=sys.stderr)
|
||||||
|
print(" Ein fehlendes Format in TS_FORMATS ergaenzen, dann erneut laufen.",
|
||||||
|
file=sys.stderr)
|
||||||
|
|
||||||
print(f"[2/5] OpenMetrics schreiben …")
|
print(f"[2/5] OpenMetrics schreiben …")
|
||||||
om = os.path.join(args.out, "apache-archive.openmetrics")
|
om = os.path.join(args.out, "apache-archive.openmetrics")
|
||||||
n = write_openmetrics(om, args.node, requests, bytes_by_domain, bytes_by_hour,
|
n = write_openmetrics(om, args.node, requests, bytes_by_domain, bytes_by_hour,
|
||||||
|
|||||||
@@ -0,0 +1,147 @@
|
|||||||
|
#!/bin/bash
|
||||||
|
# x22-log-backfill.sh — Alte Apache-Logs von x22 messen, parsen, als Archiv
|
||||||
|
# bereitstellen. DIESES SKRIPT AENDERT NICHTS AM LAUFENDEN DIENST.
|
||||||
|
#
|
||||||
|
# SICHERHEIT (die drei Wege, die schon schiefgingen):
|
||||||
|
# 1. Es importiert NICHTS in die Produktions-TSDB. Der Import laeuft
|
||||||
|
# ausschliesslich ueber prom-archive-import.sh --file auf dem imac,
|
||||||
|
# der nur in die getrennte Archiv-Instanz (:9091) schreibt.
|
||||||
|
# 2. Es stoppt nichts und loescht nichts. Ausgabe geht nach /root/apache-archive.
|
||||||
|
# 3. Die Ausgabe wird VOR der Uebergabe geprueft (Einheiten, Zukunft, Inhalt).
|
||||||
|
#
|
||||||
|
# AUFRUF auf x22 (als root):
|
||||||
|
# curl -fsSL https://gitea.m-m.bio/mm/netbird-telegraf-installer/raw/branch/main/scripts/x22-log-backfill.sh -o /root/x22-backfill.sh
|
||||||
|
# bash /root/x22-backfill.sh # MESSEN (nichts wird veraendert)
|
||||||
|
# bash /root/x22-backfill.sh --backfill # parsen und Tarball bauen
|
||||||
|
#
|
||||||
|
# Danach steht am Ende der genaue Befehl fuer den imac.
|
||||||
|
|
||||||
|
set -eu
|
||||||
|
|
||||||
|
REPO_RAW="${REPO_RAW:-https://gitea.m-m.bio/mm/netbird-telegraf-installer/raw/branch/main}"
|
||||||
|
OUT_DIR="${OUT_DIR:-/root/apache-archive}"
|
||||||
|
NODE="${NODE:-x22.idx.wf-keyhelp}"
|
||||||
|
BACKFILL=0
|
||||||
|
[ "${1:-}" = "--backfill" ] && BACKFILL=1
|
||||||
|
|
||||||
|
log() { printf '\033[1;34m[backfill]\033[0m %s\n' "$*"; }
|
||||||
|
warn() { printf '\033[1;33m[backfill] WARNUNG:\033[0m %s\n' "$*" >&2; }
|
||||||
|
die() { printf '\033[1;31m[backfill] FEHLER:\033[0m %s\n' "$*" >&2; exit 1; }
|
||||||
|
|
||||||
|
[ "$(id -u)" -eq 0 ] || die "Bitte als root ausfuehren."
|
||||||
|
|
||||||
|
# --------------------------------------------------------------------------
|
||||||
|
# 1) Bestand MESSEN — nicht raten
|
||||||
|
# --------------------------------------------------------------------------
|
||||||
|
log "Bestandsaufnahme der Apache-Logs (aendert nichts) …"
|
||||||
|
mkdir -p /tmp/x22-archiv
|
||||||
|
curl -fsSL -m 30 "$REPO_RAW/scripts/apache-log-survey.py" -o /tmp/x22-archiv/survey.py \
|
||||||
|
|| die "survey.py konnte nicht geladen werden."
|
||||||
|
python3 /tmp/x22-archiv/survey.py --node "$NODE" 2>&1 | tee /tmp/x22-archiv/bestand.txt
|
||||||
|
|
||||||
|
# Wie viel Historie liegt wirklich vor? Das entscheidet ueber den Nutzen.
|
||||||
|
FILES=$(find /var/log/apache2 /home/users -name 'access.log*' -o -name 'error.log*' 2>/dev/null | wc -l)
|
||||||
|
log "Gefundene Logdateien (inkl. rotierte/.gz): $FILES"
|
||||||
|
|
||||||
|
if [ "$BACKFILL" -eq 0 ]; then
|
||||||
|
echo
|
||||||
|
log "Das war NUR die Messung — es wurde nichts veraendert."
|
||||||
|
echo " Weiter mit: bash $0 --backfill"
|
||||||
|
echo " Bestand: /tmp/x22-archiv/bestand.txt"
|
||||||
|
exit 0
|
||||||
|
fi
|
||||||
|
|
||||||
|
# --------------------------------------------------------------------------
|
||||||
|
# 2) Archiv bauen
|
||||||
|
# --------------------------------------------------------------------------
|
||||||
|
log "Archiver laden …"
|
||||||
|
curl -fsSL -m 30 "$REPO_RAW/scripts/apache-log-archive.py" -o /tmp/x22-archiv/archive.py \
|
||||||
|
|| die "apache-log-archive.py konnte nicht geladen werden."
|
||||||
|
|
||||||
|
log "Logs parsen (kann bei viel Historie dauern) …"
|
||||||
|
python3 /tmp/x22-archiv/archive.py --node "$NODE" --out "$OUT_DIR" --include-raw 2>&1 | tail -20
|
||||||
|
|
||||||
|
# --------------------------------------------------------------------------
|
||||||
|
# 3) Selbst pruefen, BEVOR etwas weitergereicht wird
|
||||||
|
# --------------------------------------------------------------------------
|
||||||
|
OM="$OUT_DIR/apache-archive.openmetrics"
|
||||||
|
[ -s "$OM" ] || die "Keine Ausgabe erzeugt: $OM fehlt oder ist leer."
|
||||||
|
|
||||||
|
log "Selbstpruefung der Ausgabe"
|
||||||
|
python3 - "$OM" <<'PY' || exit 1
|
||||||
|
import sys, time, collections
|
||||||
|
path = sys.argv[1]
|
||||||
|
pts = [l.rstrip("\n") for l in open(path) if l and not l.startswith("#") and l.strip()]
|
||||||
|
if not pts:
|
||||||
|
print(" FEHLER: keine Datenpunkte"); sys.exit(1)
|
||||||
|
ts = sorted(int(l.rsplit(" ", 1)[1]) for l in pts)
|
||||||
|
now = int(time.time())
|
||||||
|
f = lambda t: time.strftime("%d.%m.%Y %H:%M", time.gmtime(t))
|
||||||
|
print(f" Datenpunkte: {len(pts):,}")
|
||||||
|
print(f" Zeitraum: {f(ts[0])} .. {f(ts[-1])} UTC")
|
||||||
|
|
||||||
|
domains = collections.Counter()
|
||||||
|
for l in pts:
|
||||||
|
i = l.find('domain="')
|
||||||
|
if i >= 0:
|
||||||
|
j = l.find('"', i + 8)
|
||||||
|
domains[l[i+8:j]] += 1
|
||||||
|
print(f" Domains: {len(domains)}")
|
||||||
|
for d, n in domains.most_common(8):
|
||||||
|
print(f" {d}: {n} Punkte")
|
||||||
|
|
||||||
|
# Einheiten-Wache: alles nach 2100 ist kein Sekundenwert
|
||||||
|
if ts[-1] > 4102444800:
|
||||||
|
print(" FEHLER: Zeitstempel nach dem Jahr 2100 -> Millisekunden statt Sekunden")
|
||||||
|
print(" promtool wuerde Bloecke im Jahr 58.660 erzeugen. Abbruch.")
|
||||||
|
sys.exit(1)
|
||||||
|
print(" Einheit: OK (Sekunden)")
|
||||||
|
|
||||||
|
# Zukunft: der Fehler, der die Produktion kosten kann
|
||||||
|
z = [t for t in ts if t > now + 300]
|
||||||
|
if z:
|
||||||
|
print(f" FEHLER: {len(z)} Punkte in der ZUKUNFT (max {f(z[-1])}).")
|
||||||
|
print(" Ursache: falsche Systemuhr oder Log-Zeitzone. Abbruch.")
|
||||||
|
sys.exit(1)
|
||||||
|
print(" Zukunft: OK")
|
||||||
|
|
||||||
|
# Plausibilitaet: sind die Zahlen aus echten Logs? (nicht alle identisch)
|
||||||
|
if len(domains) < 2:
|
||||||
|
print(f" WARNUNG: nur {len(domains)} Domain(s) erkannt — Logs vollstaendig?")
|
||||||
|
PY
|
||||||
|
|
||||||
|
TAR="$OUT_DIR/apache-archive.tar.gz"
|
||||||
|
[ -s "$TAR" ] && log "Tarball: $TAR ($(du -h "$TAR" | cut -f1))"
|
||||||
|
|
||||||
|
# --------------------------------------------------------------------------
|
||||||
|
# 4) Uebergabe — der sichere Weg
|
||||||
|
# --------------------------------------------------------------------------
|
||||||
|
cat <<EOF
|
||||||
|
|
||||||
|
============================================================
|
||||||
|
FERTIG auf x22. Naechster Schritt auf dem imac.
|
||||||
|
============================================================
|
||||||
|
|
||||||
|
WICHTIG: NICHT von Hand entpacken. Die Bloecke gehoeren in die getrennte
|
||||||
|
Archiv-Instanz (:9091), nie in die Produktions-TSDB. Genau dieser Weg hat am
|
||||||
|
14.09.2026 die Zeitreferenz verschoben — 13 Nodes verloren ihre Metriken.
|
||||||
|
|
||||||
|
# 1) Uebertragen (von x22 aus, im NetBird)
|
||||||
|
scp $OM mm@100.83.134.46:/tmp/apache-archive.openmetrics
|
||||||
|
|
||||||
|
# 2) Auf dem imac einspielen (prueft Zukunft, Manifest, Gegenprobe)
|
||||||
|
ssh mm@192.168.188.177 'sudo /usr/local/bin/prom-archive-import.sh --file /tmp/apache-archive.openmetrics'
|
||||||
|
|
||||||
|
# 3) Zweiter Lauf derselben Datei wird automatisch uebersprungen.
|
||||||
|
# Anzeigen, was schon importiert ist:
|
||||||
|
ssh mm@192.168.188.177 'sudo /usr/local/bin/prom-archive-import.sh --list'
|
||||||
|
|
||||||
|
# 4) Pruefen (step >= 1h wegen Stunden-Buckets!)
|
||||||
|
ssh mm@192.168.188.177 'curl -s -G http://127.0.0.1:9091/api/v1/query_range \\
|
||||||
|
--data-urlencode "query=apache_archive_requests_total" \\
|
||||||
|
--data-urlencode "start=\$(date -d "-30 days" +%s)" \\
|
||||||
|
--data-urlencode "end=\$(date +%s)" --data-urlencode "step=3600" | head -c 400'
|
||||||
|
|
||||||
|
Die Produktions-TSDB bleibt bei diesem Weg unberuehrt. Der Tarball mit den
|
||||||
|
Rohlogs liegt unter $TAR — aufheben, er ist die Quelle fuer Einzelfaelle.
|
||||||
|
EOF
|
||||||
Reference in new issue
Block a user