Hello,
I have very strange issue. Sieve generate copies of users messages i.e.
not real copies but hardlinks for the same message. It happens to many
messages but not every message and not every time, it is not a single
user issue I have couple users with that issue.
It happens during auto reporting for spam/ham with sieve.
But I'm unable to reproduce it.
At some point the hardlinks copies become so many that the mailbox index
files become so bug that dovecot start throwing error:
################################
dovecot[3385911]: imap(redac...@domain.tld)<1992901><RRBL9PQX69IXfCSs>:
Error: Mailbox Junk: mmap(size=520636784) failed with file
/var/lib/dovecot-virtualmin/index/redac...@domain.tld/.Junk/dovecot.index.cache: Cannot allocate memory
################################
other relevant logs are:
dovecot: imap-login: Login: user=<redacted.user>, method=PLAIN,
rip=YYY.YYY.YYY.YYY, lip=XXX.XXX.XXX.XXX, mpid=3393763, TLS,
session=<c1Z1lPsZuPCAWqqI>
dovecot: imap(redacted.user)<3393763><c1Z1lPsZuPCAWqqI>: sieve: DEBUG:
learn-spam.sieve was triggered on imap.cause=COPY:
msgid=<87584056G78841203D85243127W62181551P@idomziqnd>
dovecot: imap(redacted.user)<3393763><c1Z1lPsZuPCAWqqI>: sieve: DEBUG:
learn-spam on imap.cause=COPY: from=redacted.mail, to=redacted2.mail,
subject=Asseyez-vous confortablement, n'importe où...,
msgid=<87584056G78841203D85243127W62181551P@idomziqnd>,
X-Spamd-Result=default: False [4.49 / 15.00];
FORGED_RECIPIENTS(2.00)[m:redacted2.mail,s:redacted.user.fr];
BAYES_SPAM(1.89)[88.30%]; MID_RHS_NOT_FQDN(0.50)[];
BAD_REP_POLICIES(0.10)[]; RCVD_NO_TLS_LAST(0.10)[];
MIME_GOOD(-0.10)[multipart/related,multipart/alternative,text/plain];
ASN(0.00)[asn:34300, ipnet:62.173.128.0/19, country:RU];
RCVD_COUNT_ONE(0.00)[1]; MIME_TRACE(0.00)[0:+,1:+,2:+,3:~,4:~,5:+];
RCPT_COUNT_ONE(0.00)[1]; MISSING_XM_UA(0.00)[]; ARC_NA(0.00)[];
RCVD_VIA_SMTP_AUTH(0.00)[]; GREYLIST(0.00)[pass,body];
R_DKIM_NA(0.00)[]; FROM_EQ_ENVFROM(0.00)[]; FROM_HAS_DN(0.00)[];
R_SPF_ALLOW(0.00)[+mx]; TO_DN_NONE(0.00)[]; DMARC_NA(0.00)[or.mg];
NEURAL_SPAM(0.00)[0.000]
dovecot: imap(redacted.user)<3393763><c1Z1lPsZuPCAWqqI>: sieve: DEBUG:
learn-spam send to rspamd spam
dovecot: imap(redacted.user)<3393763><c1Z1lPsZuPCAWqqI>: program
exec:/var/lib/dovecot/sieve/rspamd-learn-spam.sh (3397238): Terminated
with non-zero exit code 1
dovecot: imap(redacted.user)<3393763><c1Z1lPsZuPCAWqqI>: Error: sieve:
failed to execute to program `rspamd-learn-spam.sh': refer to server log
for more information. [2024-06-03 07:36:40]
dovecot: imap(redacted.user)<3393763><c1Z1lPsZuPCAWqqI>: Disconnected:
Connection closed (UID FETCH finished 32.173 secs ago) in=2914 out=39237
deleted=1 expunged=1 trashed=0 hdr_count=14 hdr_bytes=10705 body_count=1
body_bytes=1606
I know that this is because the mail which is reported is too big for
curl but documentation say that
$$$$$$$$$$$$$$$$$
pipe :copy :try "rspamd-learn-spam.sh";
$$$$$$$$$$$$$$$$$
this should ignore the error.
I have tested also to change it like that:
$$$$$$$$$$$$$$$$$
pipe :copy "rspamd-learn-spam.sh";
$$$$$$$$$$$$$$$$$
but the issue still persists
I can't confirm that the issue is that error because these errors are
way less than the messages with hardlink copies.
Also sometimes one mail have more than two hardlinks to it.
########################################
here is a example:
inode# hardlink_count filename
2430090371 23850
./Maildir/.Trash/cur/1714190559.M355157P25776.redacted.hostname,S=39259,W=40217:2,S
2430090371 23850
./Maildir/.Trash/cur/1714190562.M259778P25902.redacted.hostname,S=39259,W=40217:2,S
2430090371 23850
./Maildir/.Trash/cur/1714190565.M188090P26028.redacted.hostname,S=39259,W=40217:2,S
2430090371 23850
./Maildir/.Trash/cur/1714190568.M340582P26179.redacted.hostname,S=39259,W=40217:2,S
yes this is "23850" hardlinks to the same Inode
#######################################
The issue is somewhere in the sieve ham/spam reporting to rspamd but
cant figure out where and why.
Is this a bug or my configuration is wrong?
Here are all related configurations (feel free to ask for more if needed):
######################################################################
# doveconf -n
# 2.3.16 (7e2e900c1a): /etc/dovecot/dovecot.conf
# Pigeonhole version 0.5.16 (09c29328)
# OS: Linux 4.18.0-513.24.1.el8_9.x86_64 x86_64 Rocky Linux release 8.9
(Green Obsidian)
# Hostname: redacteddomain.tld
auth_mechanisms = plain login
disable_plaintext_auth = no
first_valid_uid = 1000
mail_location =
maildir:~/Maildir:INDEX=/var/lib/dovecot-virtualmin/index/%u:CONTROL=/var/lib/dovecot-virtualmin/control/%u
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope
encoded-character vacation subaddress comparator-i;ascii-numeric
relational regex imap4flags copy include variables body enotify
environment mailbox date index ihave duplicate mime
foreverypart extracttext vacation-seconds imapsieve vnd.dovecot.imapsieve
mbox_write_locks = fcntl
namespace inbox {
inbox = yes
location =
mailbox Drafts {
auto = subscribe
special_use = \Drafts
}
mailbox Junk {
auto = create
special_use = \Junk
}
mailbox Sent {
auto = subscribe
special_use = \Sent
}
mailbox "Sent Messages" {
special_use = \Sent
}
mailbox Trash {
auto = subscribe
special_use = \Trash
}
mailbox spam {
auto = subscribe
special_use = \Junk
}
prefix =
}
passdb {
driver = pam
}
plugin {
imapsieve_mailbox1_before = file:/var/lib/dovecot/sieve/learn-spam.sieve
imapsieve_mailbox1_causes = COPY
imapsieve_mailbox1_name = spam
imapsieve_mailbox2_before = file:/var/lib/dovecot/sieve/learn-ham.sieve
imapsieve_mailbox2_causes = COPY
imapsieve_mailbox2_from = spam
imapsieve_mailbox2_name = *
imapsieve_mailbox3_before = file:/var/lib/dovecot/sieve/learn-spam.sieve
imapsieve_mailbox3_causes = COPY
imapsieve_mailbox3_name = Junk
imapsieve_mailbox4_before = file:/var/lib/dovecot/sieve/learn-ham.sieve
imapsieve_mailbox4_causes = COPY
imapsieve_mailbox4_from = Junk
imapsieve_mailbox4_name = *
quota = fs:user userquota
quota2 = fs:group groupquota
quota_grace = 100M
quota_warning = storage=95%% quota-warning 95 %n %d
quota_warning2 = storage=90%% quota-warning 90 %n %d
quota_warning3 = storage=80%% quota-warning 80 %n %d
sieve = file:~/sieve;active=~/.dovecot.sieve
sieve_before = /var/lib/dovecot/sieve/before-global.sieve
sieve_extensions = +vacation-seconds
sieve_global_extensions = +vnd.dovecot.pipe +vnd.dovecot.environment
+vnd.dovecot.debug
sieve_pipe_bin_dir = /var/lib/dovecot/sieve
sieve_plugins = sieve_extprograms sieve_imapsieve
sieve_vacation_default_period = 10d
sieve_vacation_max_period = 30d
sieve_vacation_min_period = 1h
}
protocols = imap pop3 lmtp sieve
process_min_avail = 5
service_count = 0
}
service imap {
process_limit = 400
}
service lmtp {
unix_listener /var/spool/postfix/private/dovecot-lmtp {
group = postfix
mode = 01224
user = postfix
}
}
service pop3 {
process_limit = 200
}
service quota-warning {
executable = script /var/lib/dovecot/quota-warning.sh
service_count = 1
unix_listener quota-warning {
group = dovecot
mode = 0666
user = dovecot
}
}
ssl_ca = </etc/pki/dovecot/certs/ca.pem
ssl_cert = </etc/pki/dovecot/certs/dovecot.pem
ssl_cipher_list =
ECDHE-RSA-AES256-SHA384:AES256-SHA256:AES256-SHA256:!RC4:HIGH:MEDIUM:+TLSv1:+TLSv1.1:+TLSv1.2:!MD5:!ADH:!aNULL:!eNULL:!NULL:!DH:!ADH:!EDH:!AESGCM
ssl_key = # hidden, use -P to show it
userdb {
driver = passwd
}
protocol lmtp {
mail_plugins = " sieve"
userdb {
args = username_format=%n /etc/passwd
driver = passwd-file
name =
}
}
protocol imap {
mail_plugins = " imap_quota imap_sieve quota"
}
######################################################################
# cat /var/lib/dovecot/sieve/learn-spam.sieve
require ["vnd.dovecot.pipe", "copy", "imapsieve", "environment",
"imap4flags", "vnd.dovecot.debug", "variables"];
# Logging
if address :matches "from" "*" { set "FROM" "${1}"; }
if address :matches "to" "*" { set "TO" "${1}"; }
if header :matches "subject" "*" { set "SUBJECT" "${1}"; }
if header :matches "Message-ID" "*" { set "MSGID" "${1}"; }
if header :matches "X-Spamd-Result" "*" { set "XSpamdResult" "${1}"; }
if environment :matches "imap.cause" "*" { set "IMAPCAUSE" "${1}"; }
debug_log "learn-spam.sieve was triggered on imap.cause=${IMAPCAUSE}:
msgid=${MSGID}";
set "LogMsg" "learn-spam on imap.cause=${IMAPCAUSE}: from=${FROM},
to=${TO}, subject=${SUBJECT}, msgid=${MSGID},
X-Spamd-Result=${XSpamdResult}";
# Spam-learning by sending copy with curl to rspmd
if anyof (environment :is "imap.cause" "COPY", environment :is
"imap.cause" "APPEND") {
debug_log "${LogMsg}";
debug_log "learn-spam send to rspamd spam";
pipe :copy :try "rspamd-learn-spam.sh";
}
# Catch replied or forwarded spam and send to rspamd ham
elsif anyof (allof (hasflag "\\Answered", environment :contains
"imap.changedflags" "\\Answered"),
allof (hasflag "$Forwarded", environment :contains
"imap.changedflags" "$Forwarded")) {
debug_log "${LogMsg}";
debug_log "learn-spam send to rspamd ham";
pipe :copy :try "rspamd-learn-ham.sh";
}
######################################################################
cat /var/lib/dovecot/sieve/learn-ham.sieve
require ["vnd.dovecot.pipe", "copy", "imapsieve", "environment",
"variables", "vnd.dovecot.debug"];
# Exclude messages which were moved to Trash (or training mailboxes)
from ham learning
if environment :matches "imap.mailbox" "*" {
set "mailbox" "${1}";
}
if string "${mailbox}" [ "INBOX/Trash", "INBOX/Deleted Items",
"INBOX/Bin", "INBOX/train_ham", "INBOX/train_prob", "INBOX/train_spam",
"Trash" ] {
stop;
}
# Logging
if address :matches "from" "*" { set "FROM" "${1}"; }
if address :matches "to" "*" { set "TO" "${1}"; }
if header :matches "subject" "*" { set "SUBJECT" "${1}"; }
if header :matches "Message-ID" "*" { set "MSGID" "${1}"; }
if header :matches "X-Spamd-Result" "*" { set "XSpamdResult" "${1}"; }
if environment :matches "imap.cause" "*" { set "IMAPCAUSE" "${1}"; }
debug_log "learn-ham on imap.cause=${IMAPCAUSE}: from=${FROM}, to=${TO},
subject=${SUBJECT}, msgid=${MSGID}, X-Spamd-Result=${XSpamdResult}";
# Ham-learning sending a copy of the message to rspamd
debug_log "learn-ham send to rspamd ham";
pipe :copy :try "rspamd-learn-ham.sh";
######################################################################
cat /var/lib/dovecot/sieve/rspamd-learn-ham.sh
#!/bin/bash
function log_error() { echo `date '+%Y-%m-%d %H:%M:%S'` ERROR: $1 >&2; }
function log() { echo `date '+%Y-%m-%d %H:%M:%S'` INFO: $1; }
MAIL=$(tee)
SERVER_LIST=("redacted.tld") #rspamd server
PASSWORD="redacted"
for SERVER in ${SERVER_LIST[@]}; do
log "Trying to report spam to ${SERVER}"
RETURN=$(/usr/bin/curl -s --connect-timeout 1 -H "Password:
${PASSWORD}" --data-binary --url "http://${SERVER}:11334/learnham"; -d
"${MAIL}")
STATUS=$?
if [ $STATUS -eq 0 ]; then
log "Spam reported to ${SERVER}: ${RETURN}"
exit 0
else
if [ $STATUS -eq 28 ]; then
log_error "Reporting SPAM to ${SERVER} failed: Connection
timed out."
else
log_error "Reporting SPAM to ${SERVER} failed: CURL exit
status ${STATUS}"
fi
fi
done
log_error "Reporting SPAM failed ${SERVERS[@]}"
exit 1
######################################################################
cat /var/lib/dovecot/sieve/rspamd-learn-spam.sh
#!/bin/bash
function log_error() { echo `date '+%Y-%m-%d %H:%M:%S'` ERROR: $1 >&2; }
function log() { echo `date '+%Y-%m-%d %H:%M:%S'` INFO: $1; }
MAIL=$(tee)
SERVER_LIST=("redacted.tld") #rspamd server
PASSWORD="redacted"
for SERVER in ${SERVER_LIST[@]}; do
log "Trying to report spam to ${SERVER}"
RETURN=$(/usr/bin/curl -s --connect-timeout 1 -H "Password:
${PASSWORD}" --data-binary --url "http://${SERVER}:11334/learnspam"; -d
"${MAIL}")
STATUS=$?
if [ $STATUS -eq 0 ]; then
log "Spam reported to ${SERVER}: ${RETURN}"
exit 0
else
if [ $STATUS -eq 28 ]; then
log_error "Reporting SPAM to ${SERVER} failed: Connection
timed out."
else
log_error "Reporting SPAM to ${SERVER} failed: CURL exit
status ${STATUS}"
fi
fi
done
log_error "Reporting SPAM failed ${SERVERS[@]}"
exit 1
######################################################################
without all "imapsieve_mailbox.* " directives the problem is gone.
Thanks to everyone in advance.
