vstakhov / rmilter

Another sendmail milter for different mail checks.
86 stars 18 forks source link

Problem with greylisting #75

Closed damned-trooper closed 8 years ago

damned-trooper commented 8 years ago

Hi.

As i see in logs, greylisting does not working. Log entries:

Jan 26 21:15:20 mx01 postfix-in/cleanup[13053]: BD6731A46C: milter-reject: END-OF-MESSAGE from mail130.atl21.rsgsv.net[205.201.133.130]: 4.7.1 Try again later; from=bounce-mc.us12_48108381.152121-sviridov=lankey.ru@mail130.atl21.rsgsv.net to=_sviridov@lankey.ru_ proto=ESMTP helo= Jan 26 21:30:22 mx01 postfix-in/cleanup[13723]: 292FC1A46C: milter-reject: END-OF-MESSAGE from mail130.atl21.rsgsv.net[205.201.133.130]: 4.7.1 Try again later; from=bounce-mc.us12_48108381.152121-sviridov=lankey.ru@mail130.atl21.rsgsv.net to=_sviridov@lankey.ru_ proto=ESMTP helo=

This message was resubmitted in 15 minutes but answer is 4.7.1 to.

Versions: CentOS Linux release 7.2.1511 (Core) rmilter-1.7.2-1.x86_64 (builded today from git master)

Config:

greylisting { timeout = 50s; expire = 3d; awl_enable = yes; awl_pool = 10M; awl_hits = 10; awl_ttl = 3600s; };

Greylisting backend is Redis. In Redis i can see entries for incoming messages.

damned-trooper commented 8 years ago

Key from Redis for this message:

[root@mx01 ~]# redis-cli keys * | grep bounc | grep svir sviridov@lankey.ru:205.201.133.130:bounce-mc.us12_48108381.152121-sviridov=lankey.ru@mail130.atl21.rsgsv.net

damned-trooper commented 8 years ago

Very strange.

After six hours of rejecting message was accepted:

[root@mx01 ~]# cat /var/log/maillog | grep sviri | grep mail130 Jan 26 13:28:20 mx01 postfix-in/cleanup[23074]: 8AD73133656: milter-reject: END-OF-MESSAGE >from mail130.atl21.rsgsv.net[205.201.133.130]: 4.7.1 Try again later; from=bounce-mc.us12_48108381.152121-sviridov=lankey.ru@mail130.atl21.rsgsv.net to=sviridov@lankey.ru proto=ESMTP helo= ... Jan 26 21:30:22 mx01 postfix-in/cleanup[13723]: 292FC1A46C: milter-reject: END-OF-MESSAGE from mail130.atl21.rsgsv.net[205.201.133.130]: 4.7.1 Try again later; from=bounce-mc.us12_48108381.152121-sviridov=lankey.ru@mail130.atl21.rsgsv.net to=sviridov@lankey.ru proto=ESMTP helo= Jan 26 21:45:27 mx01 postfix-in/cleanup[13848]: 82F0C1A46C: milter-reject: END-OF-MESSAGE from mail130.atl21.rsgsv.net[205.201.133.130]: 4.7.1 Try again later; from=bounce-mc.us12_48108381.152121-sviridov=lankey.ru@mail130.atl21.rsgsv.net to=sviridov@lankey.ru proto=ESMTP helo= Jan 26 22:00:31 mx01 postfix-in/qmgr[3505]: 44BDE1A46C: from=bounce-mc.us12_48108381.152121-sviridov=lankey.ru@mail130.atl21.rsgsv.net, size=37717, nrcpt=1 (queue active) Jan 26 22:00:31 mx01 postfix-in/smtp[13971]: 44BDE1A46C: to=sviridov@lankey.ru, relay=192.168.50.225[192.168.50.225]:25, delay=3.3, delays=3.1/0/0/0.12, dsn=2.6.0, status=sent (250 2.6.0 18dfad62acc580958bd0422083407143bf9.20160126102815@mail130.atl21.rsgsv.net [InternalId=3246995275778, Hostname=M4.LanDomain.ru] Queued mail for delivery)

I did not understand what happend.

damned-trooper commented 8 years ago

I have tried to get some statitics about greylisting in my case. Most messages stuck in greylist. Examples:

Jan 26 16:37:02 mx01 postfix-in/cleanup[25540]: 216BD5E8C: milter-reject: END-OF-MESSAGE from roberto.drweb.com[213.79.65.42]: 4.7.1 Try again later; from=www-data@roberto.drweb.com to=sviridov@lankey.ru proto=ESMTP helo= Jan 26 20:53:38 mx01 postfix-in/cleanup[13051]: 1048544F73: milter-reject: END-OF-MESSAGE from roberto.drweb.com[213.79.65.42]: 4.7.1 Try again later; from= www-data@roberto.drweb.com> to=sviridov@lankey.ru proto=ESMTP helo= Jan 26 23:05:22 mx01 postfix-in/cleanup[14435]: EF35E1A46C: milter-reject: END-OF-MESSAGE from roberto.drweb.com[213.79.65.42]: 4.7.1 Try again later; from= www-data@roberto.drweb.com> to=sviridov@lankey.ru proto=ESMTP helo=

Jan 26 17:57:21 mx01 postfix-in/cleanup[10717]: AD91444F73: milter-reject: END-OF-MESSAGE from relay05.nicmail.ru[194.85.88.236]: 4.7.1 Try again later; from=fensys@tor-haus.ru to=lankey@lankey.ru proto=ESMTP helo= Jan 26 20:31:45 mx01 postfix-in/cleanup[12844]: 43EE544F73: milter-reject: END-OF-MESSAGE from relay05.nicmail.ru[194.85.88.236]: 4.7.1 Try again later; from=fensys@tor-haus.ru to=lankey@lankey.ru proto=ESMTP helo= Jan 26 22:36:29 mx01 postfix-in/cleanup[14196]: E87801A46C: milter-reject: END-OF-MESSAGE from relay05.nicmail.ru[194.85.88.236]: 4.7.1 Try again later; from=fensys@tor-haus.ru to=lankey@lankey.ru proto=ESMTP helo=

Jan 26 14:47:14 mx01 postfix-in/cleanup[23790]: E882D133656: milter-reject: END-OF-MESSAGE from mail1.1gl.ru[83.69.214.133]: 4.7.1 Try again later; from=news@1kadry.ru to=lankey@lankey.ru proto=ESMTP helo= Jan 26 18:47:31 mx01 postfix-in/cleanup[11442]: 96983ACD3E: milter-reject: END-OF-MESSAGE from mail1.1gl.ru[83.69.214.133]: 4.7.1 Try again later; from=news@1kadry.ru to=lankey@lankey.ru proto=ESMTP helo= Jan 26 22:47:31 mx01 postfix-in/cleanup[14286]: 6327F1A46C: milter-reject: END-OF-MESSAGE from mail1.1gl.ru[83.69.214.133]: 4.7.1 Try again later; from=news@1kadry.ru to=lankey@lankey.ru proto=ESMTP helo=

etc...

I can provide any required debug information to eliminate this bug.

damned-trooper commented 8 years ago

I set option "servers_white" in config file and it seems greylisting work fine. I will check in a few days and then i'll close issue.

vstakhov commented 8 years ago

I've found the issue: the greylisting and whitelisting expire times do not have sane defaults!

vstakhov commented 8 years ago

Ok, I've changed them to a more sane behaviour.

damned-trooper commented 8 years ago

Problem fixed.