Enhance mailtrace script: add dynamic AWK selection, improve log file handling, and refine error messages

2026-07-07 23:15:43 +02:00
parent 312bd8594f
commit 92bae4df99
1 changed files with 240 additions and 56 deletions
@@ -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