Re: [exim-dev] [Bug 2376] New: log_message doesn't log if connection is interrupted (which is quite unexpected) while other rules in the same acl are applied
On 20/02/2019 12:25, Arkadiusz Miśkiewicz via Exim-dev wrote: > Is there a way to do ratelimit counting but make it return true, so > entire acl will fire? Have a very large limit (so it never exceeds it) and negate the condition. I suggest this rather than a zero limit as I cannot recall whether the first-ever value is zero. You'd need "strict" for that, too. -- Cheers, Jeremy -- ## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##
Re: [exim-dev] [Bug 2376] New: log_message doesn't log if connection is interrupted (which is quite unexpected) while other rules in the same acl are applied
On 18/02/2019 17:20, Heiko Schlittermann via Exim-dev wrote:
> admin--- via Exim-dev (Mo 18 Feb 2019 07:30:24 CET):
>> For example:
>>
>> acl_notquit:
>> accept authenticated = *
>>
>> warn condition = ${if match {$smtp_notquit_reason}{command}{yes}{no}}
>> log_message = "Connection Ratelimit - $sender_fullhost
>> because
>> of notquit: $smtp_notquit_reason ($sender_rate/$sender_rate_period
>> max:$sender_rate_limit)"
>> logwrite = "LOGWRITE: $tod_log $message_id Connection
>> Ratelimit
>> - $sender_fullhost because of notquit: $smtp_notquit_reason
>> ($sender_rate/$sender_rate_period max:$sender_rate_limit)"
>> ratelimit = BADNOAUTH_LIMIT / strict / per_conn
>>
>> accept
>>
>
>
> I'm replying here, until I'm sure that we're talking about a bug :)
>
> I believe, it is clearly documented:
> From the spec.txt:
>
> log_message =
>
> This modifier sets up a message that is used as part of the log message if
> the ACL denies access or a warn statement's conditions are true. For
> example:
>
>
> How do you know, that the "ratelimit" fired (returned TRUE, because it was
> hit?)
> The output from your log doesn't indicate it:
>
> 2019-02-15 16:09:49.000 [26467] "LOGWRITE: 2019-02-15 16:09:49.000 Connection
> Ratelimit - (mztyg.com) [49.86.182.22]:53541 because of failed SMTP AUTH
> without QUIT: connection-lost (/ max:)
>
> I'd have expected something like:
>
> LOG: H=(ME) [1.1.1.1] Warning: non-polite client: connection-lost [1.7/1m
> max:1]
I think you are right.
Is there a way to do ratelimit counting but make it return true, so
entire acl will fire?
Then my log_message should end up being logged (since it is supposed to
be "I counted here" type of message).
Have to still check what happens if connection is interrupted before acl
finishes (according to irc conversations acl won't finish then and
log_message won't get logged)
--
Arkadiusz Miśkiewicz, arekm / ( maven.pl | pld-linux.org )
signature.asc
Description: OpenPGP digital signature
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim
details at http://www.exim.org/ ##
Re: [exim-dev] [Bug 2376] New: log_message doesn't log if connection is interrupted (which is quite unexpected) while other rules in the same acl are applied
admin--- via Exim-dev (Mo 18 Feb 2019 07:30:24 CET):
> For example:
>
> acl_notquit:
> accept authenticated = *
>
> warn condition = ${if match {$smtp_notquit_reason}{command}{yes}{no}}
> log_message = "Connection Ratelimit - $sender_fullhost because
> of notquit: $smtp_notquit_reason ($sender_rate/$sender_rate_period
> max:$sender_rate_limit)"
> logwrite = "LOGWRITE: $tod_log $message_id Connection
> Ratelimit
> - $sender_fullhost because of notquit: $smtp_notquit_reason
> ($sender_rate/$sender_rate_period max:$sender_rate_limit)"
> ratelimit = BADNOAUTH_LIMIT / strict / per_conn
>
> accept
>
I'm replying here, until I'm sure that we're talking about a bug :)
I believe, it is clearly documented:
From the spec.txt:
log_message =
This modifier sets up a message that is used as part of the log message if
the ACL denies access or a warn statement's conditions are true. For
example:
How do you know, that the "ratelimit" fired (returned TRUE, because it was hit?)
The output from your log doesn't indicate it:
2019-02-15 16:09:49.000 [26467] "LOGWRITE: 2019-02-15 16:09:49.000 Connection
Ratelimit - (mztyg.com) [49.86.182.22]:53541 because of failed SMTP AUTH
without QUIT: connection-lost (/ max:)
I'd have expected something like:
LOG: H=(ME) [1.1.1.1] Warning: non-polite client: connection-lost [1.7/1m max:1]
Best regards from Dresden/Germany
Viele Grüße aus Dresden
Heiko Schlittermann
--
SCHLITTERMANN.de internet & unix support -
Heiko Schlittermann, Dipl.-Ing. (TU) - {fon,fax}: +49.351.802998{1,3} -
gnupg encrypted messages are welcome --- key ID: F69376CE -
! key id 7CBF764A and 972EAC9F are revoked since 2015-01 -
signature.asc
Description: PGP signature
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim
details at http://www.exim.org/ ##
[exim-dev] [Bug 2376] New: log_message doesn't log if connection is interrupted (which is quite unexpected) while other rules in the same acl are applied
https://bugs.exim.org/show_bug.cgi?id=2376
Bug ID: 2376
Summary: log_message doesn't log if connection is interrupted
(which is quite unexpected) while other rules in the
same acl are applied
Product: Exim
Version: 4.91
Hardware: x86
OS: All
Status: NEW
Severity: bug
Priority: medium
Component: Logging
Assignee: ni...@exim.org
Reporter: ar...@maven.pl
CC: exim-dev@exim.org
log_message behaviour is quite unexpected. It doesn't log any message if acl
doesn't finish because of some reason (like connection was interrupted).
For example:
acl_notquit:
accept authenticated = *
warn condition = ${if match {$smtp_notquit_reason}{command}{yes}{no}}
log_message = "Connection Ratelimit - $sender_fullhost because
of notquit: $smtp_notquit_reason ($sender_rate/$sender_rate_period
max:$sender_rate_limit)"
logwrite = "LOGWRITE: $tod_log $message_id Connection Ratelimit
- $sender_fullhost because of notquit: $smtp_notquit_reason
($sender_rate/$sender_rate_period max:$sender_rate_limit)"
ratelimit = BADNOAUTH_LIMIT / strict / per_conn
accept
so we want to do ratelimit counting and log message about that (in case if
ratelimit will block something in other rules and we will need to find in logs
why that happened)
Now we have a bad client:
2019-02-15 16:09:27.239 [25025] SMTP connection from [49.86.182.22]:53018
I=[1.1.1.82]:25 (TCP/IP connection count = 31)
2019-02-15 16:09:31.280 [26272] login authenticator failed for (mztyg.com)
[49.86.182.22]:53018 I=[1.1.1.82]:25: 535 Incorrect authentication data
(set_id=i...@example.pl)
2019-02-15 16:09:31.830 [26272] "LOGWRITE: 2019-02-15 16:09:31.830 Connection
Ratelimit - (mztyg.com) [49.86.182.22]:53018 because of failed SMTP AUTH
without QUIT: connection-lost (/ max:)"
2019-02-15 16:09:31.831 [26272] SMTP connection from (mztyg.com)
[49.86.182.22]:53018 I=[1.1.1.82]:25 lost D=4.590s
2019-02-15 16:09:31.832 [26272] no MAIL in SMTP connection from (mztyg.com)
[49.86.182.22]:53018 I=[1.1.1.82]:25 D=4.591s C=EHLO,AUTH
2019-02-15 16:09:35.207 [25025] SMTP connection from [49.86.182.22]:53541
I=[1.1.1.82]:25 (TCP/IP connection count = 34)
2019-02-15 16:09:44.204 [26467] login authenticator failed for (mztyg.com)
[49.86.182.22]:53541 I=[1.1.1.82]:25: 535 Incorrect authentication data
(set_id=i...@example.pl)
2019-02-15 16:09:49.000 [26467] "LOGWRITE: 2019-02-15 16:09:49.000 Connection
Ratelimit - (mztyg.com) [49.86.182.22]:53541 because of failed SMTP AUTH
without QUIT: connection-lost (/ max:)"
log_message was not logged.
That's very unexpected and from my looking into documentation also not
documented (at least not explicitly). Very unexpected because other rule -
ratelimit - in the same warn statement was executed and applied. Same for
logwrite.
Possible improvements:
1) make log_message reliable and do more what admin would expect
2) clearly document behaviour and suggest to use logwrite instead
--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim
details at http://www.exim.org/ ##
