SMTP "451 4.7.1 Try again later" SMTP responses

Server side in /var/log/mailog

Feb 21 07:58:56 nethserver postfix/smtpd[10425]: connect from uk1-rack-lon2.inumbo.com[162.13.166.7]
Feb 21 07:58:56 nethserver rspamd[2703]: <35aaa9>; proxy; proxy_accept_socket: accepted milter connection from /var/run/rspamd/worker-proxy port 0
Feb 21 07:58:56 nethserver postfix/smtpd[10425]: 9EA57E3889: client=uk1-rack-lon2.inumbo.com[162.13.166.7]
Feb 21 07:58:56 nethserver rspamd[2703]: <35aaa9>; milter; rspamd_milter_process_command: got connection from 162.13.166.7:59881
Feb 21 07:58:56 nethserver postfix/cleanup[25150]: 9EA57E3889: message-id=<9DSH2-7OHVqkLTz-9YQu-12PFe6NoEjwQY9cTsb@email.hush-newsletter.com>
Feb 21 07:58:56 nethserver rspamd[2703]: <35aaa9>; proxy; rspamd_message_parse: loaded message; id: <9DSH2-7OHVqkLTz-9YQu-12PFe6NoEjwQY9cTsb@email.hush-newsletter.com>; queue-id: <9EA57E3889>; size: 85045; checksum: <1da384755e531b09c9ce9e66d1e8d9ef>
Feb 21 07:58:56 nethserver rspamd[2703]: <35aaa9>; proxy; rspamd_mime_part_detect_language: detected part language: en
Feb 21 07:58:56 nethserver rspamd[2703]: <35aaa9>; proxy; rspamd_mime_part_detect_language: detected part language: en
Feb 21 07:58:56 nethserver rspamd[2703]: <35aaa9>; lua; greylist.lua:271: greylisted until "Sun, 21 Feb 2021 08:02:56 GMT" (meta and body)
Feb 21 07:58:56 nethserver rspamd[2703]: <35aaa9>; proxy; rspamd_add_passthrough_result: <9DSH2-7OHVqkLTz-9YQu-12PFe6NoEjwQY9cTsb@email.hush-newsletter.com>: set pre-result to 'soft reject' (no score): 'Try again later' from greylist(1)
Feb 21 07:58:56 nethserver rspamd[2703]: <35aaa9>; proxy; rspamd_task_write_log: id: <9DSH2-7OHVqkLTz-9YQu-12PFe6NoEjwQY9cTsb@email.hush-newsletter.com>, qid: <9EA57E3889>, ip: 162.13.166.7, from: <SRS0=8WiP=HX=email.hush-newsletter.com=mail.zvdcabhznfoapnixbqb@srs-uk1.protection.inumbo.net>, (default: F (soft reject): [0.00/20.00] [ASN(0.00){asn:15395, ipnet:162.13.0.0/16, country:GB;},GREYLIST(0.00){greylisted;Sun, 21 Feb 2021 08:02:56 GMT;too early;}]), len: 85045, time: 13.792ms, dns req: 1, digest: <1da384755e531b09c9ce9e66d1e8d9ef>, rcpts: <hazel@REDACTED.co.uk>, mime_rcpts: <hazel@REDACTED.co.uk>, forced: soft reject "Try again later"; score=nan (set by greylist)
Feb 21 07:58:56 nethserver rspamd[2703]: <35aaa9>; proxy; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 0 regexps matched, 184 regexps total, 0 regexps cached, 0B scanned using pcre, 0B scanned total
Feb 21 07:58:56 nethserver postfix/cleanup[25150]: 9EA57E3889: milter-reject: END-OF-MESSAGE from uk1-rack-lon2.inumbo.com[162.13.166.7]: 4.7.1 Try again later;
> Feb 21 08:33:29 nethserver postfix/smtpd[32222]: connect from uk1-rack-lon2.inumbo.com[162.13.166.7]
> Feb 21 08:33:29 nethserver rspamd[2703]: <82ecc9>; proxy; proxy_accept_socket: accepted milter connection from /var/run/rspamd/worker-proxy port 0
> Feb 21 08:33:29 nethserver postfix/smtpd[32222]: D3CF9E3896: client=uk1-rack-lon2.inumbo.com[162.13.166.7]
> Feb 21 08:33:29 nethserver rspamd[2703]: <82ecc9>; milter; rspamd_milter_process_command: got connection from 162.13.166.7:32388
> Feb 21 08:33:29 nethserver postfix/cleanup[1521]: D3CF9E3896: message-id=<44B8.10KZ3.6B1D87FB5800B8326E9VZF5489698ABCD2C709.20210221083327606@r1.dotdigital-email.com>
> Feb 21 08:33:29 nethserver rspamd[2703]: <82ecc9>; proxy; rspamd_message_parse: loaded message; id: <44B8.10KZ3.6B1D87FB5800B8326E9VZF5489698ABCD2C709.20210221083327606@r1.dotdigital-email.com>; queue-id: <D3CF9E3896>; size: 68376; checksum: <39093f49f91060031f1b2929b79e6029>
> Feb 21 08:33:29 nethserver rspamd[2703]: <82ecc9>; proxy; rspamd_mime_part_detect_language: detected part language: en
> Feb 21 08:33:29 nethserver rspamd[2703]: <82ecc9>; proxy; rspamd_mime_part_detect_language: detected part language: en
> Feb 21 08:33:30 nethserver rspamd[2703]: <82ecc9>; proxy; dkim_module_key_handler: stored DKIM key for dkim1024._domainkey.dkim.dotmailer.com in LRU cache for 3600 seconds, 465/2000 elements in the cache
> Feb 21 08:33:30 nethserver rspamd[2703]: <82ecc9>; proxy; dkim_module_key_handler: stored DKIM key for dkim1024._domainkey.dotdigital-email.com in LRU cache for 3600 seconds, 466/2000 elements in the cache
> Feb 21 08:33:30 nethserver rspamd[2703]: <82ecc9>; proxy; rspamd_redis_connected: skip obtaining bayes tokens for BAYES_SPAM of classifier bayes: not enough learns 119; 200 required
> Feb 21 08:33:30 nethserver rspamd[2703]: <82ecc9>; proxy; rspamd_stat_classifiers_process: skip statistics as SPAM class is missing
> Feb 21 08:33:30 nethserver rspamd[2703]: <82ecc9>; lua; greylist.lua:416: greylisted until "Sun, 21 Feb 2021 08:38:30 GMT", new record
> Feb 21 08:33:30 nethserver rspamd[2703]: <82ecc9>; proxy; rspamd_add_passthrough_result: <44B8.10KZ3.6B1D87FB5800B8326E9VZF5489698ABCD2C709.20210221083327606@r1.dotdigital-email.com>: set pre-result to 'soft reject' (no score): 'Try again later' from greylist(1)
> Feb 21 08:33:30 nethserver rspamd[2703]: <82ecc9>; proxy; rspamd_task_write_log: id: <44B8.10KZ3.6B1D87FB5800B8326E9VZF5489698ABCD2C709.20210221083327606@r1.dotdigital-email.com>, qid: <D3CF9E3896>, ip: 162.13.166.7, from: <SRS0=RAXR=HX=r1.dotdigital-email.com=bo-44b8-10kz3-6e9vzf-c16df@srs-uk1.protection.inumbo.net>, (default: F (soft reject): [6.29/20.00] [RSPAMD_URIBL(4.50){ddlnk.net:url;},MANY_INVISIBLE_PARTS(1.00){10;},HTML_SHORT_LINK_IMG_3(0.50){},FORGED_SENDER(0.30){Stauer@r1.dotdigital-email.com;SRS0=RAXR=HX=r1.dotdigital-email.com=bo-44b8-10kz3-6e9vzf-c16df@srs-uk1.protection.inumbo.net;},BAD_REP_POLICIES(0.10){},MIME_GOOD(-0.10){multipart/alternative;text/plain;},HAS_LIST_UNSUB(-0.01){},MX_GOOD(-0.01){},XM_UA_NO_VERSION(0.01){},ASN(0.00){asn:15395, ipnet:162.13.0.0/16, country:GB;},DKIM_TRACE(0.00){dotdigital-email.com:+;dkim.dotmailer.com:+;},DMARC_POLICY_ALLOW(0.00){r1.dotdigital-email.com;none;},FROM_HAS_DN(0.00){},FROM_NEQ_ENVFROM(0.00){Stauer@r1.dotdigital-email.com;SRS0=RAXR=HX=r1.dotdigital-email.com=bo-44b8-10kz3-6e9vzf-c16df@srs-uk1.protection.inumbo.net;},GENERIC_REPUTATION(0.00){-0.32106786437009;},GREYLIST(0.00){greylisted;Sun, 21 Feb 2021 08:38:30 GMT;new record;},HAS_REPLYTO(0.00){re-44B8-10KZ3-6E9VZF-C16DF@r1.dotdigital-email.com;},IP_REPUTATION_HAM(0.00){asn: 15395(-0.13), country: GB(-0.00), ip: 162.13.166.7(-0.32);},MID_RHS_MATCH_FROM(0.00){},MIME_TRACE(0.00){0:+;1:+;2:~;},RCPT_COUNT_ONE(0.00){1;},RCVD_COUNT_TWO(0.00){2;},RCVD_TLS_ALL(0.00){},REPLYTO_DN_EQ_FROM_DN(0.00){},REPLYTO_DOM_EQ_FROM_DOM(0.00){},R_DKIM_ALLOW(0.00){dotdigital-email.com:s=dkim1024;dkim.dotmailer.com:s=dkim1024;},R_SPF_NA(0.00){no SPF record;},TO_DN_NONE(0.00){},TO_MATCH_ENVRCPT_ALL(0.00){}]), len: 68376, time: 372.450ms, dns req: 60, digest: <39093f49f91060031f1b2929b79e6029>, rcpts: <ADDRESSREDACTED>, mime_rcpts: <ADDRESSREDACTED>, forced: soft reject "Try again later"; score=nan (set by greylist)
> Feb 21 08:33:30 nethserver rspamd[2703]: <82ecc9>; proxy; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 3 regexps matched, 184 regexps total, 80 regexps cached, 0B scanned using pcre, 71.12KiB scanned total
> Feb 21 08:33:30 nethserver postfix/cleanup[1521]: D3CF9E3896: milter-reject: END-OF-MESSAGE from uk1-rack-lon2.inumbo.com[162.13.166.7]: 4.7.1 Try again later; from=<SRS0=RAXR=HX=r1.dotdigital-email.com=bo-44b8-10kz3-6e9vzf-c16df@srs-uk1.protection.inumbo.net> to=<ADDRESSREDACTED> proto=ESMTP helo=<uk1-rack-lon2.inumbo.com>
> Feb 21 08:33:30 nethserver postfix/smtpd[32222]: disconnect from uk1-rack-lon2.inumbo.com[162.13.166.7]
> Feb 21 08:33:30 nethserver rspamd[2703]: <2ded99>; proxy; proxy_milter_finish_handler: finished milter connection

Hi @stephdl,

Do these logs tell you anything useful? I appreciate your help.

Thanks

John

set pre-result to ‘soft reject’ (no score): ‘Try again later’ from greylist(1)

what is the score of greylist

config show rspamd

try to disabled greylisting also

rspamd=service
    BlockAttachmentClassList=Exec
    BlockAttachmentCustomList=iso,scr
    BlockAttachmentCustomStatus=enabled
    BlockAttachmentStatus=enabled
    OletoolsStatus=enabled
    Password=removed
    RecipientWhiteList=
    SenderBlackList=
    SenderWhiteList=
    SpamCheckStatus=disabled
    SpamGreyLevel=4
    SpamKillLevel=16
    SpamSubjectPrefixStatus=disabled
    SpamSubjectPrefixString=***SPAM***
    SpamTag2Level=7
    VirusAction=reject
    VirusCheckStatus=disabled
    VirusScanOnlyAttachment=false
    VirusScanSize=20000000
    isLoading=false
    status=enabled

I have the Antispam set to disabled and the problem is still happening.

Thanks @mark_nl @stephdl. I’ve disabled greylisting and will see what happens overnight.

like you see rspamd is still up

this is my settings

[root@prometheus ~]# config show rspamd | grep 'Spam'
    SpamCheckStatus=enabled
    SpamDsnLevel=20
    SpamGreyLevel=
    SpamKillLevel=19.9
    SpamNotification=disabled
    SpamNotificationStatus=enabled
    SpamSubjectPrefixStatus=enabled
    SpamSubjectPrefixString=***SPAM***
    SpamTag2Level=8
    SpamTagLevel=2

by curiosity what is the output of

rspamadm configdump | grep -A 5 'greylist'

greylist should be enabled = false;

greylist_invalid = false;
    expire_novalid = 7200;
    symbol_no_mx = "MX_MISSING";
    enabled = true;
    key_prefix = "rmx";
    expire = 86400;
--
    greylist = null;
}
elastic {
    limit = 10;
    import_kibana = false;
    debug = false;
--
greylist {
    ipv6_mask = 64;
    whitelist_domains_url [
        "/etc/rspamd/local.d/greylist-whitelist-domains.inc",
        "/etc/rspamd/local.d/maps.d/greylist-whitelist-domains.inc",
    ]
    expire = 86400;
    key_prefix = "rg";
    enabled = false;
    ipv4_mask = 19;

Here (with setting shown in screen shot above):

# rspamadm configdump | grep -A 5 'greylist'
    greylist_invalid = false;
    expire_novalid = 7200;
    symbol_no_mx = "MX_MISSING";
    enabled = true;
    key_prefix = "rmx";
    expire = 86400;
--
    greylist = null;
}
elastic {
    limit = 10;
    import_kibana = false;
    debug = false;
--
greylist {
    ipv6_mask = 64;
    whitelist_domains_url [
        "/etc/rspamd/local.d/greylist-whitelist-domains.inc",
        "/etc/rspamd/local.d/maps.d/greylist-whitelist-domains.inc",
    ]
    expire = 86400;
    key_prefix = "rg";
    enabled = false;
    ipv4_mask = 19;

shows : enabled = false;

well for me the disabled state of rspamd is like it has not been saved in the UI, in a workable rspamd, each plugin gets :expressionless:

 greylist {
    enabled = false;
}
mime_types {
    enabled = false;
}

AFAIK greylisting (451 4.7.1 Try again later”) is totally following the RFC related to SMTP and therefore shouldn’t pose any problem. I’d look somewhere else.

The server being not accessible is a better track I guess.

1 Like

It is true, if postfix cannot use the rspamd linux socket you have also a try again later, but the evidence is in maillog, you can state on it

@pagaille
@stephdl

In the end it was in fact two problems. The 4.7.1 was due to greylisting behaviour which you helped me with, thank you. This explains Scenario 2 in my first post.

But also, one of my inbound MX IP was getting banned by fail2ban I found so I had to whitelist that IP which explained Scenario 1. Other MX IP we not banned, I am not sure why this was happening but everything is back to normal now.

2 Likes

Fail2ban helps to ban bad login to postfix, ddos and also a specific jail to prevent to use your smtp too many times to send email iirc about 100 email/minutes per IP

Maybe the greylist rejections increased the number of retries from my MX provider and triggered the ban.

1 Like

only fail2ban log can bring some answers