Ratelimit "mailcow" exceeded with minimal traffic

Coronon commented 1 year ago

Contribution guidelines

[X] I've read the contribution guidelines and wholeheartedly agree

I've found a bug and checked that ...

[X] ... I understand that not following the below instructions will result in immediate closure and/or deletion of my issue.
[X] ... I have understood that this bug report is dedicated for bugs, and not for support-related inquiries.
[X] ... I have understood that answers are voluntary and community-driven, and not commercial support.
[X] ... I have verified that my issue has not been already answered in the past. I also checked previous issues.

Description

I am currently building a service that automatically sends Emails using a mailcow user. After around 2 messages (~3min appart) I get the following error:

{
  code: 'EMESSAGE',
  response: '451 4.7.1 Ratelimit "mailcow" exceeded',
  responseCode: 451,
  command: 'DATA'
}

The rate limit is also shown in the logs (rspamd, watchdog and ratelimit).

The bug is the following:
When changing the users ratelimit `/edit/mailbox/myAwesomeMailbox` from `-1` -> `1000000000` the issue goes away.

This is weired because I never set a ratelimit on the domain itself: `edit/domain/myAwesomeDomain` shows ratelimit as 'Disabled'.

Logs:

mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:25:54 #48(normal) <285bbd>; task; rspamd_task_write_log: id: <e83f39ee-c5c4-16d5-0d40-96f61cefe355@sender.com>, qid: <9BCF85EEB2>, ip: 123.123.123.123, user: real-login@sender.com, from: <allowed-spoofed@sender.com>, (default: F (no action): [-18.10/15.00] [MAILCOW_AUTH(-20.00){},MISSING_MIMEOLE(2.00){},MIME_GOOD(-0.10){multipart/alternative;text/plain;},ARC_NA(0.00){},ASN(0.00){asn:3320, ipnet:123.123.0.0/10, country:DE;},BCC(0.00){},DKIM_SIGNED(0.00){raithel.dev:s=dkim;},DYN_RL(0.00){10000000000000 / 1s;real-login@sender.com;},DYN_RL_CHECK(0.00){},FROM_EQ_ENVFROM(0.00){},FROM_HAS_DN(0.00){},HAS_X_PRIO_ONE(0.00){1;},MAILCOW_DOMAIN_HEADER_FROM(0.00){raithel.dev;},MID_RHS_MATCH_FROM(0.00){},MIME_TRACE(0.00){0:+;1:+;2:~;},RCPT_COUNT_ONE(0.00){1;},RCPT_MAILCOW_DOMAIN(0.00){raithel.info;},RCVD_COUNT_ZERO(0.00){0;},TO_DN_NONE(0.00){},TO_MATCH_ENVRCPT_ALL(0.00){}]), len: 1065, time: 792.600ms, dns req: 11, digest: <b5f887ddbea5dd895d92ffcbbf25fd7a>, rcpts: <it@rcpt.com>, mime_rcpts: <it@rcpt.com>
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:25:54 #48(normal) <285bbd>; task; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 6 regexps matched, 3367 regexps total, 3064 regexps cached, 0B scanned using pcre, 1.44KiB scanned total
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:26:06 #47(controller) <32c0d5>; csession; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 0 regexps matched, 3367 regexps total, 2496 regexps cached, 0B scanned using pcre, 102B scanned total
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:26:28 #48(normal) <m5qf6z>; lua; ratelimit.lua:329: old style rate bucket config detected for mailcow: 10000000000000 / 1s
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:26:29 #48(normal) <c4f858>; task; rspamd_task_write_log: id: <d53c6235-c5a1-74ad-deea-19066a8d1e98@sender.com>, qid: <AB4FB5EED3>, ip: 123.123.123.123, user: real-login@sender.com, from: <allowed-spoofed@sender.com>, (default: F (no action): [-18.10/15.00] [MAILCOW_AUTH(-20.00){},MISSING_MIMEOLE(2.00){},MIME_GOOD(-0.10){multipart/alternative;text/plain;},ARC_NA(0.00){},ASN(0.00){asn:3320, ipnet:123.123.0.0/10, country:DE;},BCC(0.00){},DKIM_SIGNED(0.00){raithel.dev:s=dkim;},DYN_RL(0.00){10000000000000 / 1s;real-login@sender.com;},DYN_RL_CHECK(0.00){},FROM_EQ_ENVFROM(0.00){},FROM_HAS_DN(0.00){},HAS_X_PRIO_ONE(0.00){1;},MAILCOW_DOMAIN_HEADER_FROM(0.00){raithel.dev;},MID_RHS_MATCH_FROM(0.00){},MIME_TRACE(0.00){0:+;1:+;2:~;},RCPT_COUNT_ONE(0.00){1;},RCPT_MAILCOW_DOMAIN(0.00){raithel.info;},RCVD_COUNT_ZERO(0.00){0;},TO_DN_NONE(0.00){},TO_MATCH_ENVRCPT_ALL(0.00){}]), len: 1073, time: 1013.526ms, dns req: 11, digest: <f9d536576e918b1ea086f101c7297828>, rcpts: <recpt@rcpt.com>, mime_rcpts: <recpt@rcpt.com>
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:26:29 #48(normal) <c4f858>; task; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 6 regexps matched, 3367 regexps total, 3064 regexps cached, 0B scanned using pcre, 1.46KiB scanned total
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:26:50 #47(controller) <0334e5>; csession; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 0 regexps matched, 3367 regexps total, 2496 regexps cached, 0B scanned using pcre, 102B scanned total
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:26:53 #48(normal) <m5qf6z>; lua; ratelimit.lua:329: old style rate bucket config detected for mailcow: -1 / 1s
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:26:53 #48(normal) <700828>; task; rspamd_task_write_log: id: <947a7050-229b-161a-7a57-a8ebde9014d7@sender.com>, qid: <B86DB5EF08>, ip: 123.123.123.123, user: real-login@sender.com, from: <allowed-spoofed@sender.com>, (default: F (soft reject): [0.00/15.00] [ASN(0.00){asn:3320, ipnet:123.123.0.0/10, country:DE;},DYN_RL(0.00){-1 / 1s;real-login@sender.com;},DYN_RL_CHECK(0.00){},RATELIMITED(0.00){mailcow(RL7jkn1693un4cg41tw3y7ykn6);}]), len: 1063, time: 10.821ms, dns req: 2, digest: <864922914904834715d3952d3b4b63e3>, rcpts: <recpt@rcpt.com>, mime_rcpts: <recpt@rcpt.com>, forced: soft reject "Ratelimit "mailcow" exceeded"; score=nan (set by ratelimit)
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:26:53 #48(normal) <700828>; task; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 0 regexps matched, 3367 regexps total, 0 regexps cached, 0B scanned using pcre, 0B scanned total
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:27:47 #47(controller) <353272>; csession; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 0 regexps matched, 3367 regexps total, 2496 regexps cached, 0B scanned using pcre, 102B scanned total
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:28:33 #47(controller) <ababe7>; csession; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 0 regexps matched, 3367 regexps total, 2496 regexps cached, 0B scanned using pcre, 102B scanned total
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:29:23 #47(controller) <9adbcd>; csession; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 0 regexps matched, 3367 regexps total, 2496 regexps cached, 0B scanned using pcre, 102B scanned total
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:30:04 #47(controller) <4f2695>; csession; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 0 regexps matched, 3367 regexps total, 2496 regexps cached, 0B scanned using pcre, 102B scanned total
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:31:06 #47(controller) <13a1bb>; csession; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 0 regexps matched, 3367 regexps total, 2496 regexps cached, 0B scanned using pcre, 102B scanned total
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:31:28 #47(controller) <2bbe74>; csession; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 0 regexps matched, 3367 regexps total, 2496 regexps cached, 0B scanned using pcre, 102B scanned total
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:32:22 #48(normal) <m5qf6z>; lua; ratelimit.lua:329: old style rate bucket config detected for mailcow: -1 / 1s
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:32:22 #48(normal) <9dec7d>; task; rspamd_task_write_log: id: <6c48f29f-6205-1c78-d171-db3d57048a12@sender.com>, qid: <2730A5EF40>, ip: 123.123.123.123, user: real-login@sender.com, from: <allowed-spoofed@sender.com>, (default: F (soft reject): [0.00/15.00] [ASN(0.00){asn:3320, ipnet:123.123.0.0/10, country:DE;},DYN_RL(0.00){-1 / 1s;real-login@sender.com;},DYN_RL_CHECK(0.00){},RATELIMITED(0.00){mailcow(RL7jkn1693un4cg41tw3y7ykn6);}]), len: 1071, time: 15.231ms, dns req: 2, digest: <e263038bc903d37ea4b34a4ed24105b2>, rcpts: <recpt@rcpt.com>, mime_rcpts: <recpt@rcpt.com>, forced: soft reject "Ratelimit "mailcow" exceeded"; score=nan (set by ratelimit)
mailcowtestenv-rspamd-mailcow-1           | 2023-07-03 01:32:22 #48(normal) <9dec7d>; task; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 0 regexps matched, 3367 regexps total, 0 regexps cached, 0B scanned using pcre, 0B scanned total

mailcowtestenv-watchdog-mailcow-1         | Mon Jul 3 01:27:19 CEST 2023 Ratelimit health level: 0% (0/1), health trend: -1
mailcowtestenv-watchdog-mailcow-1         | Mon Jul 3 01:27:20 CEST 2023 Ratelimit hit error limit
mailcowtestenv-watchdog-mailcow-1         | Last 10 applied ratelimits (may overlap with previous reports).
mailcowtestenv-watchdog-mailcow-1         | Full ratelimit buckets can be emptied by deleting the ratelimit hash from within mailcow UI (see /debug -> Protocols -> Ratelimit):
mailcowtestenv-watchdog-mailcow-1         | 
mailcowtestenv-watchdog-mailcow-1         | {
mailcowtestenv-watchdog-mailcow-1         |   "time": 1688340413,
mailcowtestenv-watchdog-mailcow-1         |   "rcpt": "rcpt@rcpt.com",
mailcowtestenv-watchdog-mailcow-1         |   "from": "allowed-spoofed@sender.com",
mailcowtestenv-watchdog-mailcow-1         |   "user": "real-login@sender.com",
mailcowtestenv-watchdog-mailcow-1         |   "rl_info": "mailcow(RL7jkn1693un4cg41tw3y7ykn6)",
mailcowtestenv-watchdog-mailcow-1         |   "rl_name": "mailcow",
mailcowtestenv-watchdog-mailcow-1         |   "rl_hash": "RL7jkn1693un4cg41tw3y7ykn6",
mailcowtestenv-watchdog-mailcow-1         |   "qid": "B86DB5EF08",
mailcowtestenv-watchdog-mailcow-1         |   "ip": "123.123.123.123",
mailcowtestenv-watchdog-mailcow-1         |   "message_id": "947a7050-229b-161a-7a57-a8ebde9014d7@sender.com",
mailcowtestenv-watchdog-mailcow-1         |   "header_subject": "Title 1",
mailcowtestenv-watchdog-mailcow-1         |   "header_from": "allowed-spoofed <allowed-spoofed@sender.com>"
mailcowtestenv-watchdog-mailcow-1         | }
mailcowtestenv-watchdog-mailcow-1         | {
mailcowtestenv-watchdog-mailcow-1         |   "time": 1688340289,
mailcowtestenv-watchdog-mailcow-1         |   "rcpt": "rcpt@rcpt.com",
mailcowtestenv-watchdog-mailcow-1         |   "from": "allowed-spoofed@sender.com",
mailcowtestenv-watchdog-mailcow-1         |   "user": "real-login@sender.com",
mailcowtestenv-watchdog-mailcow-1         |   "rl_info": "mailcow(RL7jkn1693un4cg41tw3y7ykn6)",
mailcowtestenv-watchdog-mailcow-1         |   "rl_name": "mailcow",
mailcowtestenv-watchdog-mailcow-1         |   "rl_hash": "RL7jkn1693un4cg41tw3y7ykn6",
mailcowtestenv-watchdog-mailcow-1         |   "qid": "C8F8C5DF30",
mailcowtestenv-watchdog-mailcow-1         |   "ip": "123.123.123.123",
mailcowtestenv-watchdog-mailcow-1         |   "message_id": "90fc9ea7-fc0e-5f0d-a8b1-dc74785d3468@sender.com",
mailcowtestenv-watchdog-mailcow-1         |   "header_subject": "Title 2",
mailcowtestenv-watchdog-mailcow-1         |   "header_from": "allowed-spoofed <allowed-spoofed@sender.com>"
mailcowtestenv-watchdog-mailcow-1         | }

mailcowtestenv-postfix-mailcow-1          | Jul  3 01:26:53 eb54cfeb0022 postfix/submission/smtpd[440]: connect from sender.ip.com[123.123.123.123]
mailcowtestenv-postfix-mailcow-1          | Jul  3 01:26:53 eb54cfeb0022 postfix/submission/smtpd[440]: B86DB5EF08: client=sender.ip.com[123.123.123.123], sasl_method=PLAIN, sasl_username=real-login@sender.com
mailcowtestenv-postfix-mailcow-1          | Jul  3 01:26:53 eb54cfeb0022 postfix/cleanup[442]: B86DB5EF08: replace: header Received: from [127.0.0.1] (sender.ip.com [123.123.123.123])??(using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)?? key-exchange X25519 server-signature RSA-PSS (4096 bits)  from sender.ip.com[123.123.123.123]; from=<allowed-spoofed@sender.com> to=<rcpt@rcpt.com> proto=ESMTP helo=<[127.0.0.1]>: Received: from [127.0.0.1] (localhost [127.0.0.1]) by localhost (Mailerdaemon) with ESMTPSA id B86DB5EF08??for <rcpt@rcpt.com>; Mon,  3 Jul 2023 01:26:53 +0200 (CEST)
mailcowtestenv-postfix-mailcow-1          | Jul  3 01:26:53 eb54cfeb0022 postfix/cleanup[442]: B86DB5EF08: message-id=<947a7050-229b-161a-7a57-a8ebde9014d7@sender.com>
mailcowtestenv-postfix-mailcow-1          | Jul  3 01:26:53 eb54cfeb0022 postfix/cleanup[442]: B86DB5EF08: milter-reject: END-OF-MESSAGE from sender.ip.com[123.123.123.123]: 4.7.1 Ratelimit "mailcow" exceeded; from=<allowed-spoofed@sender.com> to=<rcpt@rcpt.com> proto=ESMTP helo=<[127.0.0.1]>
mailcowtestenv-postfix-mailcow-1          | Jul  3 01:26:53 eb54cfeb0022 postfix/submission/smtpd[440]: disconnect from sender.ip.com[123.123.123.123] ehlo=2 starttls=1 auth=1 mail=1 rcpt=1 data=0/1 commands=6/7
mailcowtestenv-postfix-mailcow-1          | Jul  3 01:30:14 eb54cfeb0022 postfix/anvil[432]: statistics: max connection rate 3/60s for (submission:123.123.123.123) at Jul  3 01:26:53
mailcowtestenv-postfix-mailcow-1          | Jul  3 01:30:14 eb54cfeb0022 postfix/anvil[432]: statistics: max connection count 1 for (submission:123.123.123.123) at Jul  3 01:22:06
mailcowtestenv-postfix-mailcow-1          | Jul  3 01:30:14 eb54cfeb0022 postfix/anvil[432]: statistics: max cache size 1 at Jul  3 01:22:06
mailcowtestenv-postfix-mailcow-1          | Jul  3 01:32:21 eb54cfeb0022 postfix/submission/smtpd[461]: connect from sender.ip.com[123.123.123.123]
mailcowtestenv-postfix-mailcow-1          | Jul  3 01:32:22 eb54cfeb0022 postfix/submission/smtpd[461]: 2730A5EF40: client=sender.ip.com[123.123.123.123], sasl_method=PLAIN, sasl_username=real-login@sender.com
mailcowtestenv-postfix-mailcow-1          | Jul  3 01:32:22 eb54cfeb0022 postfix/cleanup[465]: 2730A5EF40: replace: header Received: from [127.0.0.1] (sender.ip.com [123.123.123.123])??(using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)?? key-exchange X25519 server-signature RSA-PSS (4096 bits)  from sender.ip.com[123.123.123.123]; from=<allowed-spoofed@sender.com> to=<rcpt@rcpt.com> proto=ESMTP helo=<[127.0.0.1]>: Received: from [127.0.0.1] (localhost [127.0.0.1]) by localhost (Mailerdaemon) with ESMTPSA id 2730A5EF40??for <rcpt@rcpt.com>; Mon,  3 Jul 2023 01:32:22 +0200 (CEST)
mailcowtestenv-postfix-mailcow-1          | Jul  3 01:32:22 eb54cfeb0022 postfix/cleanup[465]: 2730A5EF40: message-id=<6c48f29f-6205-1c78-d171-db3d57048a12@sender.com>
mailcowtestenv-postfix-mailcow-1          | Jul  3 01:32:22 eb54cfeb0022 postfix/cleanup[465]: 2730A5EF40: milter-reject: END-OF-MESSAGE from sender.ip.com[123.123.123.123]: 4.7.1 Ratelimit "mailcow" exceeded; from=<allowed-spoofed@sender.com> to=<rcpt@rcpt.com> proto=ESMTP helo=<[127.0.0.1]>
mailcowtestenv-postfix-mailcow-1          | Jul  3 01:32:22 eb54cfeb0022 postfix/submission/smtpd[461]: disconnect from sender.ip.com[123.123.123.123] ehlo=2 starttls=1 auth=1 mail=1 rcpt=1 data=0/1 commands=6/7

Steps to reproduce:

1. Send multiple emails with a single user to another single user
2. Hit the "mailcow" ratelimit

3. Increase the "Disabled" rate limit for a user `-1` -> `n`
4. Now the "enabled" rate limit seems to work

Which branch are you using?

master

Operating System:

Ubuntu 22.04.2 LTS

Server/VM specifications:

8GB Ram, 2 CPU cores

Is Apparmor, SELinux or similar active?

no

Virtualization technology:

Hetzner VPS

Docker version:

24.0.2

docker-compose version or docker compose version:

v2.11.2

mailcow version:

2023-05a

Reverse proxy:

Nginx

Logs of git diff:

None that should affect this (certificates, custom sieves, ipv6 disabled)

Logs of iptables -L -vn:

Comment was to long and it's not an issue with any networking

Logs of ip6tables -L -vn:

Comment was to long and it's not an issue with any networking

Logs of iptables -L -vn -t nat:

Comment was to long and it's not an issue with any networking

Logs of ip6tables -L -vn -t nat:

Comment was to long and it's not an issue with any networking

DNS check:

151.101.193.69
151.101.129.69
151.101.1.69
151.101.65.69

MAGICCC commented 1 year ago

A mailbox rate limit overrides a domain-wide rate limit. And disabled ratelimit is '0' and not '-1'

Coronon commented 1 year ago

Thank you for the clarification :)

I knew about the override, but what does the default -1 imply then, and why do two emails minutes apart trigger a rate limit (mailcows defaults)? Could the fact that both domains are hosted on the same instance play a role in that?

MAGICCC commented 1 year ago

-1 isn't default, maybe you changed your template? I don't know what -1 will do maybe @DerLinkman knows it?

Coronon commented 1 year ago

I definitely didn’t change it for that user as it was freshly created. I also can’t remember changing anything like it on a higher level. But if the solution is to simply set them all to 0, that’s simple enough I guess ^^

The question then becomes: Why does a value of -1 trigger a ratelimit ‘mailcow’ so fast, but not instantly?

milkmaker commented 1 year ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.

mailcow / mailcow-dockerized