Hi John,
Thanks for taking your time looking at my issue.
On 13-Jun-24 3:42 PM, John Stoffel via dovecot wrote:
"George" == George Asenov via dovecot dovecot@dovecot.org writes:
I don't have a real suggestion, but I do think you can clarify your problem.
No one have idea what is wrong here? On 07-Jun-24 4:10 PM, George Asenov via dovecot wrote:
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.
Are you expecting sieve to generate copies? And are the copies in the same folder or across folders? I.e. do you find an email in the INBOX, and a hardlink in the SPAM folder?
The goal here is when user move messages around imap folders to report them as ham/spam depending on where they originate and where they go. I think Sieve should send copy of the message to Rspamd because otherwise client will see the message dispensary which is not intuitive.
Copies are all in the same folder. same message with many hard links placed in the same folder. Mostly happen in Trash and Spam folders.
What are the sizes of these emails? Are they all large? Or have attachements? Is there anything that's common amongst those emails? Nothing in common as far as I can see. Sizes are verry different mostly small.
One idea might be to setup a test account and to just send it a bunch of emails to try and make the problem occur. And to also look closely at the rspamd logs as well.
Already done that but I'm unable to reproduce it.
What is the size of the system memory on your dovecot server? And what is the size of the dovecot.index.cache file when you see this error? You should be able to delete the index and recreate it using doveadm.
Servers are with enough RAM the smallest one is 64GB. The memory I'm referring is "vsz_limit=256 MB" and in my opinion it is not the issue but a consequence of the large amount of links in the mail and from there large index file and the result not enough memory to work with. When I delete all the copies the "Out of memory" errors are gone.
But from the sound of it, you have users with many thousands of emails in a folder or folders. Can you check to see if there's any relationship between users with larger numbers of hardlinks and those with large numbers of emails?
There are users with large number of mails but only some of them have this issue and some don't. Also there are users with small amount that have it which make them with large number of mails(copies).
And maybe instead of having sieve call rspam, maybe you can put it into a milter and just have the
Rspamd is on a different server and it is set as a milter in postfix. That is why I use curl to report spam/ham.
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(redacted@domain.tld)<1992901><RRBL9PQX69IXfCSs>: Error: Mailbox Junk: mmap(size=520636784) failed with file /var/lib/dovecot-virtualmin/index/redacted@domain.tld/.Junk/dovecot.index.cache: Cannot allocate memory ################################ other relevant logs are:
dovecot: imap-login: Login: 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
Wait, how large is this email you're trying to process? So once you have rspamd-learn-spam.sh crash on you, then you are really having an rspam problem. Do you really need to scan large attachements?
The "crash" is an error from curl because the mail is too big to send it inline as I pipe it,
What is your rspam configuration? And have you talked to people on the rspamd mailing list on how to configure things?
Rspamd is on a diffrent machine and I think it is not to blame here.
$$$$$$$$$$$$$$$$$ 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
So why are you doing a :copy here? If you're trying to say this email is spam, why not just move it to your spam folder, and then have rspamd go through your junk folder once a day instead?
Because this should be kind of invisible to users. They move mails between folders and in the background they report as spam/ham
Have you looked at the system logs for memory problems when these hardlink files are created? Are you running out of memory on general on this mail server?
No memory problems on the machine itself there is plenty of free Ram
Instead of focusing on dovecot, back up a level and think about the resources allocated to the whole system, and what types of mail messages are showing this problem. How are they alike? What is your mail volume? Does the problem happen when you get lots of emails, or is it really random?
It is not the amount of messages coming if I comment out the config executing spam/ham reporting and clean up the hardlinks the issue didn't show up for months.
Do you have old rspamd processes hanging around taking up resources? Rspamd can't make copies on that machine because it is on a separate server.
Good luck! John
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 =
######################################################################
# 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() { echodate '+%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() { echodate '+%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.
-- Warm regards George A. WPXHosting
dovecot mailing list -- dovecot@dovecot.org To unsubscribe send an email to dovecot-leave@dovecot.org
dovecot mailing list -- dovecot@dovecot.org To unsubscribe send an email to dovecot-leave@dovecot.org
-- Warm regards George A.