I asked to upstream, need to wait after, the quick fix now is to increase the timeout to 25s.
In fact when rspamd cannot contact clamd, it fails with a symbol but never by a timeout, however with rspamc it is different, if clamav is not able to be reachable, then the task_timout ends the transaction.
I have maybe a better idea, we introduced with rspamd2 a value which is not from upstream
in /etc/rspamd/rspamd.conf
# Emit soft reject when timeout takes place
soft_reject_on_timeout = true;
the default is false
could you go back to the default timeout 8s and set to false the soft_reject_on_timeout
think to restart the rspamd
validated on my server, rspamc wait that the end of clamav reloading
I just made this change, thanks, this sounds good.
I will report that I have been at task_timeout = 8s most of the day today, since the suggested unchecking of “ClamAV official signatures” as suggested, and received no timeouts. So, I think that had something to do with it I believe. Not sure if for debugging purposes I shoud re-check that box, but if that is the new default I would not want it checked anyway.
Was going to update at the end of the day, but it’s only an hour away now.
No timeouts, I have had ZERO soft rejects since I made the change.
Please note that I also unchecked “ClamAV official signatures” from ClamAV settings as suggested yesterday morning and never received any after that before changing soft_reject_on_timeout, so not sure what had the most affect. If you would like me to run a day with ClamAV official signatures back on I can do that if you want, if it gives yo more info.
Either way, it’s working great now.
Yes please try to enable them again!
I bet you’ll get back the soft rejects and the discarded messages
Ok, I’ll update tomorrow.
Do you have any news?
Meanwhile, there is a bug fix to test.
Ensure there are no local modification to the rspamd configuration. Then you could install it with
yum --enablerepo=nethserver-testing update nethserver-mail\*
More information here:
POP3 connector discards mail during ClamAV reloads · Issue #6052 · NethServer/dev · GitHub
For me it has only been 1 hour at the end of the work day yesterday, and 3 hours today, but so far I have received no soft rejects or timeouts.
This is with
task_timout = 8s;
soft_reject_on_timeout = false;
Should I be setting soft_reject_on_timeout back to true as was the default?
soft_reject_on_timeout = true;
Also, in the ClamAV settings, should I re-check “ClamAV official signatures”? Even though @giacomo says that unchecked is the new default?
I probably won’t feel comfortable updating until outside of working hours after a backup, so will do later and can then test all weekend.
…and are there any timeouts in your logs?
Well, that modification should be automatically overwritten by the update, because /etc/rspamd/rspamd.conf is expanded by our template. Take it into consideration.
I suggest to keep it disabled. However to validate the bugfix I ask to re-enable them for a few hours, just to be sure the bug does not bite any more.
No problem! Thank you very much for your help!
first thought on getmail verification
Feb 7 17:55:04 prometheus rspamd[31990]: <aad1be>; csession; rspamd_controller_check_password: allow unauthorized connection from a trusted IP 127.0.0.1
Feb 7 17:55:04 prometheus rspamd[31990]: <aad1be>; csession; rspamd_message_parse: loaded message; id: <10acb788-182b-4b2c-fcdb-a85adf159e66@chubbfrance.com>; queue-id: <undef>; size: 513806; checksum: <0ecb0f65a1407a86243c84f546feba97>
Feb 7 17:55:04 prometheus rspamd[31990]: <aad1be>; csession; rspamd_mime_part_detect_language: detected part language: fr
Feb 7 17:55:04 prometheus rspamd[31990]: <aad1be>; csession; spf_symbol_callback: skip SPF checks for local networks and authorized users
Feb 7 17:55:04 prometheus rspamd[31990]: <aad1be>; csession; dkim_symbol_callback: skip DKIM checks for local networks and authorized users
Feb 7 17:55:04 prometheus rspamd[31990]: <aad1be>; lua; dmarc.lua:572: skip DMARC checks for local networks and authorized users
Feb 7 17:55:04 prometheus rspamd[31990]: <aad1be>; lua; once_received.lua:98: Skipping once_received for authenticated user or local network
Feb 7 17:55:19 prometheus rspamd[31990]: <aad1be>; lua; clamav.lua:119: clamav: failed to scan, maximum retransmits exceed
Feb 7 17:55:19 prometheus rspamd[31990]: <aad1be>; lua; common.lua:107: clamav: result - FAILED with error: "failed to scan and retransmits exceed - score: 0"
Feb 7 17:55:19 prometheus rspamd[31990]: <aad1be>; csession; rspamd_add_passthrough_result: <10acb788-182b-4b2c-fcdb-a85adf159e66@chubbfrance.com>: set pre-result to 'soft reject' (no score): 'Cannot validate the message now. Try again later' from force_actions(1)
Feb 7 17:55:19 prometheus rspamd[31990]: <aad1be>; csession; rspamd_task_write_log: id: <10acb788-182b-4b2c-fcdb-a85adf159e66@chubbfrance.com>, ip: 127.0.0.1, from: <stephane.delabrusse@Chubbfrance.com>, (default: F (soft reject): [1.10/19.90] [DATE_IN_PAST(1.00){},MIME_BASE64_TEXT(0.10){},MIME_GOOD(-0.10){multipart/mixed;text/plain;},RCVD_NO_TLS_LAST(0.10){},CLAM_VIRUS_FAIL(0.00){failed to scan and retransmits exceed;},FORCE_ACTION_CLAM_VIRUS_FAIL(0.00){soft reject;},FROM_EQ_ENVFROM(0.00){},FROM_HAS_DN(0.00){},GENERIC_REPUTATION(0.00){-0.27631962925491;},HAS_ATTACHMENT(0.00){},HAS_XOIP(0.00){},MID_RHS_MATCH_FROM(0.00){},MIME_TRACE(0.00){0:+;1:+;2:~;},PREVIOUSLY_DELIVERED(0.00){stephane@de-labrusse.fr;},RCPT_COUNT_ONE(0.00){1;},RCVD_COUNT_FIVE(0.00){5;},TO_DN_EQ_ADDR_ALL(0.00){}]), len: 513806, time: 15007.822ms, dns req: 0, digest: <0ecb0f65a1407a86243c84f546feba97>, mime_rcpts: <stephane@de-labrusse.fr>, file: stdin, forced: soft reject "Cannot validate the message now. Try again later"; score=nan (set by force_actions)
Feb 7 17:55:19 prometheus rspamd[31990]: <aad1be>; csession; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 2 regexps matched, 184 regexps total, 94 regexps cached, 0B scanned using pcre, 3.82KiB scanned total
Feb 7 17:55:19 prometheus getmail: Filter error (filter Filter_external rspamc-getmail (allow_root_commands="False", arguments="('-i', '127.0.0.1', '--mime', '-t', '120', '-h', 'localhost:11334')", command="rspamc-getmail", exitcodes_drop="('99',)", exitcodes_keep="('0',)", group="_rspamd", ignore_header_shrinkage="False", ignore_stderr="False", path="/usr/bin/rspamc-getmail", unixfrom="False", user="_rspamd") returned 3 ()#012)
cc @davidep
I will continue to test this, but with the updated installed, I have just 2 soft rejects so far this weekend, but both were actually delivered after a 5 minute delay. That is perfect if that is how it is supposed to work now. Here are the logs;
Feb 8 10:25:03 lrtserv-data rspamd[2939]: <07233a>; csession; rspamd_message_parse: loaded message; id: 0.0.B.D6B.1D5DE937034ABDE.0@suitepmta022079.emsmtp.us; queue-id: ; size: 168533; checksum: <2a71f21eb7c2cb1e84a315a4c3a2029c>
Feb 8 10:25:03 lrtserv-data rspamd[2939]: <07233a>; csession; rspamd_mime_part_detect_language: detected part language: en
Feb 8 10:25:03 lrtserv-data rspamd[2939]: <07233a>; csession; rspamd_mime_part_detect_language: detected part language: en
Feb 8 10:25:03 lrtserv-data rspamd[2939]: <07233a>; csession; spf_symbol_callback: skip SPF checks for local networks and authorized users
Feb 8 10:25:03 lrtserv-data rspamd[2939]: <07233a>; csession; dkim_symbol_callback: skip DKIM checks for local networks and authorized users
Feb 8 10:25:03 lrtserv-data rspamd[2939]: <07233a>; lua; dmarc.lua:572: skip DMARC checks for local networks and authorized users
Feb 8 10:25:03 lrtserv-data rspamd[2939]: <07233a>; lua; once_received.lua:98: Skipping once_received for authenticated user or local network
Feb 8 10:25:03 lrtserv-data rspamd[2939]: <07233a>; csession; make_dns_request_task_common: stop resolving on reaching 64 requests
Feb 8 10:25:03 lrtserv-data clamd[3050]: Reading databases from /var/lib/clamav
Feb 8 10:25:18 lrtserv-data rspamd[2939]: <07233a>; lua; clamav.lua:119: clamav: failed to scan, maximum retransmits exceed
Feb 8 10:25:18 lrtserv-data rspamd[2939]: <07233a>; lua; common.lua:107: clamav: result - FAILED with error: “failed to scan and retransmits exceed - score: 0”
Feb 8 10:25:18 lrtserv-data rspamd[2939]: <07233a>; csession; rspamd_add_passthrough_result: 0.0.B.D6B.1D5DE937034ABDE.0@suitepmta022079.emsmtp.us: set pre-result to ‘soft reject’ (no score): ‘Cannot validate the message now. Try again later’ from force_actions(1)
Feb 8 10:25:18 lrtserv-data rspamd[2939]: <07233a>; csession; rspamd_task_write_log: id: 0.0.B.D6B.1D5DE937034ABDE.0@suitepmta022079.emsmtp.us, ip: 127.0.0.1, from: suite11@xpressus.emsmtp.us, (default: F (soft reject): [2.93/15.00] [SUBJECT_HAS_CURRENCY(1.00){},URI_COUNT_ODD(1.00){189;},R_PARTS_DIFFER(0.93){96.5%;},MIME_GOOD(-0.10){multipart/alternative;text/plain;},RCVD_NO_TLS_LAST(0.10){},HAS_LIST_UNSUB(-0.01){},XM_UA_NO_VERSION(0.01){},CLAM_VIRUS_FAIL(0.00){failed to scan and retransmits exceed;},FORCE_ACTION_CLAM_VIRUS_FAIL(0.00){soft reject;},FROM_HAS_DN(0.00){},FROM_NEQ_ENVFROM(0.00){postmaster@enews.cesdeals.com;suite11@xpressus.emsmtp.us;},GENERIC_REPUTATION(0.00){0.80253696185865;},HAS_DATA_URI(0.00){},MIME_TRACE(0.00){0:+;1:+;2:~;},PREVIOUSLY_DELIVERED(0.00){wayne@mydomain.com;},RCPT_COUNT_ONE(0.00){1;},RCVD_COUNT_THREE(0.00){3;},TO_DN_NONE(0.00){}]), len: 168533, time: 15321.156ms, dns req: 64, digest: <2a71f21eb7c2cb1e84a315a4c3a2029c>, mime_rcpts: wayne@mydomain.com, file: stdin, forced: soft reject “Cannot validate the message now. Try again later”; score=nan (set by force_actions)
Feb 8 10:25:18 lrtserv-data rspamd[2939]: <07233a>; csession; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 6 regexps matched, 184 regexps total, 93 regexps cached, 0B scanned using pcre, 183.74KiB scanned total
Feb 8 10:25:18 lrtserv-data getmail: Filter error (filter Filter_external rspamc-getmail (allow_root_commands=“False”, arguments=“(‘-i’, ‘127.0.0.1’, ‘–mime’, ‘-t’, ‘120’, ‘-h’, ‘localhost:11334’)”, command=“rspamc-getmail”, exitcodes_drop=“(‘99’,)”, exitcodes_keep=“(‘0’,)”, group=“_rspamd”, ignore_header_shrinkage=“False”, ignore_stderr=“False”, path=“/usr/bin/rspamc-getmail”, unixfrom=“False”, user=“_rspamd”) returned 3 ()#012)
Feb 8 10:25:18 lrtserv-data getmail: msg 105/105 (170766 bytes) msgid 1580749373/128 from suite11@xpressus.emsmtp.us
Feb 8 10:25:18 lrtserv-data getmail: Filter error (filter Filter_external rspamc-getmail (allow_root_commands=“False”, arguments=“(‘-i’, ‘127.0.0.1’, ‘–mime’, ‘-t’, ‘120’, ‘-h’, ‘localhost:11334’)”, command=“rspamc-getmail”, exitcodes_drop=“(‘99’,)”, exitcodes_keep=“(‘0’,)”, group=“_rspamd”, ignore_header_shrinkage=“False”, ignore_stderr=“False”, path=“/usr/bin/rspamc-getmail”, unixfrom=“False”, user=“_rspamd”) returned 3 ()
Feb 8 10:25:18 lrtserv-data getmail: )
Feb 8 10:25:21 lrtserv-data clamd[3050]: Database correctly reloaded (6905731 signatures)
And, 5 minutes later
Feb 8 10:30:03 lrtserv-data rspamd[2939]: ; csession; rspamd_controller_check_password: allow unauthorized connection from a trusted IP 127.0.0.1
Feb 8 10:30:03 lrtserv-data rspamd[2939]: ; csession; rspamd_message_parse: loaded message; id: 0.0.B.D6B.1D5DE937034ABDE.0@suitepmta022079.emsmtp.us; queue-id: ; size: 168533; checksum: <2a71f21eb7c2cb1e84a315a4c3a2029c>
Feb 8 10:30:03 lrtserv-data rspamd[2939]: ; csession; rspamd_mime_part_detect_language: detected part language: en
Feb 8 10:30:03 lrtserv-data rspamd[2939]: ; csession; rspamd_mime_part_detect_language: detected part language: en
Feb 8 10:30:03 lrtserv-data rspamd[2939]: ; csession; spf_symbol_callback: skip SPF checks for local networks and authorized users
Feb 8 10:30:03 lrtserv-data rspamd[2939]: ; csession; dkim_symbol_callback: skip DKIM checks for local networks and authorized users
Feb 8 10:30:03 lrtserv-data rspamd[2939]: ; lua; dmarc.lua:572: skip DMARC checks for local networks and authorized users
Feb 8 10:30:03 lrtserv-data rspamd[2939]: ; lua; once_received.lua:98: Skipping once_received for authenticated user or local network
Feb 8 10:30:03 lrtserv-data rspamd[2939]: ; csession; make_dns_request_task_common: stop resolving on reaching 64 requests
Feb 8 10:30:03 lrtserv-data rspamd[2939]: ; csession; rspamd_redis_connected: skip obtaining bayes tokens for BAYES_HAM of classifier bayes: not enough learns 114; 200 required
Feb 8 10:30:03 lrtserv-data rspamd[2939]: ; csession; rspamd_stat_classifiers_process: skip statistics as HAM class is missing
Feb 8 10:30:03 lrtserv-data rspamd[2939]: ; csession; rspamd_task_write_log: id: 0.0.B.D6B.1D5DE937034ABDE.0@suitepmta022079.emsmtp.us, ip: 127.0.0.1, from: suite11@xpressus.emsmtp.us, (default: F (no action): [2.93/15.00] [SUBJECT_HAS_CURRENCY(1.00){},URI_COUNT_ODD(1.00){189;},R_PARTS_DIFFER(0.93){96.5%;},MIME_GOOD(-0.10){multipart/alternative;text/plain;},RCVD_NO_TLS_LAST(0.10){},HAS_LIST_UNSUB(-0.01){},XM_UA_NO_VERSION(0.01){},FROM_HAS_DN(0.00){},FROM_NEQ_ENVFROM(0.00){postmaster@enews.cesdeals.com;suite11@xpressus.emsmtp.us;},GENERIC_REPUTATION(0.00){0.80253696185865;},HAS_DATA_URI(0.00){},MIME_TRACE(0.00){0:+;1:+;2:~;},PREVIOUSLY_DELIVERED(0.00){wayne@mydomain.com;},RCPT_COUNT_ONE(0.00){1;},RCVD_COUNT_THREE(0.00){3;},TO_DN_NONE(0.00){}]), len: 168533, time: 461.626ms, dns req: 64, digest: <2a71f21eb7c2cb1e84a315a4c3a2029c>, mime_rcpts: wayne@mydomain.com, file: stdin
Feb 8 10:30:03 lrtserv-data rspamd[2939]: ; csession; rspamd_protocol_http_reply: regexp statistics: 0 pcre regexps scanned, 6 regexps matched, 184 regexps total, 93 regexps cached, 0B scanned using pcre, 183.74KiB scanned total
Feb 8 10:30:05 lrtserv-data dovecot: lda(wayne@mydomain.com): sieve: msgid=0.0.B.D6B.1D5DE937034ABDE.0@suitepmta022079.emsmtp.us: stored mail into mailbox ‘INBOX’
Feb 8 10:30:05 lrtserv-data getmail: msg 105/105 (170766 bytes) msgid 1580749373/128 from suite11@xpressus.emsmtp.us delivered to MDA_external command dovecot-lda ()
This is the new behaviour, if clamd is not available, you soft reject the email but getmail receive an error and download it again
This topic was automatically closed after 6 days. New replies are no longer allowed.