From 92bae4df998b18762962500bd273f530de11b7e3 Mon Sep 17 00:00:00 2001 From: Christoph Date: Tue, 7 Jul 2026 23:15:43 +0200 Subject: [PATCH] Enhance mailtrace script: add dynamic AWK selection, improve log file handling, and refine error messages --- mailtrace.sh | 296 +++++++++++++++++++++++++++++++++++++++++---------- 1 file changed, 240 insertions(+), 56 deletions(-) diff --git a/mailtrace.sh b/mailtrace.sh index 10fc8a9..bc5ca8c 100755 --- a/mailtrace.sh +++ b/mailtrace.sh @@ -107,6 +107,17 @@ 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 @@ -233,8 +244,8 @@ 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" && ! -r "$LOG_FILE" ]]; then - echo "Datei nicht lesbar: $LOG_FILE" >&2 +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 @@ -251,47 +262,120 @@ if [[ $INBOUND_ONLY -eq 1 && $OUTBOUND_ONLY -eq 1 ]]; then fi # --- Input selection --------------------------------------------------------- -if [[ $FOLLOW -eq 1 ]]; then - INPUT_CMD=(sudo tail -F /var/log/mail.log) -elif [[ -n "$LOG_FILE" ]]; then - INPUT_CMD=(sudo zcat -f "$LOG_FILE") +declare -a LOGFILES=() + +if [[ -n "$LOG_FILE" ]]; then + LOGFILES=("$LOG_FILE") elif [[ $ALL_LOGS -eq 1 ]]; then - INPUT_CMD=(sudo zcat -f /var/log/mail.log*) + for f in /var/log/mail.log*; do + [[ -e "$f" ]] && LOGFILES+=("$f") + done else - INPUT_CMD=(sudo cat /var/log/mail.log) + 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 ############################################################################### -"${INPUT_CMD[@]}" | gawk \ - -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" ' +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 grab(re, s, m) { return match(s, re, m) ? m[1] : "" } +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]$/) } @@ -317,6 +401,28 @@ function annotate_sender(from, qid, reason) { 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) @@ -354,12 +460,23 @@ function classify_source(qid, mid, relay, extip) { ############################################################################### # TLS Korrelation ############################################################################### -function remember_tls(line, ip, proto, cipher, bits) { - ip = grab(" from [^\\[]+\\[([^\\]]+)\\]", line) +function remember_tls(line, ip, proto, cipher, bits, n, r, p) { + ip = bracket_after(line, " from ") if (ip == "") return - proto = grab(": (TLS[^ ]+) with cipher", line) - cipher = grab(" with cipher ([^ ]+)", line) - bits = grab(" \\(([0-9]+/[0-9]+) bits\\)", line) + + 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 : "-") @@ -619,17 +736,22 @@ END { if ($0 ~ /TLS connection established from /) { remember_tls($0); next } # Postfix Queue-ID (qid) aus Zeile ziehen - qid = grab(" ([A-F0-9]{7,20}):", $0) + 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] = grab(" from=<([^>]*)>", $0) - if ($0 ~ / to=<[^>]*>/) TO[qid] = grab(" to=<([^>]*)>", $0) + 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] = grab(" message-id=<([^>]+)>", $0) + 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] != "") { @@ -648,11 +770,11 @@ END { } # pickup uid: lokal erzeugt - if ($0 ~ / postfix\/pickup\[/ && $0 ~ / uid=/) UID[qid] = grab(" uid=([0-9]+)", $0) + 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 = grab(" sender non-delivery notification: ([A-F0-9]{7,20})", $0) + 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] @@ -661,12 +783,12 @@ END { # smtpd: client/orig_client, HELO fallback, TLS map via clientip if ($0 ~ / postfix\/smtpd\[/ && $0 ~ / client=/) { - CLIENT[qid] = grab(" client=([^\\[]+)", $0) - CLIENTIP[qid] = grab(" client=[^\\[]+\\[([^\\]]+)\\]", $0) + CLIENT[qid] = host_before_bracket_after($0, " client=") + CLIENTIP[qid] = bracket_after($0, " client=") if ($0 ~ / orig_client=/) { - ORIGCLIENT[qid] = grab(" orig_client=([^\\[]+)", $0) - ORIGCLIENTIP[qid] = grab(" orig_client=[^\\[]+\\[([^\\]]+)\\]", $0) + ORIGCLIENT[qid] = host_before_bracket_after($0, " orig_client=") + ORIGCLIENTIP[qid] = bracket_after($0, " orig_client=") } # externen Ursprung puffern bis cleanup (msgid) kommt @@ -677,8 +799,8 @@ END { # HELO auslesen (falls vorhanden), sonst fallback auf client host if ($0 ~ / helo=/) { - he = grab(" helo=<([^>]+)>", $0) - if (he == "") he = grab(" helo=([^ ,;]+)", $0) + 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] @@ -693,11 +815,11 @@ END { } # SMTP AUTH User - if ($0 ~ / postfix\/smtpd\[/ && $0 ~ / sasl_username=/) SASL[qid] = grab(" sasl_username=([^, ]+)", $0) + 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 = grab(" status=([^ ]+)", $0) + raw_status = token_after($0, " status=") transport = ($0 ~ / postfix\/smtp\[/ ? "smtp" : "lmtp") from = (FROM[qid] ? FROM[qid] : "-") @@ -710,11 +832,11 @@ END { if (from_filter != "" && index(from, from_filter)==0) next if (to_filter != "" && index(to, to_filter)==0) next - dsn = grab(" dsn=([^, ]+)", $0) - relay = grab(" relay=([^, ]+)", $0) + 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 = grab(" status=[^ ]+ \\((.*)\\)$", $0) + msg = status_message($0) if (status == "failed" && msg != "") LAST_FAILURE[qid] = msg # Statusfilter @@ -793,4 +915,66 @@ END { 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