mm
df2ee94613
BEFUND (x22, gemessen und reproduziert): Der Aufruf war 'python3 apache-log-survey.py 2>&1 | tee bestand.txt'. Das Skript gab ALLES erst nach der Scan-Schleife aus (alle print() standen dahinter), und Python puffert stdout in eine PIPE blockweise (4-8 KB). Die Gesamtausgabe ist aber nur ~1 KB -> sie landete erst beim Prozessende in der Datei. Messung mit 2 Mio Zeilen (140 MB): mit tee: nach 5 s = 0 Bytes, fertig nach 41 s -> dann 1028 Bytes ohne Pipe: nach 1 s = 0 Bytes python3 -u: nach 1 s = 0 Bytes => Die Datei war leer, weil der Scan LIEF. Auf einem KeyHelp-Host mit tausenden Logdateien dauert das Minuten und liest sich wie ein Haenger oder Absturz. FIX (drei Massnahmen, damit das nie wieder passiert): 1. sys.stdout.reconfigure(line_buffering=True) — jede Zeile geht sofort raus, auch durch eine Pipe. 2. Startbanner VOR dem Scan: Anzahl und Gesamtgroesse der Dateien. 3. Fortschrittszeile pro Datei (Nummer/Gesamtzahl, Zeilen, Groesse, Pfad) plus eine Zeile fuer nicht lesbare Dateien. Verifiziert mit 1,4 Mio Zeilen durch eine Pipe: nach 2 s steht das Banner, drei Fortschrittszeilen erscheinen waehrend des Scans. Gegenprobe mit dem alten Code: nach 3 s 16 Bytes, alles erst am Ende.
238 lines
8.9 KiB
Python
238 lines
8.9 KiB
Python
#!/usr/bin/env python3
|
|
"""
|
|
apache-log-survey.py — Bestandsaufnahme der Apache-Logs auf einem KeyHelp-Host.
|
|
|
|
MESSEN, NICHT RATEN: Bevor Logs archiviert werden, muss der Umfang bekannt sein.
|
|
Kardinalitaet ist der begrenzende Faktor in Prometheus — pro Request eine Serie
|
|
wuerde die TSDB sprengen. Die Aggregation richtet sich nach diesen Zahlen.
|
|
|
|
Aufruf (als root, damit alle User-Homes lesbar sind):
|
|
python3 apache-log-survey.py
|
|
|
|
Ausgabe: Dateien, Zeilen, Zeitraum, Status-Verteilung, Top-Domains.
|
|
Schreibt nichts, aendert nichts.
|
|
"""
|
|
import gzip
|
|
import glob
|
|
import os
|
|
import re
|
|
import sys
|
|
import time
|
|
from collections import Counter, defaultdict
|
|
from datetime import datetime, timezone
|
|
|
|
# Zugriffs- und Fehlerlogs, inkl. rotierter Varianten (.1, .2.gz).
|
|
PATTERNS = [
|
|
"/var/log/apache2/*access*.log", "/var/log/apache2/*access*.log.*",
|
|
"/var/log/apache2/*error*.log", "/var/log/apache2/*error*.log.*",
|
|
"/home/users/*/logs/*/access.log", "/home/users/*/logs/*/access.log.*",
|
|
"/home/users/*/logs/*/error.log", "/home/users/*/logs/*/error.log.*",
|
|
"/var/www/vhosts/*/logs/access_log*", "/var/www/vhosts/*/logs/error_log*",
|
|
]
|
|
|
|
# Combined / Common: ip - - [14/Sep/2026:00:47:01 +0200] "GET /x HTTP/1.1" 200 559
|
|
RE_LINE = re.compile(
|
|
r'^(?P<ip>\S+) \S+ \S+ \[(?P<ts>[^\]]+)\] "(?P<req>[^"]*)" (?P<status>\d{3}|-) (?P<bytes>\d+|-)'
|
|
)
|
|
# Apache-Fehlerlog: [Mon Sep 14 00:47:01.123456 2026] [core:error] [pid 1] msg
|
|
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"]
|
|
|
|
|
|
def open_maybe_gz(path):
|
|
try:
|
|
if path.endswith(".gz"):
|
|
return gzip.open(path, "rt", errors="replace")
|
|
return open(path, "r", errors="replace")
|
|
except OSError:
|
|
return None
|
|
|
|
|
|
def parse_ts(raw):
|
|
"""Zeitstempel parsen und IMMER auf zeitzonenbewusst (UTC) normalisieren.
|
|
|
|
Access-Logs haben eine Zeitzone ([14/Sep/2026:00:47:01 +0200]), Error-Logs
|
|
nicht. Ohne Normalisierung sind die Werte nicht vergleichbar — Python wirft
|
|
dann 'can't compare offset-naive and offset-aware datetimes'. Lokale Zeiten
|
|
werden als Systemzeitzone interpretiert (das ist auch ihre Bedeutung).
|
|
"""
|
|
for fmt in TS_FORMATS:
|
|
try:
|
|
dt = datetime.strptime(raw.strip(), fmt)
|
|
except ValueError:
|
|
continue
|
|
if dt.tzinfo is None:
|
|
dt = dt.astimezone() # lokale Zeit -> mit Offset versehen
|
|
return dt.astimezone(timezone.utc)
|
|
return None
|
|
|
|
|
|
def main():
|
|
# ----------------------------------------------------------------------
|
|
# FORTSCHRITT SICHTBAR MACHEN — sonst sieht der Scan wie ein Haenger aus.
|
|
#
|
|
# Real passiert (x22): der Aufruf war `python3 survey.py 2>&1 | tee bestand.txt`.
|
|
# Das Skript gibt ALLES erst am Ende aus (alle print() stehen hinter der
|
|
# Scan-Schleife), und Python puffert stdout in eine PIPE blockweise (4-8 KB,
|
|
# nicht zeilenweise). Die Gesamtausgabe ist aber nur ~1 KB — sie landet also
|
|
# erst beim Prozessende in der Datei. Bei 2 Mio Zeilen gemessen: 41 s lang
|
|
# 0 Bytes, dann alles auf einmal. Auf einem KeyHelp-Host mit tausenden
|
|
# Logdateien dauert das Minuten und liest sich wie ein Absturz.
|
|
#
|
|
# Drei Gegenmaßnahmen:
|
|
# 1. Zeilenpufferung erzwingen (reconfigure), damit jede Zeile sofort raus ist
|
|
# 2. einen Startbanner VOR dem Scan ausgeben
|
|
# 3. pro Datei eine Fortschrittszeile (mit flush)
|
|
# ----------------------------------------------------------------------
|
|
try:
|
|
sys.stdout.reconfigure(line_buffering=True)
|
|
sys.stderr.reconfigure(line_buffering=True)
|
|
except (AttributeError, ValueError):
|
|
pass # aeltere Python-Version: dann eben gepuffert
|
|
|
|
files = sorted({f for pat in PATTERNS for f in glob.glob(pat)})
|
|
if not files:
|
|
print("Keine Apache-Logs gefunden. Laeuft Apache? (apache2ctl -v)")
|
|
return 1
|
|
|
|
total_bytes = 0
|
|
for _f in files:
|
|
try:
|
|
total_bytes += os.path.getsize(_f)
|
|
except OSError:
|
|
pass
|
|
|
|
def human(n):
|
|
for u in ("B", "KB", "MB", "GB"):
|
|
if n < 1024:
|
|
return f"{n:.1f} {u}"
|
|
n /= 1024
|
|
return f"{n:.1f} TB"
|
|
|
|
print("=" * 72)
|
|
print("APACHE-LOG BESTANDSAUFNAHME")
|
|
print("=" * 72)
|
|
print(f"Scanne {len(files)} Dateien ({human(total_bytes)} auf Platte) …")
|
|
print("(grosse Bestaende dauern; dieser Fortschritt laeuft mit)")
|
|
print()
|
|
|
|
total_lines = 0
|
|
total_parsed = 0
|
|
total_err = 0
|
|
bytes_on_disk = 0
|
|
first_ts = None
|
|
last_ts = None
|
|
by_status = Counter()
|
|
by_domain = Counter()
|
|
by_method = Counter()
|
|
err_levels = Counter()
|
|
# Stunden-Buckets: hier entscheidet sich die Kardinalitaet der Archiv-Metriken.
|
|
hour_domain = set()
|
|
day_domain = set()
|
|
per_file = []
|
|
|
|
t0 = time.time()
|
|
for _idx, path in enumerate(files, 1):
|
|
fh = open_maybe_gz(path)
|
|
if fh is None:
|
|
print(f" [{_idx}/{len(files)}] NICHT LESBAR: {path}", flush=True)
|
|
continue
|
|
try:
|
|
_sz = os.path.getsize(path)
|
|
bytes_on_disk += _sz
|
|
except OSError:
|
|
_sz = 0
|
|
domain = os.path.basename(os.path.dirname(path)) or os.path.basename(path)
|
|
n_lines = n_ok = n_err = 0
|
|
f_first = f_last = None
|
|
with fh:
|
|
for line in fh:
|
|
n_lines += 1
|
|
m = RE_LINE.match(line)
|
|
if m:
|
|
n_ok += 1
|
|
by_status[m.group("status")] += 1
|
|
by_domain[domain] += 1
|
|
req = m.group("req") or ""
|
|
if " " in req:
|
|
by_method[req.split(" ", 1)[0]] += 1
|
|
ts = parse_ts(m.group("ts"))
|
|
if ts is not None:
|
|
if first_ts is None or ts < first_ts:
|
|
first_ts = ts
|
|
if last_ts is None or ts > last_ts:
|
|
last_ts = ts
|
|
if f_first is None or ts < f_first:
|
|
f_first = ts
|
|
if f_last is None or ts > f_last:
|
|
f_last = ts
|
|
hour_domain.add((ts.strftime("%Y-%m-%dT%H"), domain))
|
|
day_domain.add((ts.strftime("%Y-%m-%d"), domain))
|
|
continue
|
|
m = RE_ERR.match(line)
|
|
if m:
|
|
n_err += 1
|
|
err_levels[m.group("lvl").lower()] += 1
|
|
ts = parse_ts(m.group("ts"))
|
|
if ts is not None:
|
|
if first_ts is None or ts < first_ts:
|
|
first_ts = ts
|
|
if last_ts is None or ts > last_ts:
|
|
last_ts = ts
|
|
total_lines += n_lines
|
|
total_parsed += n_ok
|
|
total_err += n_err
|
|
per_file.append((path, n_lines, n_ok, n_err, f_first, f_last))
|
|
# Fortschritt pro Datei — und bei grossen Dateien auch bei jeder Zeile
|
|
# die Marke, damit lange Einzeldateien nicht stumm wirken.
|
|
print(f" [{_idx}/{len(files)}] {n_lines:>10,} Zeilen "
|
|
f"{human(_sz):>9} {path}", flush=True)
|
|
|
|
print()
|
|
print(f"Scan fertig in {time.time() - t0:.1f} s.")
|
|
print()
|
|
print(f"Zeilen total: {total_lines:,}")
|
|
print(f" Zugriffe: {total_parsed:,}")
|
|
print(f" Fehlerlog: {total_err:,}")
|
|
print(f" Unparsbar: {total_lines - total_parsed - total_err:,}")
|
|
if first_ts and last_ts:
|
|
span = last_ts - first_ts
|
|
print(f"Zeitraum: {first_ts:%Y-%m-%d %H:%M} .. {last_ts:%Y-%m-%d %H:%M} ({span.days} Tage)")
|
|
print()
|
|
print("--- Status-Verteilung (Top 10) ---")
|
|
for code, n in by_status.most_common(10):
|
|
print(f" {code} {n:>12,}")
|
|
print()
|
|
print("--- Methoden ---")
|
|
for meth, n in by_method.most_common(8):
|
|
print(f" {meth:<8} {n:>12,}")
|
|
print()
|
|
print("--- Top 15 Domains ---")
|
|
for dom, n in by_domain.most_common(15):
|
|
print(f" {n:>12,} {dom}")
|
|
print(f" ({len(by_domain)} Domains insgesamt)")
|
|
if err_levels:
|
|
print()
|
|
print("--- Fehler-Level ---")
|
|
for lvl, n in err_levels.most_common():
|
|
print(f" {lvl:<10} {n:>10,}")
|
|
print()
|
|
print("=" * 72)
|
|
print("KARDINALITAET der Archiv-Metriken (das entscheidet die Granularitaet)")
|
|
print("=" * 72)
|
|
print(f" pro Stunde + Domain: {len(hour_domain):,} Serien")
|
|
print(f" pro Tag + Domain: {len(day_domain):,} Serien")
|
|
print(f" pro Tag + Domain + Status: ~{len(day_domain) * max(1, len(by_status)):,} Serien")
|
|
print()
|
|
print("Faustregel: unter ~100k Serien ist unkritisch, darueber wird die TSDB traege.")
|
|
print()
|
|
print("--- Groesste Dateien ---")
|
|
for path, n_lines, n_ok, n_err, _, _ in sorted(per_file, key=lambda x: -x[1])[:10]:
|
|
print(f" {n_lines:>10,} Zeilen {path}")
|
|
return 0
|
|
|
|
|
|
if __name__ == "__main__":
|
|
sys.exit(main())
|