From 19c4ea037946e197e30530bd6b4f2880be77c95f Mon Sep 17 00:00:00 2001 From: Jeremy Harris Date: Thu, 1 Aug 2024 14:41:32 +0100 Subject: [PATCH] Add smtp:fail: events --- doc/doc-docbook/spec.xfpt | 8 ++++ doc/doc-txt/NewStuff | 2 + src/src/smtp_in.c | 4 ++ test/confs/0612 | 2 +- test/log/0612 | 93 ++++++++++++++++++++------------------- 5 files changed, 62 insertions(+), 47 deletions(-) diff --git a/doc/doc-docbook/spec.xfpt b/doc/doc-docbook/spec.xfpt index aaa4a270f..816db59f9 100644 --- a/doc/doc-docbook/spec.xfpt +++ b/doc/doc-docbook/spec.xfpt @@ -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$&. diff --git a/doc/doc-txt/NewStuff b/doc/doc-txt/NewStuff index d48f2252e..4aa1d04b1 100644 --- a/doc/doc-txt/NewStuff +++ b/doc/doc-txt/NewStuff @@ -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 diff --git a/src/src/smtp_in.c b/src/src/smtp_in.c index 150d65a2d..076ea423a 100644 --- a/src/src/smtp_in.c +++ b/src/src/smtp_in.c @@ -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); diff --git a/test/confs/0612 b/test/confs/0612 index f4f427246..ad84f9268 100644 --- a/test/confs/0612 +++ b/test/confs/0612 @@ -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: diff --git a/test/log/0612 b/test/log/0612 index e022b5071..b1730b912 100644 --- a/test/log/0612 +++ b/test/log/0612 @@ -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:: 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:: 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 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: 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 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:: 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:: 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:: 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:: 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:: 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:: 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 @@ -80,38 +80,39 @@ 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: 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:: 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: 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= rejected RCPT 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 -- 2.30.2