Parse postfix TLS features

.github/workflows/test_config_syntax.yml

@@ -5,7 +5,7 @@ jobs:
     runs-on: ubuntu-latest
     strategy:
       matrix:
-        logstash-version: ['8.14.1', '7.17.22']
+        logstash-version: ['9.2.1', '8.19.7', '7.17.28']
     steps:
       - name: Checkout code
         uses: actions/checkout@v4

.github/workflows/test_grok_patterns.yml

@@ -10,6 +10,6 @@ jobs:
           submodules: true
       - uses: ruby/setup-ruby@v1
         with:
-          ruby-version: '3.2'
+          ruby-version: '3.4'
       - run: gem install jls-grok minitest
       - run: ruby test/test.rb

50-filter-postfix.conf

@@ -222,6 +222,14 @@ filter {
                 remove_field   => [ "postfix_delays" ]
             }
         }
+        if [postfix_tls] {
+            grok {
+                patterns_dir   => "/etc/logstash/patterns.d"
+                match          => ["postfix_tls", "^%{POSTFIX_TLS_FEATURES}$"]
+                tag_on_failure => [ "_grok_kv_postfix_tls_nomatch" ]
+                remove_field   => [ "postfix_tls" ]
+            }
+        }
     }
 
     # process command counter data if it exists
@@ -289,6 +297,12 @@ filter {
             "postfix_delay_transmission", "float",
             "postfix_postscreen_violation_time", "float"
         ]
+        gsub => [
+            # rewrite some extracted values
+            "postfix_tls_policy_undecided", "\?", "true",
+            "postfix_requiretls_policy_undecided", "\?", "true",
+            "postfix_requiretls_policy_violation", "\!", "true",
+            "postfix_requiretls", "requiretls", "true"
+        ]
     }
 }
-

postfix.grok

@@ -121,6 +121,10 @@ POSTFIX_VERIFY_CACHE cache %{DATA} (?<postfix_verify_cleanup_type>(full|partial)
 # local patterns
 POSTFIX_LOCAL_DELIVERY %{POSTFIX_KEYVALUE} status=%{STATUS_WORD:postfix_status}( \(%{GREEDYDATA:postfix_local_response}\))?
 
+# TLS features
+POSTFIX_TLS_FEAT_REQUIRETLS (?<postfix_requiretls_policy_violation>\!)?(?<postfix_requiretls>requiretls)(:(?<postfix_requiretls_downgrade_level>\w+))?(?<postfix_requiretls_policy_undecided>\?)?
+POSTFIX_TLS_FEATURES (?<postfix_tls_security_level>\w+)(:(?<postfix_tls_downgrade_level>\w+))?(?<postfix_tls_policy_undecided>\?)?(/%{POSTFIX_TLS_FEAT_REQUIRETLS})?
+
 # aggregate all patterns
 POSTFIX_SMTPD %{POSTFIX_SMTPD_CONNECT}|%{POSTFIX_SMTPD_DISCONNECT}|%{POSTFIX_SMTPD_LOSTCONN}|%{POSTFIX_SMTPD_NOQUEUE}|%{POSTFIX_SMTPD_PIPELINING}|%{POSTFIX_TLSCONN}|%{POSTFIX_WARNING}|%{POSTFIX_SMTPD_PROXY}|%{POSTFIX_KEYVALUE}
 POSTFIX_CLEANUP %{POSTFIX_CLEANUP_MESSAGEID}|%{POSTFIX_CLEANUP_MILTER}|%{POSTFIX_CLEANUP_PREPEND}|%{POSTFIX_WARNING}|%{POSTFIX_KEYVALUE}

test/tls_features_0001.yaml

@@ -0,0 +1,6 @@
+pattern: "^%{POSTFIX_SMTP}$"
+# TLS features: security level only (single word)
+data: "7EE668039: to=<user@example.com>, relay=mail.example.com[1.2.3.4]:25, delay=3.6, delays=0.08/0.02/0.85/0.14, tls=dane, dsn=2.1.5, status=sent (250 2.0.0 Ok: queued as 153053D)"
+results:
+    postfix_queueid: 7EE668039
+    postfix_keyvalue_data: "to=<user@example.com>, relay=mail.example.com[1.2.3.4]:25, delay=3.6, delays=0.08/0.02/0.85/0.14, tls=dane, dsn=2.1.5,"

test/tls_features_0002.yaml

@@ -0,0 +1,6 @@
+pattern: "^%{POSTFIX_SMTP}$"
+# TLS features: security level undecided (with question mark)
+data: "7EE668039: to=<user@example.com>, relay=mail.example.com[1.2.3.4]:25, delay=3.6, delays=0.08/0.02/0.85/0.14, tls=may?, dsn=2.1.5, status=sent (250 2.0.0 Ok: queued as 153053D)"
+results:
+    postfix_queueid: 7EE668039
+    postfix_keyvalue_data: "to=<user@example.com>, relay=mail.example.com[1.2.3.4]:25, delay=3.6, delays=0.08/0.02/0.85/0.14, tls=may?, dsn=2.1.5,"

test/tls_features_0003.yaml

@@ -0,0 +1,6 @@
+pattern: "^%{POSTFIX_SMTP}$"
+# TLS features: with downgrade level (separated by colon)
+data: "7EE668039: to=<user@example.com>, relay=mail.example.com[1.2.3.4]:25, delay=3.6, delays=0.08/0.02/0.85/0.14, tls=may:none, dsn=2.1.5, status=sent (250 2.0.0 Ok: queued as 153053D)"
+results:
+    postfix_queueid: 7EE668039
+    postfix_keyvalue_data: "to=<user@example.com>, relay=mail.example.com[1.2.3.4]:25, delay=3.6, delays=0.08/0.02/0.85/0.14, tls=may:none, dsn=2.1.5,"

test/tls_features_0004.yaml

@@ -0,0 +1,6 @@
+pattern: "^%{POSTFIX_SMTP}$"
+# TLS features: requiretls
+data: "7EE668039: to=<user@example.com>, relay=mail.example.com[1.2.3.4]:25, delay=3.6, delays=0.08/0.02/0.85/0.14, tls=dane/requiretls, dsn=2.1.5, status=sent (250 2.0.0 Ok: queued as 153053D)"
+results:
+    postfix_queueid: 7EE668039
+    postfix_keyvalue_data: "to=<user@example.com>, relay=mail.example.com[1.2.3.4]:25, delay=3.6, delays=0.08/0.02/0.85/0.14, tls=dane/requiretls, dsn=2.1.5,"

test/tls_features_0005.yaml

@@ -0,0 +1,6 @@
+pattern: "^%{POSTFIX_SMTP}$"
+# TLS features: requiretls violation
+data: "7EE668039: to=<user@example.com>, relay=mail.example.com[1.2.3.4]:25, delay=3.6, delays=0.08/0.02/0.85/0.14, tls=dane/!requiretls:nocertmatch, dsn=2.1.5, status=sent (250 2.0.0 Ok: queued as 153053D)"
+results:
+    postfix_queueid: 7EE668039
+    postfix_keyvalue_data: "to=<user@example.com>, relay=mail.example.com[1.2.3.4]:25, delay=3.6, delays=0.08/0.02/0.85/0.14, tls=dane/!requiretls:nocertmatch, dsn=2.1.5,"

test/tls_features_0006.yaml

@@ -0,0 +1,6 @@
+pattern: "^%{POSTFIX_SMTP}$"
+# TLS features: requiretls policy undecided
+data: "7EE668039: to=<user@example.com>, relay=mail.example.com[1.2.3.4]:25, delay=3.6, delays=0.08/0.02/0.85/0.14, tls=dane/requiretls?, dsn=2.1.5, status=sent (250 2.0.0 Ok: queued as 153053D)"
+results:
+    postfix_queueid: 7EE668039
+    postfix_keyvalue_data: "to=<user@example.com>, relay=mail.example.com[1.2.3.4]:25, delay=3.6, delays=0.08/0.02/0.85/0.14, tls=dane/requiretls?, dsn=2.1.5,"

test/tls_features_0007.yaml

@@ -0,0 +1,4 @@
+pattern: "^%{POSTFIX_TLS_FEATURES}$"
+data: "dane"
+results:
+    postfix_tls_security_level: dane

test/tls_features_0008.yaml

@@ -0,0 +1,5 @@
+pattern: "^%{POSTFIX_TLS_FEATURES}$"
+data: "dane:none"
+results:
+    postfix_tls_security_level: dane
+    postfix_tls_downgrade_level: none

test/tls_features_0009.yaml

@@ -0,0 +1,5 @@
+pattern: "^%{POSTFIX_TLS_FEATURES}$"
+data: "may?"
+results:
+    postfix_tls_security_level: may
+    postfix_tls_policy_undecided: "?"

test/tls_features_0010.yaml

@@ -0,0 +1,5 @@
+pattern: "^%{POSTFIX_TLS_FEATURES}$"
+data: "dane/requiretls"
+results:
+    postfix_tls_security_level: dane
+    postfix_requiretls: requiretls

test/tls_features_0011.yaml

@@ -0,0 +1,6 @@
+pattern: "^%{POSTFIX_TLS_FEATURES}$"
+data: "dane/requiretls?"
+results:
+    postfix_tls_security_level: dane
+    postfix_requiretls: requiretls
+    postfix_requiretls_policy_undecided: "?"

test/tls_features_0012.yaml

@@ -0,0 +1,7 @@
+pattern: "^%{POSTFIX_TLS_FEATURES}$"
+data: "dane/!requiretls:nostarttls"
+results:
+    postfix_tls_security_level: dane
+    postfix_requiretls: requiretls
+    postfix_requiretls_policy_violation: "!"
+    postfix_requiretls_downgrade_level: nostarttls

test_config_syntax.sh

@@ -8,7 +8,7 @@
 
 set -eu
 
-LOGSTASH_VERSION=8.14.1
+LOGSTASH_VERSION=9.2.1
 
 docker run \
   --rm \

test_pipeline.sh

@@ -9,7 +9,7 @@
 
 set -eu
 
-LOGSTASH_VERSION=8.14.1
+LOGSTASH_VERSION=9.2.1
 
 INPUT=$(mktemp tmp.logstash.in.XXXXX)
 OUTPUT=$(mktemp tmp.logstash.out.XXXXX)
@@ -23,7 +23,7 @@ perform_cleanup() {
 trap perform_cleanup INT TERM
 
 echo Preparing input data
-echo "postfix/smtp[123]: 7EE668039: to=<admin@example.com>, relay=127.0.0.1[127.0.0.1]:2525, delay=3.6, delays=0.2/0.02/0.04/3.3, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 153053D)" > "$INPUT"
+echo "postfix/smtp[123]: 7EE668039: to=<admin@example.com>, relay=127.0.0.1[127.0.0.1]:2525, delay=3.6, delays=0.2/0.02/0.04/3.3, dsn=2.0.0, tls=dane/!requiretls:nostarttls, status=sent (250 2.0.0 Ok: queued as 153053D)" > "$INPUT"
 
 echo Preparing pipeline config
 cat > "$PIPELINE" << EOF
@@ -63,17 +63,19 @@ CONTAINER_ID=$(docker run --rm --detach \
 
 printf "Waiting for output from logstash "
 until test -s "$OUTPUT"; do
+  # For debugging a crashing container (probably invalid configuration)
+  # docker inspect "$CONTAINER_ID" | jq '.[0].State'
   printf "."
   sleep 2
 done
 echo
 
 if test "$(jq .tags[0] "$OUTPUT")" = '"_grok_postfix_success"'; then
   echo Grok processing successful!
-  jq . "$OUTPUT"
+  jq --sort-keys . "$OUTPUT"
 else
   echo "Grok processing failed :<"
-  jq . "$OUTPUT"
+  jq --sort-keys . "$OUTPUT"
   exit 1
 fi