Add smtp:fail: events
authorJeremy Harris <jgh146exb@wizmail.org>
Thu, 1 Aug 2024 13:41:32 +0000 (14:41 +0100)
committerJeremy Harris <jgh146exb@wizmail.org>
Thu, 1 Aug 2024 13:41:32 +0000 (14:41 +0100)
doc/doc-docbook/spec.xfpt
doc/doc-txt/NewStuff
src/src/smtp_in.c
test/confs/0612
test/log/0612

index aaa4a270f180c79566aa084780809083c498225e..816db59f9c0b3e5c6fe03c3d5d1f0751782ccd30 100644 (file)
@@ -43150,6 +43150,7 @@ 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:
 .itable all 0 0 4 25* left 10* center 15* center 50* left
 .row auth:fail             after    both       "per driver per authentication attempt"
@@ -43169,7 +43170,10 @@ The current list of events is:
 .row tls:fail:connect       after    main       "per connection"
 .row smtp:connect           after    transport  "per connection"
 .row smtp:ehlo              after    transport  "per connection"
+.row smtp:fail:protocol     after    main       "per connection"
+.row smtp:fail:syntax       after    main       "per connection"
 .endtable
+.wen
 New event types may be added in future.
 
 The event name is a colon-separated list, defining the type of
@@ -43185,6 +43189,7 @@ should define the event action.
 
 An additional variable, &$event_data$&, is filled with information varying
 with the event type:
+.new
 .itable all 0 0 2 20* left 80* left
 .row auth:fail           "smtp response"
 .row dane:fail            "failure reason"
@@ -43200,7 +43205,10 @@ with the event type:
 .row tls:fail:connect     "error string"
 .row smtp:connect         "smtp banner"
 .row smtp:ehlo            "smtp ehlo response"
+.row smtp:fail:protocol   "error string"
+.row smtp:fail:syntax     "error string"
 .endtable
+.wen
 
 The :defer events populate one extra variable: &$event_defer_errno$&.
 
index d48f2252ee662382845a91e286c52a4365d28239..4aa1d04b115c476867676f66073de37be1c1ba09 100644 (file)
@@ -12,6 +12,8 @@ Version 4.98
 
  2. A "connection_id" variable
 
+ 3. Events smtp:fail:protocol and smtp:fail:syntax
+
 Version 4.98
 ------------
  1. The dkim_status ACL condition may now be used in data ACLs
index 150d65a2d37c148f5e5d620885d80fbb100ccef7..076ea423a959d280827ee1484287b6a3895714c8 100644 (file)
@@ -2765,6 +2765,10 @@ synprot_error(int type, int code, uschar *data, uschar *errmess)
 {
 int yield = -1;
 
+event_raise(event_action,
+  L_smtp_syntax_error ? US"smtp:fail:syntax" : US"smtp:fail:protocol",
+  errmess, NULL);
+
 log_write(type, LOG_MAIN, "SMTP %s error in \"%s\" %s %s",
   type == L_smtp_syntax_error ? "syntax" : "protocol",
   string_printing(smtp_cmd_buffer), host_and_ident(TRUE), errmess);
index f4f4272461e52be4f404d01d74ab226a1f4356d1..ad84f9268121bae81839974fe566dfd9b87f6045 100644 (file)
@@ -34,7 +34,7 @@ begin acl
 
 .ifdef _HAVE_EVENT
 ev_log:
-  accept logwrite = event $event_name
+  accept logwrite = event $event_name data "$event_data"
 .endif
 
 rcpt:
index e022b5071877d248bac866b89c4fafcb231993b0..b1730b9124d70bc203afc00504e3ee917b4fa2ab 100644 (file)
@@ -1,77 +1,77 @@
 1999-03-02 09:44:33 rej/never
 1999-03-02 09:44:33 Start queue run: pid=p1234
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 event tcp:connect
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 event smtp:connect
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 event smtp:ehlo
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 event tcp:close
+1999-03-02 09:44:33 10HmaX-000000005vi-0000 event tcp:connect data ""
+1999-03-02 09:44:33 10HmaX-000000005vi-0000 event smtp:connect data "220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000"
+1999-03-02 09:44:33 10HmaX-000000005vi-0000 event smtp:ehlo data "250-myhost.test.ex Hello localhost [127.0.0.1]\n250-SIZE 52428800\n250-LIMITS MAILMAX=1000 RCPTMAX=50000\n250-DSN\n250 HELP"
+1999-03-02 09:44:33 10HmaX-000000005vi-0000 event tcp:close data ""
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 ** rmt_reject@test.ex R=r2 T=smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after RCPT TO:<rmt_reject@test.ex>: 550 Administrative prohibition
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 event msg:fail:delivery
+1999-03-02 09:44:33 10HmaX-000000005vi-0000 event msg:fail:delivery data "SMTP error from remote mail server after RCPT TO:<rmt_reject@test.ex>: 550 Administrative prohibition"
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 rmt_reject@test.ex: error ignored: RFC 3461 DSN, failure notify not requested
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 Completed
-1999-03-02 09:44:33 10HmaX-000000005vi-0000 event msg:complete
+1999-03-02 09:44:33 10HmaX-000000005vi-0000 event msg:complete data ""
 1999-03-02 09:44:33 End queue run: pid=p1234
 1999-03-02 09:44:33 accept/success
 1999-03-02 09:44:33 Start queue run: pid=p1235
-1999-03-02 09:44:33 10HmaY-000000005vi-0000 event tcp:connect
-1999-03-02 09:44:33 10HmaY-000000005vi-0000 event smtp:connect
-1999-03-02 09:44:33 10HmaY-000000005vi-0000 event smtp:ehlo
-1999-03-02 09:44:33 10HmaY-000000005vi-0000 event tcp:close
+1999-03-02 09:44:33 10HmaY-000000005vi-0000 event tcp:connect data ""
+1999-03-02 09:44:33 10HmaY-000000005vi-0000 event smtp:connect data "220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000"
+1999-03-02 09:44:33 10HmaY-000000005vi-0000 event smtp:ehlo data "250-myhost.test.ex Hello localhost [127.0.0.1]\n250-SIZE 52428800\n250-LIMITS MAILMAX=1000 RCPTMAX=50000\n250-DSN\n250 HELP"
+1999-03-02 09:44:33 10HmaY-000000005vi-0000 event tcp:close data ""
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 => rmt_accept@test.ex R=r2 T=smtp H=127.0.0.1 [127.0.0.1] C="250 OK id=10HmaZ-000000005vi-0000"
-1999-03-02 09:44:33 10HmaY-000000005vi-0000 event msg:delivery
+1999-03-02 09:44:33 10HmaY-000000005vi-0000 event msg:delivery data "250 OK id=10HmaZ-000000005vi-0000"
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 Completed
-1999-03-02 09:44:33 10HmaY-000000005vi-0000 event msg:complete
+1999-03-02 09:44:33 10HmaY-000000005vi-0000 event msg:complete data ""
 1999-03-02 09:44:33 End queue run: pid=p1235
 1999-03-02 09:44:33 Start queue run: pid=p1236
 1999-03-02 09:44:33 10HmaZ-000000005vi-0000 => rmt_accept <rmt_accept@test.ex> R=r1 T=tofile
-1999-03-02 09:44:33 10HmaZ-000000005vi-0000 event msg:delivery
+1999-03-02 09:44:33 10HmaZ-000000005vi-0000 event msg:delivery data ""
 1999-03-02 09:44:33 10HmbA-000000005vi-0000 <= <> R=10HmaZ-000000005vi-0000 U=EXIMUSER P=local S=sss for b@dump.ex
 1999-03-02 09:44:33 10HmaZ-000000005vi-0000 Completed
-1999-03-02 09:44:33 10HmaZ-000000005vi-0000 event msg:complete
+1999-03-02 09:44:33 10HmaZ-000000005vi-0000 event msg:complete data ""
 1999-03-02 09:44:33 End queue run: pid=p1236
 1999-03-02 09:44:33 Start queue run: pid=p1237
 1999-03-02 09:44:33 10HmbA-000000005vi-0000 => :blackhole: <b@dump.ex> R=r_dump
 1999-03-02 09:44:33 10HmbA-000000005vi-0000 Completed
-1999-03-02 09:44:33 10HmbA-000000005vi-0000 event msg:complete
+1999-03-02 09:44:33 10HmbA-000000005vi-0000 event msg:complete data ""
 1999-03-02 09:44:33 End queue run: pid=p1237
 1999-03-02 09:44:33 fakereject/success
 1999-03-02 09:44:33 Start queue run: pid=p1238
-1999-03-02 09:44:33 10HmbB-000000005vi-0000 event tcp:connect
-1999-03-02 09:44:33 10HmbB-000000005vi-0000 event smtp:connect
-1999-03-02 09:44:33 10HmbB-000000005vi-0000 event smtp:ehlo
-1999-03-02 09:44:33 10HmbB-000000005vi-0000 event tcp:close
+1999-03-02 09:44:33 10HmbB-000000005vi-0000 event tcp:connect data ""
+1999-03-02 09:44:33 10HmbB-000000005vi-0000 event smtp:connect data "220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000"
+1999-03-02 09:44:33 10HmbB-000000005vi-0000 event smtp:ehlo data "250-myhost.test.ex Hello localhost [127.0.0.1]\n250-SIZE 52428800\n250-LIMITS MAILMAX=1000 RCPTMAX=50000\n250-DSN\n250 HELP"
+1999-03-02 09:44:33 10HmbB-000000005vi-0000 event tcp:close data ""
 1999-03-02 09:44:33 10HmbB-000000005vi-0000 ** rmt_fakereject@test.ex R=r2 T=smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after end of data: 550-Your message has been rejected but is being kept for evaluation.\n550-If it was a legitimate message, it may still be delivered to the target\n550 recipient(s).
-1999-03-02 09:44:33 10HmbB-000000005vi-0000 event msg:fail:delivery
+1999-03-02 09:44:33 10HmbB-000000005vi-0000 event msg:fail:delivery data "SMTP error from remote mail server after end of data: 550-Your message has been rejected but is being kept for evaluation.\n550-If it was a legitimate message, it may still be delivered to the target\n550 recipient(s)."
 1999-03-02 09:44:33 10HmbB-000000005vi-0000 rmt_fakereject@test.ex: error ignored: RFC 3461 DSN, failure notify not requested
 1999-03-02 09:44:33 10HmbB-000000005vi-0000 Completed
-1999-03-02 09:44:33 10HmbB-000000005vi-0000 event msg:complete
+1999-03-02 09:44:33 10HmbB-000000005vi-0000 event msg:complete data ""
 1999-03-02 09:44:33 End queue run: pid=p1238
 1999-03-02 09:44:33 Start queue run: pid=p1239
 1999-03-02 09:44:33 10HmbC-000000005vi-0000 => rmt_fakereject <rmt_fakereject@test.ex> R=r1 T=tofile
-1999-03-02 09:44:33 10HmbC-000000005vi-0000 event msg:delivery
+1999-03-02 09:44:33 10HmbC-000000005vi-0000 event msg:delivery data ""
 1999-03-02 09:44:33 10HmbC-000000005vi-0000 Completed
-1999-03-02 09:44:33 10HmbC-000000005vi-0000 event msg:complete
+1999-03-02 09:44:33 10HmbC-000000005vi-0000 event msg:complete data ""
 1999-03-02 09:44:33 End queue run: pid=p1239
 1999-03-02 09:44:33 Start queue run: pid=p1240
 1999-03-02 09:44:33 End queue run: pid=p1240
 1999-03-02 09:44:33 defer/delay
 1999-03-02 09:44:33 Start queue run: pid=p1241
-1999-03-02 09:44:33 10HmbD-000000005vi-0000 event tcp:connect
-1999-03-02 09:44:33 10HmbD-000000005vi-0000 event smtp:connect
-1999-03-02 09:44:33 10HmbD-000000005vi-0000 event smtp:ehlo
-1999-03-02 09:44:33 10HmbD-000000005vi-0000 event msg:rcpt:host:defer
-1999-03-02 09:44:33 10HmbD-000000005vi-0000 event msg:rcpt:defer
-1999-03-02 09:44:33 10HmbD-000000005vi-0000 event tcp:close
+1999-03-02 09:44:33 10HmbD-000000005vi-0000 event tcp:connect data ""
+1999-03-02 09:44:33 10HmbD-000000005vi-0000 event smtp:connect data "220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000"
+1999-03-02 09:44:33 10HmbD-000000005vi-0000 event smtp:ehlo data "250-myhost.test.ex Hello localhost [127.0.0.1]\n250-SIZE 52428800\n250-LIMITS MAILMAX=1000 RCPTMAX=50000\n250-DSN\n250 HELP"
+1999-03-02 09:44:33 10HmbD-000000005vi-0000 event msg:rcpt:host:defer data "SMTP error from remote mail server after RCPT TO:<rmt_defer@test.ex>: 451 Temporary local problem - please try later"
+1999-03-02 09:44:33 10HmbD-000000005vi-0000 event msg:rcpt:defer data "SMTP error from remote mail server after RCPT TO:<rmt_defer@test.ex>: 451 Temporary local problem - please try later"
+1999-03-02 09:44:33 10HmbD-000000005vi-0000 event tcp:close data ""
 1999-03-02 09:44:33 10HmbD-000000005vi-0000 == rmt_defer@test.ex R=r2 T=smtp defer (-44) H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after RCPT TO:<rmt_defer@test.ex>: 451 Temporary local problem - please try later
 1999-03-02 09:44:33 End queue run: pid=p1241
 1999-03-02 09:44:33 defer/never
 1999-03-02 09:44:33 Start queue run: pid=p1242
 1999-03-02 09:44:33 10HmbD-000000005vi-0000 == rmt_defer@test.ex routing defer (-52): retry time not reached
-1999-03-02 09:44:33 10HmbE-000000005vi-0000 event tcp:connect
-1999-03-02 09:44:33 10HmbE-000000005vi-0000 event smtp:connect
-1999-03-02 09:44:33 10HmbE-000000005vi-0000 event smtp:ehlo
-1999-03-02 09:44:33 10HmbE-000000005vi-0000 event msg:rcpt:host:defer
-1999-03-02 09:44:33 10HmbE-000000005vi-0000 event msg:rcpt:defer
-1999-03-02 09:44:33 10HmbE-000000005vi-0000 event tcp:close
+1999-03-02 09:44:33 10HmbE-000000005vi-0000 event tcp:connect data ""
+1999-03-02 09:44:33 10HmbE-000000005vi-0000 event smtp:connect data "220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000"
+1999-03-02 09:44:33 10HmbE-000000005vi-0000 event smtp:ehlo data "250-myhost.test.ex Hello localhost [127.0.0.1]\n250-SIZE 52428800\n250-LIMITS MAILMAX=1000 RCPTMAX=50000\n250-DSN\n250 HELP"
+1999-03-02 09:44:33 10HmbE-000000005vi-0000 event msg:rcpt:host:defer data "SMTP error from remote mail server after RCPT TO:<rmt_defer@test.ex>: 451 Temporary local problem - please try later"
+1999-03-02 09:44:33 10HmbE-000000005vi-0000 event msg:rcpt:defer data "SMTP error from remote mail server after RCPT TO:<rmt_defer@test.ex>: 451 Temporary local problem - please try later"
+1999-03-02 09:44:33 10HmbE-000000005vi-0000 event tcp:close data ""
 1999-03-02 09:44:33 10HmbE-000000005vi-0000 == rmt_defer@test.ex R=r2 T=smtp defer (-44) H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after RCPT TO:<rmt_defer@test.ex>: 451 Temporary local problem - please try later
 1999-03-02 09:44:33 End queue run: pid=p1242
 1999-03-02 09:44:33 playout
 1999-03-02 09:44:33 10HmbF-000000005vi-0000 <= <> R=10HmbD-000000005vi-0000 U=EXIMUSER P=local S=sss for c@dump.ex
 1999-03-02 09:44:33 10HmbE-000000005vi-0000 == rmt_defer@test.ex routing defer (-52): retry time not reached
 1999-03-02 09:44:33 End queue run: pid=p1243
-1999-03-02 09:44:33 10HmbD-000000005vi-0000 event msg:fail:internal
-1999-03-02 09:44:33 10HmbD-000000005vi-0000 event msg:complete
+1999-03-02 09:44:33 10HmbD-000000005vi-0000 event msg:fail:internal data "message removed by CALLER"
+1999-03-02 09:44:33 10HmbD-000000005vi-0000 event msg:complete data ""
 1999-03-02 09:44:33 10HmbD-000000005vi-0000 removed by CALLER
 1999-03-02 09:44:33 10HmbD-000000005vi-0000 Completed
-1999-03-02 09:44:33 10HmbE-000000005vi-0000 event msg:fail:internal
-1999-03-02 09:44:33 10HmbE-000000005vi-0000 event msg:complete
+1999-03-02 09:44:33 10HmbE-000000005vi-0000 event msg:fail:internal data "message removed by CALLER"
+1999-03-02 09:44:33 10HmbE-000000005vi-0000 event msg:complete data ""
 1999-03-02 09:44:33 10HmbE-000000005vi-0000 removed by CALLER
 1999-03-02 09:44:33 10HmbE-000000005vi-0000 Completed
 1999-03-02 09:44:33 rej/failure+delay
 1999-03-02 09:44:33 Start queue run: pid=p1244
 1999-03-02 09:44:33 10HmbF-000000005vi-0000 => :blackhole: <c@dump.ex> R=r_dump
 1999-03-02 09:44:33 10HmbF-000000005vi-0000 Completed
-1999-03-02 09:44:33 10HmbF-000000005vi-0000 event msg:complete
-1999-03-02 09:44:33 10HmbG-000000005vi-0000 event tcp:connect
-1999-03-02 09:44:33 10HmbG-000000005vi-0000 event smtp:connect
-1999-03-02 09:44:33 10HmbG-000000005vi-0000 event smtp:ehlo
-1999-03-02 09:44:33 10HmbG-000000005vi-0000 event tcp:close
+1999-03-02 09:44:33 10HmbF-000000005vi-0000 event msg:complete data ""
+1999-03-02 09:44:33 10HmbG-000000005vi-0000 event tcp:connect data ""
+1999-03-02 09:44:33 10HmbG-000000005vi-0000 event smtp:connect data "220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000"
+1999-03-02 09:44:33 10HmbG-000000005vi-0000 event smtp:ehlo data "250-myhost.test.ex Hello localhost [127.0.0.1]\n250-SIZE 52428800\n250-LIMITS MAILMAX=1000 RCPTMAX=50000\n250-DSN\n250 HELP"
+1999-03-02 09:44:33 10HmbG-000000005vi-0000 event tcp:close data ""
 1999-03-02 09:44:33 10HmbG-000000005vi-0000 ** rmt_reject@test.ex R=r2 T=smtp H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after RCPT TO:<rmt_reject@test.ex>: 550 Administrative prohibition
 1999-03-02 09:44:33 10HmbH-000000005vi-0000 <= <> R=10HmbG-000000005vi-0000 U=EXIMUSER P=local S=sss for e@dump.ex
 1999-03-02 09:44:33 10HmbG-000000005vi-0000 Completed
-1999-03-02 09:44:33 10HmbG-000000005vi-0000 event msg:complete
+1999-03-02 09:44:33 10HmbG-000000005vi-0000 event msg:complete data ""
 1999-03-02 09:44:33 End queue run: pid=p1244
 1999-03-02 09:44:33 deliver DSN
 1999-03-02 09:44:33 Start queue run: pid=p1245
 1999-03-02 09:44:33 10HmbH-000000005vi-0000 => :blackhole: <e@dump.ex> R=r_dump
 1999-03-02 09:44:33 10HmbH-000000005vi-0000 Completed
-1999-03-02 09:44:33 10HmbH-000000005vi-0000 event msg:complete
+1999-03-02 09:44:33 10HmbH-000000005vi-0000 event msg:complete data ""
 1999-03-02 09:44:33 End queue run: pid=p1245
 
 ******** SERVER ********
 1999-03-02 09:44:33 exim x.yz daemon started: pid=p1246, no queue runs, listening for SMTP on port PORT_D
 1999-03-02 09:44:33 exim x.yz daemon started: pid=p1247, no queue runs, listening for SMTP on port PORT_D
+1999-03-02 09:44:33 event smtp:fail:syntax data "Invalid value for NOTIFY parameter"
 1999-03-02 09:44:33 10HmaX-000000005vi-0000 <= a@dump.ex H=(testclient) [ip4.ip4.ip4.ip4] P=esmtp S=sss for rmt_reject@test.ex
 1999-03-02 09:44:33 H=localhost (myhost.test.ex) [127.0.0.1] F=<a@dump.ex> rejected RCPT <rmt_reject@test.ex>
 1999-03-02 09:44:33 10HmaY-000000005vi-0000 <= b@dump.ex H=(testclient) [ip4.ip4.ip4.ip4] P=esmtp S=sss for rmt_accept@test.ex