#!/usr/bin/env bash set -euo pipefail ############################################################################### # mailtrace # # Ziel: # Postfix-/Amavis-/Dovecot-LMTP-Logzeilen aus /var/log/mail.log korrelieren, # damit du pro Zustell-Outcome (LMTP) sauber siehst: # - from / to # - status / dsn # - Queue-ID (qid) und Header Message-ID # - relay (Amavis-Hop 10024 / Dovecot private/dovecot-lmtp / etc.) # - client / clientip / orig_clientip (extern vs. reinject) # - sasl user (SMTP AUTH) # - TLS Daten (wenn im Log korrelierbar) # # Admin-Notizen (wichtig, wenn du dich über "fehlende Felder" wunderst): # # 1) "qid" = Postfix Queue-ID, nicht Header-Message-ID: # - qid ist ein interner Bezeichner für einen Queue-Entry in Postfix. # - Eine Mail kann mehrere qids bekommen (z.B. durch Content-Filter/Amavis # oder durch Re-Queueing). Daher korrelieren wir zusätzlich über # die Header Message-ID (cleanup: message-id=<...>). # # 2) Warum "helo=" oft leer/nie auftaucht: # - Postfix loggt das HELO/EHLO nicht standardmäßig bei jeder Mail. # - Darum nutzt mailtrace als Fallback den Client-Hostname aus # "client=host[ip]" (hilft für Herkunft/Debugging zuverlässig). # # 3) TLS-Parameter sind manchmal nicht zuordenbar: # - Die Zeile "TLS connection established ..." hat KEINE Queue-ID. # - TLS ist "pro Verbindung", qid entsteht oft erst später im SMTP-Dialog. # - Bei Amavis-Reinject entstehen neue qids (localhost), TLS gehört aber # zur externen Session. # - Wir mappen TLS zunächst per clientip und vererben TLS zusätzlich über # die Header-Message-ID (damit nach Reinject/Mehrfachzustellung möglichst # viel wieder sichtbar wird). # # 4) TLS auf 25/465/587 (dein Setup): # - Je nach master.cf siehst du TLS-Zeilen in: # postfix/smtpd[...] (Port 25) # postfix/submission/smtpd[...] (Port 587, Submission) # postfix/smtps/smtpd[...] (Port 465, SMTPS) # - Dieses Script sucht die generische Zeile: # "TLS connection established from ..." # unabhängig davon, welcher Service-Name davor steht. D.h. TLS von # 25/465/587 wird grundsätzlich erkannt – wenn die Zeile im Log ist. # - Wie viele TLS-Details im Log landen, steuert u.a. smtpd_tls_loglevel. # Höherer Loglevel => mehr Details, aber auch deutlich mehr Logvolumen. # # 5) inbound-only / outbound-only (Heuristik!): # - outbound-only: typischerweise SMTP AUTH (sasl_username) oder lokal # erzeugt (pickup uid=...), ggf. rein lokal/localhost. # - inbound-only : typischerweise von extern (orig_clientip extern), # ohne SMTP AUTH. # - Das sind Regeln “für die Praxis”, keine 100% perfekte Klassifikation. # # 6) Erfolg/Fehlschlag: # - --success zeigt nur Outcomes mit status=success # - --fail zeigt nur Outcomes mit status=failed # - Handoff-Einträge (Übergabe an Amavis) werden von beiden Filtern # ausgeblendet, da sie keine endgültige Zustellung darstellen. # - Erfolgreich definieren wir hier pragmatisch als status in: # sent | delivered | deliverable # # 7) Debug-Modus: # - --debug ergänzt im Output eine Zeile "debug:" mit Gründen, z.B.: # outbound: sasl set / pickup uid / local / no external origin # inbound : external origin + no sasl # Das hilft beim Nachjustieren der Heuristik, ohne den Parser umzubauen. ############################################################################### FOLLOW=0 ALL_LOGS=0 LOG_FILE="" FAIL_ONLY=0 SUCCESS_ONLY=0 ADDR_FILTER="" FROM_FILTER="" TO_FILTER="" QID_FILTER="" MSGID_FILTER="" SENDER_HOST_FILTER="" SENDER_IP_FILTER="" SINCE_PREFIX="" UNTIL_PREFIX="" FORMAT="block" # block|one-line|json NO_NOTE=0 # suppress note lines in block output when TLS unknown DEDUP=0 DEDUP_PREFER="final" # final|amavis|first|last FINAL_ONLY=1 SASL_ONLY=0 NO_SASL=0 INBOUND_ONLY=0 OUTBOUND_ONLY=0 DEBUG=0 SHOW_PROGRESS=0 if [[ -t 2 ]]; then SHOW_PROGRESS=1 fi AWK_BIN="${AWK_BIN:-}" if [[ -z "$AWK_BIN" ]]; then if command -v mawk >/dev/null 2>&1; then AWK_BIN="mawk" elif command -v gawk >/dev/null 2>&1; then AWK_BIN="gawk" else AWK_BIN="awk" fi fi usage() { cat <<'USAGE' mailtrace – Postfix SMTP/LMTP Zustellungen aus /var/log/mail.log korrelieren Ausgabeformate: (default) Blockformat (lesbar, mit Leerzeile davor) --one-line Eine Zeile pro Zustell-Outcome --format json JSON Lines (eine Zeile pro Outcome) Filter: --addr match in from ODER to --from-addr match nur in from --to-addr match nur in to --qid match Queue-ID (Postfix Queue-ID / "qid") --message-id match Header Message-ID (cleanup: message-id=<...>) --sender-host match absendenden Client-Host (client/orig_client) --sender-ip match absendende Client-IP (clientip/orig_clientip; IPv4/IPv6) Status-Filter: --success nur erfolgreiche Endzustellungen (status=success) --fail nur fehlgeschlagene Endzustellungen (status=failed, kein handoff) AUTH / Richtung: --sasl-only nur Einlieferungen mit SMTP AUTH (sasl_username vorhanden) --no-sasl nur Einlieferungen ohne SMTP AUTH (sasl_username fehlt) --inbound-only heuristisch: nur eingehend (extern, i.d.R. ohne AUTH) --outbound-only heuristisch: nur ausgehend (AUTH oder lokal erzeugt) Dedup (ein Eintrag pro Empfänger): --dedup dedupliziere pro (message-id,to). Fallback: (qid,to) falls msgid fehlt --dedup-prefer final|amavis|first|last (Default: final) Umfang: (default) nur endgültige Zustellungen ausgeben (remote SMTP oder lokales LMTP), keine Amavis-Handoffs --final-only wie Default; nur finale Zustellungen anzeigen --all-outcomes alle SMTP/LMTP-Outcomes anzeigen, inkl. Amavis-Handoffs TLS/Notizen: --no-note im Blockformat keine Hinweiszeile ausgeben, wenn TLS nicht korrelierbar ist Debug: --debug ergänzt Debug-Details zur Heuristik/Klassifikation Fortschritt: Bei interaktivem stderr zeigt mailtrace.sh waehrend der Verarbeitung einen kleinen Spinner an. Der Spinner wird vor jeder Ausgabezeile entfernt. Input / Zeitraum: --follow tail -F /var/log/mail.log (live) --all-logs /var/log/mail.log* inkl. .gz (historisch) --log-file einzelne Logdatei (auch .gz); nicht kombinierbar mit --follow/--all-logs --since Timestamp prefix-match (z.B. 2026-01-13T14:47) --until stoppe sobald ts >= prefix (ISO8601 string compare) Beispiele: # Finale Zustellungen eines absendenden Hosts (Default) mailtrace.sh --sender-host web0.warenform.de # Finale Zustellungen einer IPv4-Adresse mailtrace.sh --sender-ip 83.223.85.164 # Finale Zustellungen einer IPv6-Adresse mailtrace.sh --sender-ip 2a01:30:0:13:286:96ff:fe4a:6eee # Nur erfolgreiche finale Zustellungen dieses Hosts mailtrace.sh --sender-host web0.warenform.de --success # Nur fehlgeschlagene Zustellungen einer IP in alten und rotierten Logs mailtrace.sh --all-logs --sender-ip 83.223.85.164 --fail # Voller Verlauf inkl. Amavis-Handoffs und Reinject-Zustellungen mailtrace.sh --sender-host web0.warenform.de --all-outcomes # Kompakte Ausgabe fuer einen Zeitraum mailtrace.sh --sender-host web0.warenform.de --since 2026-01-13T14 --one-line USAGE } # --- CLI Parser -------------------------------------------------------------- while [[ $# -gt 0 ]]; do case "$1" in --follow) FOLLOW=1 ;; --all-logs) ALL_LOGS=1 ;; --log-file) LOG_FILE="${2:-}"; shift ;; --success) SUCCESS_ONLY=1 ;; --fail) FAIL_ONLY=1 ;; --addr) ADDR_FILTER="${2:-}"; shift ;; --from-addr) FROM_FILTER="${2:-}"; shift ;; --to-addr) TO_FILTER="${2:-}"; shift ;; --qid) QID_FILTER="${2:-}"; shift ;; --message-id) MSGID_FILTER="${2:-}"; shift ;; --sender-host) SENDER_HOST_FILTER="${2:-}"; shift ;; --sender-ip) SENDER_IP_FILTER="${2:-}"; shift ;; --since) SINCE_PREFIX="${2:-}"; shift ;; --until) UNTIL_PREFIX="${2:-}"; shift ;; --one-line) FORMAT="one-line" ;; --format) FORMAT="${2:-}"; shift ;; --no-note) NO_NOTE=1 ;; --dedup) DEDUP=1 ;; --dedup-prefer) DEDUP_PREFER="${2:-}"; shift ;; --final-only) FINAL_ONLY=1 ;; --all-outcomes) FINAL_ONLY=0 ;; --sasl-only) SASL_ONLY=1 ;; --no-sasl) NO_SASL=1 ;; --inbound-only) INBOUND_ONLY=1 ;; --outbound-only) OUTBOUND_ONLY=1 ;; --debug) DEBUG=1 ;; --help|-h) usage; exit 0 ;; *) echo "Unbekannte Option: $1" >&2; usage; exit 2 ;; esac shift done # --- Validation -------------------------------------------------------------- if [[ "$FORMAT" != "block" && "$FORMAT" != "one-line" && "$FORMAT" != "json" ]]; then echo "Ungültiges --format: $FORMAT (erlaubt: block|one-line|json)" >&2 exit 2 fi if [[ "$DEDUP_PREFER" != "final" && "$DEDUP_PREFER" != "amavis" && "$DEDUP_PREFER" != "first" && "$DEDUP_PREFER" != "last" ]]; then echo "Ungültiges --dedup-prefer: $DEDUP_PREFER (final|amavis|first|last)" >&2 exit 2 fi if [[ -n "$LOG_FILE" && ($FOLLOW -eq 1 || $ALL_LOGS -eq 1) ]]; then echo "--log-file kann nicht zusammen mit --follow oder --all-logs verwendet werden." >&2 exit 2 fi if [[ -n "$LOG_FILE" && ! -e "$LOG_FILE" ]]; then echo "Datei nicht gefunden: $LOG_FILE" >&2 exit 2 fi if [[ $SUCCESS_ONLY -eq 1 && $FAIL_ONLY -eq 1 ]]; then echo "Bitte nur eines von --success oder --fail verwenden." >&2 exit 2 fi if [[ $SASL_ONLY -eq 1 && $NO_SASL -eq 1 ]]; then echo "Bitte nur eines von --sasl-only oder --no-sasl verwenden." >&2 exit 2 fi if [[ $INBOUND_ONLY -eq 1 && $OUTBOUND_ONLY -eq 1 ]]; then echo "Bitte nur eines von --inbound-only oder --outbound-only verwenden." >&2 exit 2 fi # --- Input selection --------------------------------------------------------- declare -a LOGFILES=() if [[ -n "$LOG_FILE" ]]; then LOGFILES=("$LOG_FILE") elif [[ $ALL_LOGS -eq 1 ]]; then for f in /var/log/mail.log*; do [[ -e "$f" ]] && LOGFILES+=("$f") done else LOGFILES=(/var/log/mail.log) fi if [[ ${#LOGFILES[@]} -eq 0 ]]; then echo "Keine Logdateien gefunden." >&2 exit 2 fi NEED_SUDO=0 declare -a UNREADABLE_FILES=() for f in "${LOGFILES[@]}"; do if ! { : < "$f"; } 2>/dev/null; then NEED_SUDO=1 UNREADABLE_FILES+=("$f") fi done if [[ $NEED_SUDO -eq 1 ]]; then { echo "Using sudo because these selected log file(s) cannot be opened for reading by $(id -un):" echo "Current groups: $(id -nG)" for f in "${UNREADABLE_FILES[@]}"; do if [[ -e "$f" ]]; then ls -ld -- "$f" else printf " missing: %s\n" "$f" fi done } >&2 sudo -v || { echo "sudo authentication failed; cannot read mail log files." >&2; exit 2; } fi run_read() { if [[ $NEED_SUDO -eq 1 ]]; then sudo "$@" else "$@" fi } if [[ $FOLLOW -eq 1 ]]; then INPUT_CMD=(run_read tail -F /var/log/mail.log) else INPUT_CMD=(run_read zcat -f "${LOGFILES[@]}") fi ############################################################################### # gawk core ############################################################################### AWK_PROGRAM="$(mktemp)" AWK_FIFO="$(mktemp -u)" GAWK_ERR="$(mktemp)" mkfifo "$AWK_FIFO" trap 'rm -f "$AWK_PROGRAM" "$AWK_FIFO" "$GAWK_ERR"' EXIT cat > "$AWK_PROGRAM" <<'AWK' ############################################################################### # Helferfunktionen ############################################################################### function token_after(s, prefix, n, r) { n = index(s, prefix) if (n == 0) return "" r = substr(s, n + length(prefix)) sub(/[ ,;].*/, "", r) return r } function angle_after(s, prefix, n, r, e) { n = index(s, prefix) if (n == 0) return "" r = substr(s, n + length(prefix)) e = index(r, ">") if (e == 0) return "" return substr(r, 1, e - 1) } function bracket_after(s, prefix, n, r, b, e) { n = index(s, prefix) if (n == 0) return "" r = substr(s, n + length(prefix)) b = index(r, "[") if (b == 0) return "" r = substr(r, b + 1) e = index(r, "]") if (e == 0) return "" return substr(r, 1, e - 1) } function host_before_bracket_after(s, prefix, n, r, b) { n = index(s, prefix) if (n == 0) return "" r = substr(s, n + length(prefix)) b = index(r, "[") if (b > 0) return substr(r, 1, b - 1) sub(/[ ,;].*/, "", r) return r } function qid_from_line(s) { if (!match(s, / [A-F0-9]{7,20}:/)) return "" return substr(s, RSTART + 1, RLENGTH - 2) } function status_message(s, n, r, p) { n = index(s, " status=") if (n == 0) return "" r = substr(s, n + length(" status=")) p = index(r, " (") if (p == 0 || substr(r, length(r), 1) != ")") return "" return substr(r, p + 2, length(r) - p - 2) } function is_amavis_handoff(relay) { return (relay ~ /(127\.0\.0\.1|localhost).*:1002[456]$/ || relay ~ /\[127\.0\.0\.1\]:1002[456]$/) } function is_success_raw(st) { return (st=="sent" || st=="delivered" || st=="deliverable") } function outcome_status(st, relay) { if (is_amavis_handoff(relay)) return "handoff" return is_success_raw(st) ? "success" : "failed" } function is_success(st) { return (st=="success") } function is_final_relay(relay, transport) { if (is_amavis_handoff(relay)) return 0 if (transport == "lmtp" && relay ~ /private\/dovecot-lmtp/) return 1 if (transport == "smtp") return 1 return 0 } function annotate_sender(from, qid, reason) { if (from != "") return from if (DSN_KIND[qid] != "") { reason = DSN_REASON[qid] if (reason != "") return "MAILER-DAEMON (" DSN_KIND[qid] ": " reason ")" return "MAILER-DAEMON (" DSN_KIND[qid] ")" } return from } function delete_qid_state(qid) { delete FROM[qid] delete TO[qid] delete MID[qid] delete CLIENT[qid] delete CLIENTIP[qid] delete ORIGCLIENT[qid] delete ORIGCLIENTIP[qid] delete HELO[qid] delete SASL[qid] delete UID[qid] delete TLS[qid] delete TLS_P[qid] delete TLS_C[qid] delete TLS_B[qid] delete TMP_EXTCLIENT[qid] delete TMP_EXTCLIENTIP[qid] delete DSN_KIND[qid] delete DSN_REASON[qid] delete LAST_FAILURE[qid] } function jesc(s) { gsub(/\\/,"\\\\",s); gsub(/"/,"\\\"",s) gsub(/\t/,"\\t",s); gsub(/\r/,"\\r",s); gsub(/\n/,"\\n",s) return s } function is_local_ip(ip) { return (ip=="" || ip=="-" || ip=="127.0.0.1" || ip=="::1") } ############################################################################### # Pretty printing (Blockausgabe) ############################################################################### BEGIN { labels[1]="time"; labels[2]="from"; labels[3]="to"; labels[4]="status"; labels[5]="dsn" labels[6]="qid"; labels[7]="msgid"; labels[8]="relay"; labels[9]="client"; labels[10]="clientip" labels[11]="orig_client"; labels[12]="orig_clientip"; labels[13]="helo"; labels[14]="sasl"; labels[15]="source" labels[16]="tls"; labels[17]="tls_proto"; labels[18]="tls_cipher"; labels[19]="tls_bits"; labels[20]="note"; labels[21]="debug" maxw = 0 for (i=1; i in labels; i++) { w = length(labels[i] ":"); if (w > maxw) maxw = w } LABEL_W = maxw progress_tick() } function pl(label, value) { printf "%-*s %s\n", LABEL_W, label ":", value } ############################################################################### # Quelle klassifizieren (grob) ############################################################################### function classify_source(qid, mid, relay, extip) { extip = (mid != "" && EXTCLIENTIP_BY_MSGID[mid] ? EXTCLIENTIP_BY_MSGID[mid] : "") if (relay ~ /127\.0\.0\.1:10024/ || relay ~ /\[127\.0\.0\.1\]:10024/) return "amavis" if (extip != "" && !is_local_ip(extip)) return "smtpd" if (is_local_ip(CLIENTIP[qid]) && extip != "") return "amavis" if (UID[qid] != "") return "local" return "local" } ############################################################################### # TLS Korrelation ############################################################################### function remember_tls(line, ip, proto, cipher, bits, n, r, p) { ip = bracket_after(line, " from ") if (ip == "") return n = index(line, ": TLS") if (n > 0) { r = substr(line, n + 2) p = index(r, " with cipher") if (p > 0) proto = substr(r, 1, p - 1) } cipher = token_after(line, " with cipher ") n = index(line, " (") if (n > 0) { r = substr(line, n + 2) p = index(r, " bits)") if (p > 0) bits = substr(r, 1, p - 1) } TLS_SEEN[ip] = 1 TLS_PROTO[ip] = (proto != "" ? proto : "-") TLS_CIPHER[ip] = (cipher != "" ? cipher : "-") TLS_BITS[ip] = (bits != "" ? bits : "-") } ############################################################################### # Dedup: Ein Eintrag pro (message-id,to) (fallback: (qid,to)) ############################################################################### function dedup_score(relay, idx) { if (dedup_prefer == "first") return -idx if (dedup_prefer == "last") return idx if (dedup_prefer == "final") { if (!is_amavis_handoff(relay)) return 1000000000 + idx; return idx } if (dedup_prefer == "amavis") { if (relay ~ /127\.0\.0\.1:10024/ || relay ~ /\[127\.0\.0\.1\]:10024/) return 1000000000 + idx; return idx } return idx } ############################################################################### # inbound/outbound Heuristik + Debug-Gründe ############################################################################### function outbound_reason(sasl, uid, orig_ip, src, r) { r="" if (sasl != "" && sasl != "-") r = r (r?"; ":"") "sasl set" if (uid != "" && uid != "-") r = r (r?"; ":"") "pickup uid" if (src == "local") r = r (r?"; ":"") "source=local" if (is_local_ip(orig_ip)) r = r (r?"; ":"") "no external origin" if (r=="") r="(none)" return r } function inbound_reason(sasl, orig_ip, src, r) { r="" if (sasl != "" && sasl != "-") r = r (r?"; ":"") "sasl set (blocks inbound)" if (!is_local_ip(orig_ip)) r = r (r?"; ":"") "external origin" if (src == "smtpd") r = r (r?"; ":"") "source=smtpd" if (r=="") r="(none)" return r } function is_outbound(sasl, uid, orig_ip, src) { if (sasl != "" && sasl != "-") return 1 if (uid != "" && uid != "-") return 1 if (src == "local") return 1 if (is_local_ip(orig_ip)) return 1 return 0 } function is_inbound(sasl, orig_ip, src) { if (sasl != "" && sasl != "-") return 0 if (!is_local_ip(orig_ip)) return 1 if (src == "smtpd") return 1 return 0 } ############################################################################### # Fortschrittsanzeige auf stderr ############################################################################### function progress_tick( now, ch) { if (show_progress != 1) return now = systime() if (PROGRESS_LAST != "" && now - PROGRESS_LAST < 2) return PROGRESS_LAST = now PROGRESS_IDX = (PROGRESS_IDX % 4) + 1 ch = substr("|/-\\", PROGRESS_IDX, 1) printf "\r%s", ch > "/dev/stderr" fflush("/dev/stderr") PROGRESS_DRAWN = 1 } function progress_clear() { if (show_progress != 1 || PROGRESS_DRAWN != 1) return printf "\r \r" > "/dev/stderr" fflush("/dev/stderr") PROGRESS_DRAWN = 0 } ############################################################################### # Ausgabe ############################################################################### function count_record(k) { STAT_TOTAL++ if (REC_status[k] == "success") STAT_SUCCESS++ if (REC_status[k] == "failed") STAT_FAILED++ } function emit_stats( width) { progress_clear() if (out_format == "json") { printf "{\"type\":\"stats\",\"total\":%d,\"success\":%d,\"failed\":%d}\n", STAT_TOTAL+0, STAT_SUCCESS+0, STAT_FAILED+0 return } if (out_format == "one-line") { printf "stats\ttotal=%d\tsuccess=%d\tfailed=%d\n", STAT_TOTAL+0, STAT_SUCCESS+0, STAT_FAILED+0 return } width = length(STAT_TOTAL+0) if (length(STAT_SUCCESS+0) > width) width = length(STAT_SUCCESS+0) if (length(STAT_FAILED+0) > width) width = length(STAT_FAILED+0) print "" print "Statistics:" printf " total: %*d\n", width, STAT_TOTAL+0 printf " success: %*d\n", width, STAT_SUCCESS+0 printf " failed: %*d\n", width, STAT_FAILED+0 } function emit_record(k, tls_part) { progress_clear() count_record(k) if (out_format == "one-line") { tls_part = "" if (REC_tls[k] != "" && REC_tls[k] != "-") { tls_part = sprintf("\ttls=%s\tproto=%s\tcipher=%s\tbits=%s", REC_tls[k], (REC_tls_proto[k]?REC_tls_proto[k]:"-"), (REC_tls_cipher[k]?REC_tls_cipher[k]:"-"), (REC_tls_bits[k]?REC_tls_bits[k]:"-")) } if (debug_mode == 1 && REC_debug[k] != "") { tls_part = tls_part sprintf("\tdebug=%s", REC_debug[k]) } printf "%s\tfrom=%s\tto=%s\tstatus=%s\tdsn=%s\tqid=%s\tmsgid=<%s>\tsource=%s%s\trelay=%s\tclient=%s\tclientip=%s\torig_client=%s\torig_clientip=%s\thelo=%s\tsasl=%s\t%s\n", REC_time[k], REC_from[k], REC_to[k], REC_status[k], REC_dsn[k], REC_qid[k], (REC_msgid[k]?REC_msgid[k]:"-"), REC_source[k], tls_part, REC_relay[k], REC_client[k], REC_clientip[k], REC_orig_client[k], REC_orig_clientip[k], REC_helo[k], REC_sasl[k], REC_msg[k] return } if (out_format == "json") { printf "{" printf "\"time\":\"%s\",", jesc(REC_time[k]) printf "\"from\":\"%s\",", jesc(REC_from[k]) printf "\"to\":\"%s\",", jesc(REC_to[k]) printf "\"status\":\"%s\",", jesc(REC_status[k]) printf "\"dsn\":\"%s\",", jesc(REC_dsn[k]) printf "\"qid\":\"%s\",", jesc(REC_qid[k]) printf "\"message_id\":\"%s\",", jesc(REC_msgid[k]?REC_msgid[k]:"-") printf "\"source\":\"%s\",", jesc(REC_source[k]) if (REC_tls[k] != "" && REC_tls[k] != "-") { printf "\"tls\":\"%s\",", jesc(REC_tls[k]) printf "\"tls_proto\":\"%s\",", jesc(REC_tls_proto[k]?REC_tls_proto[k]:"-") printf "\"tls_cipher\":\"%s\",", jesc(REC_tls_cipher[k]?REC_tls_cipher[k]:"-") printf "\"tls_bits\":\"%s\",", jesc(REC_tls_bits[k]?REC_tls_bits[k]:"-") } if (debug_mode == 1 && REC_debug[k] != "") { printf "\"debug\":\"%s\",", jesc(REC_debug[k]) } printf "\"relay\":\"%s\",", jesc(REC_relay[k]) printf "\"client\":\"%s\",", jesc(REC_client[k]) printf "\"clientip\":\"%s\",", jesc(REC_clientip[k]) printf "\"orig_client\":\"%s\",", jesc(REC_orig_client[k]) printf "\"orig_clientip\":\"%s\",", jesc(REC_orig_clientip[k]) printf "\"helo\":\"%s\",", jesc(REC_helo[k]) printf "\"sasl\":\"%s\",", jesc(REC_sasl[k]) printf "\"message\":\"%s\"", jesc(REC_msg[k]) printf "}\n" return } # Blockformat print "" pl("time", REC_time[k]); pl("from", REC_from[k]); pl("to", REC_to[k]); pl("status", REC_status[k]); pl("dsn", REC_dsn[k]) pl("qid", REC_qid[k]); pl("msgid", "<" (REC_msgid[k]?REC_msgid[k]:"-") ">"); pl("relay", REC_relay[k]) pl("client", REC_client[k]); pl("clientip", REC_clientip[k]) pl("orig_client", REC_orig_client[k]); pl("orig_clientip", REC_orig_clientip[k]) pl("helo", REC_helo[k]); pl("sasl", REC_sasl[k]); pl("source", REC_source[k]) if (REC_tls[k] != "" && REC_tls[k] != "-") { pl("tls", REC_tls[k]) pl("tls_proto", (REC_tls_proto[k]?REC_tls_proto[k]:"-")) pl("tls_cipher", (REC_tls_cipher[k]?REC_tls_cipher[k]:"-")) pl("tls_bits", (REC_tls_bits[k]?REC_tls_bits[k]:"-")) } else if (no_note != 1) { pl("note", "TLS-Info im Log nicht eindeutig korrelierbar") } if (debug_mode == 1 && REC_debug[k] != "") { pl("debug", REC_debug[k]) } if (REC_msg[k] != "") print "\n" REC_msg[k] } ############################################################################### # Dedup Speicherlogik ############################################################################### function store_record(key, score, idx, time, from, to, status, dsn, qid, msgid, relay, client, clientip, orig_client, orig_clientip, helo, sasl, source, tls, tls_proto, tls_cipher, tls_bits, msg, debug) { if (follow_mode == 1) { # Live: first wins, direkt emit if (!(key in BEST_score)) { BEST_score[key] = score BEST_idx[key] = idx REC_time[key]=time; REC_from[key]=from; REC_to[key]=to; REC_status[key]=status; REC_dsn[key]=dsn REC_qid[key]=qid; REC_msgid[key]=msgid; REC_relay[key]=relay; REC_client[key]=client; REC_clientip[key]=clientip REC_orig_client[key]=orig_client; REC_orig_clientip[key]=orig_clientip; REC_helo[key]=helo; REC_sasl[key]=sasl REC_source[key]=source; REC_tls[key]=tls; REC_tls_proto[key]=tls_proto; REC_tls_cipher[key]=tls_cipher; REC_tls_bits[key]=tls_bits REC_msg[key]=msg; REC_debug[key]=debug emit_record(key) } return } # Historisch: best-of nach score if (!(key in BEST_score) || score > BEST_score[key]) { BEST_score[key] = score BEST_idx[key] = idx REC_time[key]=time; REC_from[key]=from; REC_to[key]=to; REC_status[key]=status; REC_dsn[key]=dsn REC_qid[key]=qid; REC_msgid[key]=msgid; REC_relay[key]=relay; REC_client[key]=client; REC_clientip[key]=clientip REC_orig_client[key]=orig_client; REC_orig_clientip[key]=orig_clientip; REC_helo[key]=helo; REC_sasl[key]=sasl REC_source[key]=source; REC_tls[key]=tls; REC_tls_proto[key]=tls_proto; REC_tls_cipher[key]=tls_cipher; REC_tls_bits[key]=tls_bits REC_msg[key]=msg; REC_debug[key]=debug } } END { if (dedup == 1 && follow_mode == 0) { # Ausgabe in Einlesereihenfolge: sortiere keys nach BEST_idx (einfaches insertion sort) n=0 for (k in BEST_idx) { n++; KEYS[n]=k } for (i=2; i<=n; i++) { k=KEYS[i]; j=i-1 while (j>=1 && BEST_idx[KEYS[j]] > BEST_idx[k]) { KEYS[j+1]=KEYS[j]; j-- } KEYS[j+1]=k } for (i=1; i<=n; i++) emit_record(KEYS[i]) } emit_stats() } ############################################################################### # Hauptparser: pro Logzeile State sammeln, bei Zustell-Outcome ausgeben ############################################################################### { progress_tick() ts = $1 # Zeitraumfilter (prefix match; ISO8601) if (since_prefix != "" && index(ts, since_prefix) != 1) next if (until_prefix != "" && ts >= until_prefix) exit # TLS: keine qid -> per IP merken if ($0 ~ /TLS connection established from /) { remember_tls($0); next } # Postfix Queue-ID (qid) aus Zeile ziehen qid = qid_from_line($0) if (qid == "") next if (qid_filter != "" && index(qid, qid_filter) == 0) next if ($0 ~ / postfix\/qmgr\[/ && $0 ~ / removed$/) { delete_qid_state(qid) next } # Envelope from/to sammeln if ($0 ~ / from=<[^>]*>/) FROM[qid] = angle_after($0, " from=<") if ($0 ~ / to=<[^>]*>/) TO[qid] = angle_after($0, " to=<") # cleanup: Header Message-ID sammeln + Ursprung/TLS an msgid binden if ($0 ~ / postfix\/cleanup\[/ && $0 ~ / message-id=<[^>]+>/) { MID[qid] = angle_after($0, " message-id=<") # Externen Ursprung puffern und an msgid binden (für spätere qids) if (MID[qid] != "" && TMP_EXTCLIENT[qid] != "") { EXTCLIENT_BY_MSGID[MID[qid]] = TMP_EXTCLIENT[qid] EXTCLIENTIP_BY_MSGID[MID[qid]] = TMP_EXTCLIENTIP[qid] TMP_EXTCLIENT[qid] = ""; TMP_EXTCLIENTIP[qid] = "" } # TLS an msgid binden (wenn TLS schon auf qid bekannt ist) if (MID[qid] != "" && TLS[qid] != "" && TLS[qid] != "-") { TLS_BY_MSGID[MID[qid]] = TLS[qid] TLS_P_BY_MSGID[MID[qid]] = (TLS_P[qid] ? TLS_P[qid] : "-") TLS_C_BY_MSGID[MID[qid]] = (TLS_C[qid] ? TLS_C[qid] : "-") TLS_B_BY_MSGID[MID[qid]] = (TLS_B[qid] ? TLS_B[qid] : "-") } } # pickup uid: lokal erzeugt if ($0 ~ / postfix\/pickup\[/ && $0 ~ / uid=/) UID[qid] = token_after($0, " uid=") # postfix/bounce: neue DSN-Queue-ID einer fehlgeschlagenen Ursprungszustellung zuordnen if ($0 ~ / postfix\/bounce\[/ && $0 ~ / sender non-delivery notification: /) { newqid = token_after($0, " sender non-delivery notification: ") if (newqid != "") { DSN_KIND[newqid] = "non-delivery notification" if (LAST_FAILURE[qid] != "") DSN_REASON[newqid] = LAST_FAILURE[qid] } } # smtpd: client/orig_client, HELO fallback, TLS map via clientip if ($0 ~ / postfix\/smtpd\[/ && $0 ~ / client=/) { CLIENT[qid] = host_before_bracket_after($0, " client=") CLIENTIP[qid] = bracket_after($0, " client=") if ($0 ~ / orig_client=/) { ORIGCLIENT[qid] = host_before_bracket_after($0, " orig_client=") ORIGCLIENTIP[qid] = bracket_after($0, " orig_client=") } # externen Ursprung puffern bis cleanup (msgid) kommt if (!is_local_ip(CLIENTIP[qid])) { TMP_EXTCLIENT[qid] = CLIENT[qid] TMP_EXTCLIENTIP[qid] = CLIENTIP[qid] } # HELO auslesen (falls vorhanden), sonst fallback auf client host if ($0 ~ / helo=/) { he = angle_after($0, " helo=<") if (he == "") he = token_after($0, " helo=") if (he != "") HELO[qid] = he } if (!HELO[qid] && CLIENT[qid] != "") HELO[qid] = CLIENT[qid] # TLS pro clientip übernehmen ip = CLIENTIP[qid] if (ip != "" && TLS_SEEN[ip]) { TLS[qid]="yes"; TLS_P[qid]=TLS_PROTO[ip]; TLS_C[qid]=TLS_CIPHER[ip]; TLS_B[qid]=TLS_BITS[ip] } else { if (!is_local_ip(ip)) TLS[qid]="no" } } # SMTP AUTH User if ($0 ~ / postfix\/smtpd\[/ && $0 ~ / sasl_username=/) SASL[qid] = token_after($0, " sasl_username=") # ===================== Delivery Outcome (Ausgabezeitpunkt) ===================== if ($0 ~ / postfix\/(lmtp|smtp)\[/ && $0 ~ / status=/) { raw_status = token_after($0, " status=") transport = ($0 ~ / postfix\/smtp\[/ ? "smtp" : "lmtp") from = (FROM[qid] ? FROM[qid] : "-") to = (TO[qid] ? TO[qid] : "-") mid = (MID[qid] ? MID[qid] : "") # Allgemeine Filter if (msgid_filter != "" && (mid == "" || index(mid, msgid_filter) == 0)) next if (addr_filter != "" && index(from, addr_filter)==0 && index(to, addr_filter)==0) next if (from_filter != "" && index(from, from_filter)==0) next if (to_filter != "" && index(to, to_filter)==0) next dsn = token_after($0, " dsn=") relay = token_after($0, " relay=") if (final_only == 1 && !is_final_relay(relay, transport)) next status = outcome_status(raw_status, relay) msg = status_message($0) if (status == "failed" && msg != "") LAST_FAILURE[qid] = msg # Statusfilter if (success_only == 1 && status != "success") next if (fail_only == 1 && status != "failed") next client = (CLIENT[qid] ? CLIENT[qid] : "-") clientip = (CLIENTIP[qid] ? CLIENTIP[qid] : "-") helo = (HELO[qid] ? HELO[qid] : "-") sasl = (SASL[qid] ? SASL[qid] : "-") uid = (UID[qid] ? UID[qid] : "") if (from == "-") from = annotate_sender("", qid) # SASL Filter if (sasl_only == 1 && (sasl == "" || sasl == "-")) next if (no_sasl == 1 && (sasl != "" && sasl != "-")) next # Ursprung via msgid zurückführen (Amavis) orig_client = (mid != "" && EXTCLIENT_BY_MSGID[mid] ? EXTCLIENT_BY_MSGID[mid] : (ORIGCLIENT[qid]?ORIGCLIENT[qid]:"-")) orig_clientip = (mid != "" && EXTCLIENTIP_BY_MSGID[mid] ? EXTCLIENTIP_BY_MSGID[mid] : (ORIGCLIENTIP[qid]?ORIGCLIENTIP[qid]:"-")) # Absender-Host/IP Filter: direkter client plus rekonstruierter Ursprung. if (sender_host_filter != "" && index(client, sender_host_filter)==0 && index(orig_client, sender_host_filter)==0) next if (sender_ip_filter != "" && index(clientip, sender_ip_filter)==0 && index(orig_clientip, sender_ip_filter)==0) next # TLS: qid oder msgid-Vererbung tls = (TLS[qid] ? TLS[qid] : "") tls_proto = (TLS_P[qid] ? TLS_P[qid] : "") tls_cipher= (TLS_C[qid] ? TLS_C[qid] : "") tls_bits = (TLS_B[qid] ? TLS_B[qid] : "") if (tls == "" && mid != "" && TLS_BY_MSGID[mid] != "") { tls = TLS_BY_MSGID[mid] tls_proto = TLS_P_BY_MSGID[mid] tls_cipher= TLS_C_BY_MSGID[mid] tls_bits = TLS_B_BY_MSGID[mid] } source = classify_source(qid, mid, relay) # inbound/outbound Filter + Debug-Grund debug = "" if (debug_mode == 1) { debug = "outbound_reason=" outbound_reason(sasl, uid, orig_clientip, source) \ " | inbound_reason=" inbound_reason(sasl, orig_clientip, source) } if (inbound_only == 1 && !is_inbound(sasl, orig_clientip, source)) next if (outbound_only == 1 && !is_outbound(sasl, uid, orig_clientip, source)) next # Dedup oder Direktausgabe if (dedup == 1) { idx = ++SEQ key = (mid != "" ? mid : qid) SUBSEP to score = dedup_score(relay, idx) store_record(key, score, idx, ts, from, to, status, (dsn?dsn:"-"), qid, (mid?mid:"-"), (relay?relay:"-"), client, clientip, orig_client, orig_clientip, helo, sasl, source, (tls!=""?tls:""), (tls_proto!=""?tls_proto:""), (tls_cipher!=""?tls_cipher:""), (tls_bits!=""?tls_bits:""), msg, debug) next } k="__direct__" REC_time[k]=ts; REC_from[k]=from; REC_to[k]=to; REC_status[k]=status; REC_dsn[k]=(dsn?dsn:"-") REC_qid[k]=qid; REC_msgid[k]=(mid?mid:"-"); REC_relay[k]=(relay?relay:"-") REC_client[k]=client; REC_clientip[k]=clientip REC_orig_client[k]=orig_client; REC_orig_clientip[k]=orig_clientip REC_helo[k]=helo; REC_sasl[k]=sasl; REC_source[k]=source REC_tls[k]=(tls!=""?tls:""); REC_tls_proto[k]=(tls_proto!=""?tls_proto:""); REC_tls_cipher[k]=(tls_cipher!=""?tls_cipher:""); REC_tls_bits[k]=(tls_bits!=""?tls_bits:"") REC_msg[k]=msg; REC_debug[k]=debug emit_record(k) } } AWK set +e "${INPUT_CMD[@]}" > "$AWK_FIFO" & input_pid=$! bash -c ' awk_bin=$1 shift "$awk_bin" "$@" st=$? exit "$st" ' _ "$AWK_BIN" \ -v success_only="$SUCCESS_ONLY" \ -v fail_only="$FAIL_ONLY" \ -v addr_filter="$ADDR_FILTER" \ -v from_filter="$FROM_FILTER" \ -v to_filter="$TO_FILTER" \ -v qid_filter="$QID_FILTER" \ -v msgid_filter="$MSGID_FILTER" \ -v sender_host_filter="$SENDER_HOST_FILTER" \ -v sender_ip_filter="$SENDER_IP_FILTER" \ -v since_prefix="$SINCE_PREFIX" \ -v until_prefix="$UNTIL_PREFIX" \ -v out_format="$FORMAT" \ -v no_note="$NO_NOTE" \ -v dedup="$DEDUP" \ -v dedup_prefer="$DEDUP_PREFER" \ -v final_only="$FINAL_ONLY" \ -v follow_mode="$FOLLOW" \ -v sasl_only="$SASL_ONLY" \ -v no_sasl="$NO_SASL" \ -v inbound_only="$INBOUND_ONLY" \ -v outbound_only="$OUTBOUND_ONLY" \ -v debug_mode="$DEBUG" \ -v show_progress="$SHOW_PROGRESS" \ -f "$AWK_PROGRAM" < "$AWK_FIFO" 2>"$GAWK_ERR" gawk_status=$? wait "$input_pid" input_status=$? set -e if [[ $gawk_status -eq 139 ]]; then grep -v -E '(Segmentation fault|Speicherzugriffsfehler).*(gawk|awk)' "$GAWK_ERR" >&2 || true echo "ERROR: $AWK_BIN crashed with a segmentation fault while parsing the mail log." >&2 echo " Try narrowing the input with --since/--until or --log-file, or set AWK_BIN=gawk/mawk explicitly." >&2 exit 1 fi if [[ $gawk_status -ne 0 ]]; then cat "$GAWK_ERR" >&2 echo "ERROR: $AWK_BIN failed while parsing the mail log (exit status: $gawk_status)." >&2 exit "$gawk_status" fi # 141 = SIGPIPE. This can happen when awk exits intentionally, for example # because --until stopped parsing before zcat/cat consumed all input. if [[ $input_status -ne 0 && $input_status -ne 141 ]]; then echo "ERROR: input command failed while reading the mail log (exit status: $input_status)." >&2 exit "$input_status" fi