bug report: ClamAV: failed to scan, maximum retransmits exceed

[rhyst]

Preliminary Checks

• I checked that all ports are open and not blocked by my ISP / hosting provider.
• I know that SSL errors are likely the result of a wrong setup on the user side and not caused by DMS itself. I'm confident my setup is correct.
• I searched the issue tracker but was unable to find my issue.
• I read the extended documentation in general but found nothing to resolve the issue.
• I read the documentation on debugging, tried the proposed steps to debug the problem, but was still unable to resolve the issue.
• I have read this project's Code of Conduct and I agree

Affected Component(s)

Rspamd antivirus scanning

What happened and when does this occur?

When an email is recieved I see the error:

ClamAV: failed to scan, maximum retransmits exceed

In the rspamd web ui, on the history page, in the errors section.

What did you expect to happen?

I don't expect to see that error, or I expect to see an error with Clamav somewhere.

How do we replicate the issue?

1. Enable rspamd and clamav using ENABLE_RSPAMD and ENABLE_CLAMAV in the environment vars.
2. Receive an email
   ...

DMS version

v12.1.0

What operating system is DMS running on?

Linux

Which operating system version?

Ubuntu 20.04

What instruction set architecture is DMS running on?

AMD64 / x86_64

What container orchestration tool are you using?

Docker

compose.yaml

# I run via ansible but syntax is very similar to compose
- name: Start mail container
  become: true
  docker_container:
    name: mail
    image: ghcr.io/docker-mailserver/docker-mailserver:12
    hostname: "{{ mail_hostname }}"
    domainname: "{{ mail_domainname }}"
    state: started
    restart: true
    restart_policy: unless-stopped
    volumes:
      - "{{ service_root }}/mail/mail/:/var/mail/"
      - "{{ service_root }}/mail/mail-state/:/var/mail-state/"
      - "{{ service_root }}/mail/mail-logs/:/var/log/mail/"
      - "{{ service_root }}/mail/mail-config/:/tmp/docker-mailserver/"
      # - "{{ service_root }}/mail/mail-config/dovecot/fts-xapian-plugin.conf:/etc/dovecot/conf.d/10-plugin.conf:ro"
      - /etc/letsencrypt:/etc/letsencrypt
    ports:
      - "25:25"
      - "143:143"
      - "465:465"
      - "587:587"
      - "993:993"
      - "995:995"
      - "4190:4190"
      - "11334:11334"
    cpus: 1
    capabilities:
      - NET_ADMIN
      - SYS_PTRACE
    env: "{{ default_mail_env_yaml | combine(mail_env_yaml) }}"
    container_default_behavior: no_defaults

Relevant log output

Startup logs on debug:

UG  ]  Logwatch reports disabled.
[  DEBUG  ]  Consolidating all state onto /var/mail-state
[  DEBUG  ]  Checking /var/mail permissions
[  DEBUG  ]  Removing files and directories from older versions
[  DEBUG  ]  Exporting environment variables now (creating '/etc/dms-settings')
[  DEBUG  ]  Setting up configuration checksum file
[  DEBUG  ]  Printing environment variables. Make sure no sensitive data is copied.
ACCOUNT_PROVISIONER='FILE'
AMAVIS_LOGLEVEL='0'
CLAMAV_MESSAGE_SIZE_LIMIT='25M'
DEFAULT_RELAY_HOST=''
DOVECOT_INET_PROTOCOLS='all'
DOVECOT_MAILBOX_FORMAT='maildir'
DOVECOT_TLS='no'
ENABLE_AMAVIS='0'
ENABLE_CLAMAV='1'
ENABLE_DNSBL='0'
ENABLE_FAIL2BAN='1'
ENABLE_FETCHMAIL='1'
ENABLE_MANAGESIEVE='1'
ENABLE_OPENDKIM='0'
ENABLE_OPENDMARC='0'
ENABLE_POLICYD_SPF='0'
ENABLE_POP3='0'
ENABLE_POSTGREY='0'
ENABLE_QUOTAS='0'
ENABLE_RSPAMD='1'
ENABLE_RSPAMD_REDIS='1'
ENABLE_SASLAUTHD='0'
ENABLE_SPAMASSASSIN='0'
ENABLE_SPAMASSASSIN_KAM='0'
ENABLE_SRS='0'
ENABLE_UPDATE_CHECK='1'
FAIL2BAN_BLOCKTYPE='drop'
FETCHMAIL_PARALLEL='0'
FETCHMAIL_POLL='60'
LOGROTATE_INTERVAL='weekly'
LOGWATCH_INTERVAL='none'
LOGWATCH_RECIPIENT='postmaster@mydomain.tld'
LOGWATCH_SENDER='mailserver-report@mail.mydomain.tld'
LOG_LEVEL='debug'
MOVE_SPAM_TO_JUNK='1'
NETWORK_INTERFACE='eth0'
ONE_DIR='1'
OVERRIDE_HOSTNAME=''
PERMIT_DOCKER='network'
PFLOGSUMM_RECIPIENT='postmaster@mydomain.tld'
PFLOGSUMM_SENDER='mailserver-report@mail.mydomain.tld'
PFLOGSUMM_TRIGGER='none'
POSTFIX_DAGENT=''
POSTFIX_INET_PROTOCOLS='all'
POSTFIX_MAILBOX_SIZE_LIMIT='0'
POSTFIX_MESSAGE_SIZE_LIMIT='102400000'
POSTFIX_REJECT_UNKNOWN_CLIENT_HOSTNAME='0'
POSTGREY_AUTO_WHITELIST_CLIENTS='5'
POSTGREY_DELAY='300'
POSTGREY_MAX_AGE='35'
POSTGREY_TEXT='Delayed by Postgrey'
POSTMASTER_ADDRESS='postmaster@mydomain.tld'
POSTSCREEN_ACTION='enforce'
RELAY_HOST=''
REPORT_RECIPIENT='postmaster@mydomain.tld'
REPORT_SENDER='mailserver-report@mail.mydomain.tld'
RSPAMD_GREYLISTING='0'
RSPAMD_HFILTER='1'
RSPAMD_HFILTER_HOSTNAME_UNKNOWN_SCORE='6'
RSPAMD_LEARN='1'
SA_KILL='6.31'
SA_SPAM_SUBJECT='***SPAM*****'
SA_TAG2='6.31'
SA_TAG='2.0'
SMTP_ONLY='0'
SPAMASSASSIN_SPAM_TO_INBOX='1'
SPOOF_PROTECTION='0'
SRS_DOMAINNAME='mydomain.tld'
SRS_EXCLUDE_DOMAINS=''
SRS_SECRET=''
SRS_SENDER_CLASSES='envelope_sender'
SSL_TYPE='letsencrypt'
SUPERVISOR_LOGLEVEL='warn'
TLS_LEVEL='intermediate'
TZ=''
UPDATE_CHECK_INTERVAL='1d'
VIRUSMAILS_DELETE_DELAY='7'
[  DEBUG  ]  Applying user patches
[   INF   ]  Starting daemons
[  DEBUG  ]  Starting cron
[  DEBUG  ]  Starting rsyslog
[  DEBUG  ]  Starting dovecot
[  DEBUG  ]  Starting update-check
[  DEBUG  ]  Starting rspamd-redis
[  DEBUG  ]  Starting rspamd
[  DEBUG  ]  Starting postfix
[  DEBUG  ]  Starting fail2ban
[  DEBUG  ]  Starting fetchmail
[  DEBUG  ]  Starting clamav
[  DEBUG  ]  Starting changedetector
[   INF   ]  mail.mydomain.tld is up and running

Log from recieving an email:

May 10 12:51:16 mail postfix/postscreen[1696]: CONNECT from [20.93.246.55]:48178 to [172.17.0.16]:25
May 10 12:51:16 mail postfix/postscreen[1696]: PASS OLD [20.93.246.55]:48178
May 10 12:51:17 mail postfix/smtpd[1697]: connect from mecsa.dcslab.eu[20.93.246.55]
May 10 12:51:17 mail postfix/smtpd[1697]: Anonymous TLS connection established from mecsa.dcslab.eu[20.93.246.55]: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits) server-digest SHA256
May 10 12:51:17 mail postfix/smtpd[1697]: 2DACE9CFC6: client=mecsa.dcslab.eu[20.93.246.55]
May 10 12:51:17 mail postfix/cleanup[1705]: 2DACE9CFC6: message-id=<20230510125116.C674E3F3B1@mecsa.dcslab.eu>
May 10 12:51:17 mail postfix/qmgr[863]: 2DACE9CFC6: from=<ranker@mecsa.dcslab.eu>, size=2030, nrcpt=1 (queue active)
May 10 12:51:17 mail postfix/smtpd[1697]: disconnect from mecsa.dcslab.eu[20.93.246.55] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
May 10 12:51:17 mail dovecot: lmtp(1708): Connect from local
May 10 12:51:17 mail dovecot: lmtp(rhys@mail)<1708><Nmn4N0WTW2SsBgAAn/CpQg>: sieve: msgid=<20230510125116.C674E3F3B1@mecsa.dcslab.eu>: stored mail into mailbox 'INBOX'
May 10 12:51:17 mail dovecot: lmtp(1708): Disconnect from local: Logged out (state=READY)
May 10 12:51:17 mail postfix/lmtp[1707]: 2DACE9CFC6: to=<rhys@mail>, orig_to=<mail@mydomain.tld>, relay=mail.mydomain.tld[/var/run/dovecot/lmtp], delay=0.79, delays=0.73/0.02/0.01/0.02, dsn=2.0.0, status=sent (250 2.0.0 <rhys@mail> Nmn4N0WTW2SsBgAAn/CpQg Saved)
May 10 12:51:17 mail postfix/qmgr[863]: 2DACE9CFC6: removed
May 10 12:51:21 mail postfix/postscreen[1696]: CONNECT from [95.214.27.139]:63603 to [172.17.0.16]:25
May 10 12:51:21 mail postfix/postscreen[1696]: PREGREET 11 after 0.02 from [95.214.27.139]:63603: EHLO User\r\n
May 10 12:51:21 mail postfix/postscreen[1696]: DISCONNECT [95.214.27.139]:63603

Other relevant information

It looks like clamav is running:

❯ ps aux | grep clam
200      1698399  5.1 16.4 1546824 1310620 ?     Sl   12:44   0:25 /usr/sbin/clamd -c /etc/clamav/clamd.conf
me       1702443  0.0  0.0   6432  2528 pts/0    R+   12:52   0:00 grep --color=auto clam

But I don't see any errors anywhere else.

I actually don't know for sure if this worked for sure with spamassassin as I am not sure where the errors would surface there. I am unsure how to debug further.

Thank you for any help

What level of experience do you have with Docker and mail servers?

• I am inexperienced with docker
• I am rather experienced with docker
• I am inexperienced with mail servers
• I am rather experienced with mail servers
• I am uncomfortable with the CLI
• I am rather comfortable with the CLI

Improvements to this form?

No response

[georglauterbach]

I think I had seen this in my Rspamd log as well, but as I didn't see it anywhere else, I was not investigating further. I will have a look though.

[georglauterbach]

Probably related to Mailu/Mailu#2321 and https://community.mailcow.email/d/1940-clamav-failed-to-scan-maximum-retransmits-exceed. Should be a non-issue when it comes to actually receiving e-mails. They just wont be scanned by Clam.

[georglauterbach]

Adding

    timeout = 10;
    retransmits = 2;

to local.d/antivirus.conf (inside the ClamAV { ... } block) now and monitoring logs. Looking at the source

https://github.com/rspamd/rspamd/blob/9c6373baf65808a50c7ba0163e8b00c0b8fda6b6/lualib/lua_scanners/clamav.lua#L34-L45

these seem to be valid settings, even though they are poorly documented. @rhyst could you please also try them? You could set the settings in override.d or adjust them manually in local.d.

[rhyst]

I have created override.d/antivirus.conf:

enabled = true;

ClamAV {
    type = "clamav";
    servers = "/var/run/clamav/clamd.ctl";
    action = "reject";
    message = '${SCANNER} FOUND VIRUS "${VIRUS}"';
    scan_mime_parts = false;
    symbol = "CLAM_VIRUS";
    log_clean = true;
    timeout = 10;
    retransmits = 2;
}

And the error is maybe no longer appearing (have recieved a few emails). Will keep an eye on it.

Is there a way to confirm that rspamd is actually running clamav?

[polarathene]

But I don't see any errors anywhere else.

I actually don't know for sure if this worked for sure with spamassassin as I am not sure where the errors would surface there. I am unsure how to debug further.

If any mail is sent locally to a system user like clamav or root, they'll get delivered in /var/mail into a mailbox file. If the mail was sent to a non-system user but still to a local account (eg: @localhost or @mail.example.com), a lookup is still done in /etc/aliases such as for postmaster user. If one exists it'll be delivered to where the alias directs the mail, otherwise it should be rejected by Postfix.

It's common for cron jobs run as Amavis (which includes for SpamAssassin IIRC) to not have an alias configured, thus they arrive at /var/mail/amavis. You may want to check for unexpected mail there (it's a text file, so you can just open or cat it).

[georglauterbach]

Is there a way to confirm that rspamd is actually running clamav?

It is noted in the Rspamd log at /var/log/supervisor/rspamd.log. When you grep for "antivirus" with grep antivirus rspamd.log, you should see that Rspamd has chosen ClamAV. We also employ a test that checks this condition; and we check whether test mails that are made for testing anti-virus scanners' integration are rejected by ClamAV as well :)

---

I will provide a PR for this, but we'll wait a bit to make sure the error really is gone.

[georglauterbach]

@rhyst have you been seeing the issue ever since you adjusted antivirus.conf?

[rhyst]

I have not seen the error again, so it seems to be an effective fix for me

[georglauterbach]

Alright, thanks for the feedback. I merged #3331 which will bring this addition to :edge now and later into v13.0.0.

If the issue re-appears, please ping me :)