Events: Add smtp:ehlo event
authorJeremy Harris <jgh146exb@wizmail.org>
Thu, 3 Oct 2019 19:57:40 +0000 (20:57 +0100)
committerJeremy Harris <jgh146exb@wizmail.org>
Fri, 4 Oct 2019 09:26:36 +0000 (10:26 +0100)
doc/doc-docbook/spec.xfpt
doc/doc-txt/NewStuff
src/src/transports/smtp.c
test/aux-fixed/event-logger-acl
test/confs/5710
test/confs/5720
test/log/5700
test/log/5702
test/log/5703
test/log/5710
test/log/5720

index 273348ac8dfeb033c563f45f05b283fea911ef3e..3afc62989a093566ea0686f3dd72f88f42034ea6 100644 (file)
@@ -41032,7 +41032,9 @@ Events have names which correspond to the point in process at which they fire.
 The name is placed in the variable &$event_name$& and the event action
 expansion must check this, as it will be called for every possible event type.
 
+.new
 The current list of events is:
+.wen
 .display
 &`dane:fail              after    transport  `& per connection
 &`msg:complete           after    main       `& per message
@@ -41046,6 +41048,7 @@ The current list of events is:
 &`tcp:close              after    transport  `& per connection
 &`tls:cert               before   both       `& per certificate in verification chain
 &`smtp:connect           after    transport  `& per connection
+&`smtp:ehlo              after    transport  `& per connection
 .endd
 New event types may be added in future.
 
@@ -41072,6 +41075,7 @@ with the event type:
 &`msg:host:defer       `& error string
 &`tls:cert             `& verification chain depth
 &`smtp:connect         `& smtp banner
+&`smtp:ehlo            `& smtp ehlo response
 .endd
 
 The :defer events populate one extra variable: &$event_defer_errno$&.
index aa05e67d59931269d41e7f6a87f79b55a8c5b7be..4caa897e305a310171765a2aa9b654d0953de5bc 100644 (file)
@@ -39,6 +39,8 @@ Version 4.93
 
 13. Dual-certificate stacks on servers now support OCSP stapling, under OpenSSL.
 
+14: An smtp:ehlo transport event, for observability of the remote offered features.
+
 
 Version 4.92
 --------------
index d90f7adf1cefe43665f128924faa0c3e25be8200..3df06c2029e568fe16050b08dc5c314570160c2e 100644 (file)
@@ -814,6 +814,10 @@ if (!smtp_read_response(sx, sx->buffer, sizeof(sx->buffer), '2',
 #ifdef EXPERIMENTAL_DSN_INFO
 sx->helo_response = string_copy(sx->buffer);
 #endif
+#ifndef DISABLE_EVENT
+(void) event_raise(sx->conn_args.tblock->event_action,
+  US"smtp:ehlo", sx->buffer);
+#endif
 return TRUE;
 }
 
index 62cba32d633b1415bc780dc9c31aa04cbdcb2aaa..980d47f1145dd5896ed8af857436a48face3e397 100644 (file)
@@ -4,13 +4,17 @@ ev_tcp:
     accept condition = ${if eq {$event_name}{tcp:close}}
           logwrite = . [$sending_ip_address] -> \
                        [$host_address]:$host_port
-    accept
+    accept logwrite =  UNEXPECTED $event_name
 
 ev_smtp:
-    accept
+    warn
           logwrite = . [$sending_ip_address] -> \
                        [$host_address]:$host_port
+    accept condition = ${if eq {$event_name}{smtp:connect}}
           logwrite = . banner <$event_data>
+    accept condition = ${if eq {$event_name}{smtp:ehlo}}
+          logwrite = . ehlo-resp <$event_data>
+    accept logwrite =  UNEXPECTED $event_name
 
 ev_msg_fail:
     accept condition = ${if eq {$event_name}{msg:fail:delivery}}
@@ -64,6 +68,9 @@ ev_msg:
                        "err <$event_defer_errno>:<$acl_m_ev_lkup:$acl_m_ev_code> \
                        errstr <$event_data>"
 
+    accept condition = ${if eq {$event_name}{msg:rcpt:host:defer}}
+    accept logwrite =  UNEXPECTED $event_name
+
 logger:
     warn   logwrite = event $event_name
     accept condition = ${if eq {tcp} {${listextract{1}{$event_name}}}}
@@ -72,3 +79,4 @@ logger:
           acl = ev_smtp
     accept condition = ${if eq {msg} {${listextract{1}{$event_name}}}}
           acl = ev_msg
+    accept logwrite =  UNEXPECTED $event_name
index e61fadc5e84fc0829e118ba39cb488d4b3a865ab..6ab64f4ec65705084fdebe467d9a61c569ff2214 100644 (file)
@@ -69,6 +69,8 @@ logger:
         acl = ev_msg $event_name $acl_arg2
   accept condition = ${if eq {tls} {${listextract{1}{$event_name}}}}
         message =   ${acl {ev_tls}}
+  accept condition = ${if eq {smtp:ehlo}{$event_name}}
+        logwrite =  $tls_out_cipher smtp:ehlo $event_data
   accept
 
 # ----- Routers -----
index 2de47bd8264f6e6c7f068ce23cdffb378c214aef..0304349731d0c38afa7da5f5dc77bed17607deaf 100644 (file)
@@ -69,6 +69,8 @@ logger:
         acl =       ev_msg $event_name $acl_arg2
   accept condition = ${if eq {tls} {${listextract{1}{$event_name}}}}
         message =   ${acl {ev_tls}}
+  accept condition = ${if eq {smtp:ehlo}{$event_name}}
+        logwrite =  $tls_out_cipher smtp:ehlo $event_data
   accept
 
 # ----- Routers -----
index 7f810e438f8a5f423f3c65d1fddbd70cd21a48d0..d50c67cd1bed7a48dca1cc908dfd37459e6a3ba7 100644 (file)
@@ -5,6 +5,9 @@
 1999-03-02 09:44:33 10HmaY-0005vi-00 event smtp:connect
 1999-03-02 09:44:33 10HmaY-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
 1999-03-02 09:44:33 10HmaY-0005vi-00 . banner <220 ESMTP>
+1999-03-02 09:44:33 10HmaY-0005vi-00 event smtp:ehlo
+1999-03-02 09:44:33 10HmaY-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
+1999-03-02 09:44:33 10HmaY-0005vi-00 . ehlo-resp <250-OK\n250 HELP>
 1999-03-02 09:44:33 10HmaY-0005vi-00 event tcp:close
 1999-03-02 09:44:33 10HmaY-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
 1999-03-02 09:44:33 10HmaY-0005vi-00 => userx@domain1 R=others T=smtp H=127.0.0.1 [127.0.0.1] C="250 OK"
@@ -21,6 +24,9 @@
 1999-03-02 09:44:33 10HmaX-0005vi-00 event smtp:connect
 1999-03-02 09:44:33 10HmaX-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
 1999-03-02 09:44:33 10HmaX-0005vi-00 . banner <220 ESMTP>
+1999-03-02 09:44:33 10HmaX-0005vi-00 event smtp:ehlo
+1999-03-02 09:44:33 10HmaX-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
+1999-03-02 09:44:33 10HmaX-0005vi-00 . ehlo-resp <250-OK\n250 HELP>
 1999-03-02 09:44:33 10HmaX-0005vi-00 event tcp:close
 1999-03-02 09:44:33 10HmaX-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
 1999-03-02 09:44:33 10HmaX-0005vi-00 => userx@expansionfail R=others T=smtp H=127.0.0.1 [127.0.0.1] C="250 OK"
@@ -57,6 +63,9 @@
 1999-03-02 09:44:33 10HmbA-0005vi-00 event smtp:connect
 1999-03-02 09:44:33 10HmbA-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
 1999-03-02 09:44:33 10HmbA-0005vi-00 . banner <220 ESMTP>
+1999-03-02 09:44:33 10HmbA-0005vi-00 event smtp:ehlo
+1999-03-02 09:44:33 10HmbA-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
+1999-03-02 09:44:33 10HmbA-0005vi-00 . ehlo-resp <250-OK\n250 HELP>
 1999-03-02 09:44:33 10HmbA-0005vi-00 event msg:rcpt:host:defer
 1999-03-02 09:44:33 10HmbA-0005vi-00 event msg:rcpt:defer
 1999-03-02 09:44:33 10HmbA-0005vi-00 . rcpt deferral ip <127.0.0.1> port <1224> fqdn <127.0.0.1> local_part <userx> domain <domain1> err <12865>:<A:450> errstr <SMTP error from remote mail server after RCPT TO:<userx@domain1>: 450 NOT RIGHT NOW> router <others> transport <smtp>
@@ -78,6 +87,9 @@
 1999-03-02 09:44:33 10HmbB-0005vi-00 event smtp:connect
 1999-03-02 09:44:33 10HmbB-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
 1999-03-02 09:44:33 10HmbB-0005vi-00 . banner <220 ESMTP>
+1999-03-02 09:44:33 10HmbB-0005vi-00 event smtp:ehlo
+1999-03-02 09:44:33 10HmbB-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
+1999-03-02 09:44:33 10HmbB-0005vi-00 . ehlo-resp <250-OK\n250 HELP>
 1999-03-02 09:44:33 10HmbB-0005vi-00 event tcp:close
 1999-03-02 09:44:33 10HmbB-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
 1999-03-02 09:44:33 10HmbB-0005vi-00 ** userx@domain1 R=others T=smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after RCPT TO:<userx@domain1>: 550 GO AWAY
index 45f517bf5e0669bb226f84273e409d722dd03303..5d494eee011a911968f64a11e8df64a0b38b8f95 100644 (file)
@@ -5,6 +5,9 @@
 1999-03-02 09:44:33 10HmaX-0005vi-00 event smtp:connect
 1999-03-02 09:44:33 10HmaX-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
 1999-03-02 09:44:33 10HmaX-0005vi-00 . banner <220 ESMTP>
+1999-03-02 09:44:33 10HmaX-0005vi-00 event smtp:ehlo
+1999-03-02 09:44:33 10HmaX-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
+1999-03-02 09:44:33 10HmaX-0005vi-00 . ehlo-resp <250-OK\n250 HELP>
 1999-03-02 09:44:33 10HmaX-0005vi-00 event tcp:close
 1999-03-02 09:44:33 10HmaX-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
 1999-03-02 09:44:33 10HmaX-0005vi-00 => userx@domain1 R=route_smtp T=smtp H=127.0.0.1 [127.0.0.1] C="250 OK"
index 0ce0f133fd62c64bb030e062876cd04d576017bb..ac98fc9d9b02e6396dde8ef600eb1863f317ac66 100644 (file)
@@ -5,6 +5,9 @@
 1999-03-02 09:44:33 10HmaX-0005vi-00 event smtp:connect
 1999-03-02 09:44:33 10HmaX-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
 1999-03-02 09:44:33 10HmaX-0005vi-00 . banner <220 ESMTP>
+1999-03-02 09:44:33 10HmaX-0005vi-00 event smtp:ehlo
+1999-03-02 09:44:33 10HmaX-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
+1999-03-02 09:44:33 10HmaX-0005vi-00 . ehlo-resp <250-OK\n250 HELP>
 1999-03-02 09:44:33 10HmaX-0005vi-00 event tcp:close
 1999-03-02 09:44:33 10HmaX-0005vi-00 . [127.0.0.1] -> [127.0.0.1]:PORT_S
 1999-03-02 09:44:33 10HmaX-0005vi-00 event msg:fail:delivery
index 4c92928b93817bdeddcb85aab56a16580c946545..72bba14e609f5095ceecee6cc86e99a13c4a5102 100644 (file)
@@ -1,6 +1,7 @@
 1999-03-02 09:44:33 10HmaX-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
 1999-03-02 09:44:33 10HmaY-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
 1999-03-02 09:44:33 Start queue run: pid=pppp -qf
+1999-03-02 09:44:33 10HmaX-0005vi-00 smtp:ehlo 250-myhost.test.ex Hello localhost [127.0.0.1]\n250-SIZE 52428800\n250-8BITMIME\n250-PIPELINING\n250-STARTTLS\n250 HELP
 1999-03-02 09:44:33 10HmaX-0005vi-00 tls:cert depth=0 <CN=server1.example.com>
 1999-03-02 09:44:33 10HmaX-0005vi-00 msg:host:defer bad
 1999-03-02 09:44:33 10HmaX-0005vi-00 NO CLIENT CERT presented
 1999-03-02 09:44:33 10HmaX-0005vi-00 SAN <DNS=alternatename.server1.example.com\nDNS=alternatename2.server1.example.com\nDNS=*.test.ex\nDNS=server1.example.com>
 1999-03-02 09:44:33 10HmaX-0005vi-00 CRU <http://crl.example.com/latest.crl>
 1999-03-02 09:44:33 10HmaX-0005vi-00 TLS session: (certificate verification failed): certificate invalid: delivering unencrypted to H=127.0.0.1 [127.0.0.1] (not in hosts_require_tls)
+1999-03-02 09:44:33 10HmaX-0005vi-00 smtp:ehlo 250-myhost.test.ex Hello localhost [127.0.0.1]\n250-SIZE 52428800\n250-8BITMIME\n250-PIPELINING\n250-STARTTLS\n250 HELP
 1999-03-02 09:44:33 10HmaX-0005vi-00 => bad@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1] C="250 OK id=10HmaZ-0005vi-00"
 1999-03-02 09:44:33 10HmaX-0005vi-00 msg:delivery bad
 1999-03-02 09:44:33 10HmaX-0005vi-00 NO CLIENT CERT presented
 1999-03-02 09:44:33 10HmaX-0005vi-00 No Peer cert
 1999-03-02 09:44:33 10HmaX-0005vi-00 Completed
+1999-03-02 09:44:33 10HmaY-0005vi-00 smtp:ehlo 250-myhost.test.ex Hello localhost [127.0.0.1]\n250-SIZE 52428800\n250-8BITMIME\n250-PIPELINING\n250-STARTTLS\n250 HELP
 1999-03-02 09:44:33 10HmaY-0005vi-00 tls:cert depth=0 <CN=server1.example.com>
+1999-03-02 09:44:33 10HmaY-0005vi-00 TLS1.x:ke-RSA-AES256-SHAnnn:xxx smtp:ehlo 250-myhost.test.ex Hello localhost [127.0.0.1]\n250-SIZE 52428800\n250-8BITMIME\n250-PIPELINING\n250 HELP
 1999-03-02 09:44:33 10HmaY-0005vi-00 => good@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DN="CN=server1.example.com" C="250 OK id=10HmbA-0005vi-00"
 1999-03-02 09:44:33 10HmaY-0005vi-00 msg:delivery good
 1999-03-02 09:44:33 10HmaY-0005vi-00 Our cert SN: CN=server2.example.com
index 154d09d64c89f9a16ea4c102d4cf0bc89570ba41..066f7fb3553699cb46c3ce663e27253966a56973 100644 (file)
@@ -1,6 +1,7 @@
 1999-03-02 09:44:33 10HmaX-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
 1999-03-02 09:44:33 10HmaY-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss
 1999-03-02 09:44:33 Start queue run: pid=pppp -qf
+1999-03-02 09:44:33 10HmaX-0005vi-00 smtp:ehlo 250-myhost.test.ex Hello localhost [127.0.0.1]\n250-SIZE 52428800\n250-8BITMIME\n250-PIPELINING\n250-STARTTLS\n250 HELP
 1999-03-02 09:44:33 10HmaX-0005vi-00 [127.0.0.1] SSL verify error: depth=2 error=self signed certificate in certificate chain cert=/O=example.com/CN=clica CA rsa
 1999-03-02 09:44:33 10HmaX-0005vi-00 msg:host:defer bad
 1999-03-02 09:44:33 10HmaX-0005vi-00 NO CLIENT CERT presented
 1999-03-02 09:44:33 10HmaX-0005vi-00 (no OCU)
 1999-03-02 09:44:33 10HmaX-0005vi-00 (no CRU)
 1999-03-02 09:44:33 10HmaX-0005vi-00 TLS session: (SSL_connect): error: <<detail omitted>>
+1999-03-02 09:44:33 10HmaX-0005vi-00 smtp:ehlo 250-myhost.test.ex Hello localhost [127.0.0.1]\n250-SIZE 52428800\n250-8BITMIME\n250-PIPELINING\n250-STARTTLS\n250 HELP
 1999-03-02 09:44:33 10HmaX-0005vi-00 => bad@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1] C="250 OK id=10HmaZ-0005vi-00"
 1999-03-02 09:44:33 10HmaX-0005vi-00 msg:delivery bad
 1999-03-02 09:44:33 10HmaX-0005vi-00 NO CLIENT CERT presented
 1999-03-02 09:44:33 10HmaX-0005vi-00 No Peer cert
 1999-03-02 09:44:33 10HmaX-0005vi-00 Completed
+1999-03-02 09:44:33 10HmaY-0005vi-00 smtp:ehlo 250-myhost.test.ex Hello localhost [127.0.0.1]\n250-SIZE 52428800\n250-8BITMIME\n250-PIPELINING\n250-STARTTLS\n250 HELP
 1999-03-02 09:44:33 10HmaY-0005vi-00 tls:cert depth=2 <CN=clica CA rsa,O=example.com>
 1999-03-02 09:44:33 10HmaY-0005vi-00 tls:cert depth=1 <CN=clica Signing Cert rsa,O=example.com>
 1999-03-02 09:44:33 10HmaY-0005vi-00 tls:cert depth=0 <CN=server1.example.com>
+1999-03-02 09:44:33 10HmaY-0005vi-00 TLS1.x:ke-RSA-AES256-SHAnnn:xxx smtp:ehlo 250-myhost.test.ex Hello localhost [127.0.0.1]\n250-SIZE 52428800\n250-8BITMIME\n250-PIPELINING\n250 HELP
 1999-03-02 09:44:33 10HmaY-0005vi-00 => good@test.ex R=client T=send_to_server H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DN="/CN=server1.example.com" C="250 OK id=10HmbA-0005vi-00"
 1999-03-02 09:44:33 10HmaY-0005vi-00 msg:delivery good
 1999-03-02 09:44:33 10HmaY-0005vi-00 Our cert SN: CN=server2.example.com