failed to pipe to program sa-learn-spam.sh

[@lbutlr]

On Jun 4, 2019, at 1:43 PM, Stephan Bosch via dovecot <dovecot at dovecot.org> wrote:
> Op 30-5-2019 om 9:46 schreef @lbutlr via dovecot:
>> Error: program `/usr/lib/dovecot/sieve/sa-learn-spam.sh' terminated abnormally, signal 11
>> Error: sieve: pipe action: failed to pipe message to program `sa-learn-spam.sh': refer to server log for more information. [2019-05-29 17:59:12]
>> 
>> What server log? This is all that get logged.
> 
> Output from dovecot -n is needed to answer this one. Does it crash when you invoke sa-learn-spam.sh manually from shell?

The last time this happened (march 2018) it filled up the mailq when someone dumped thousands of messages into Junk and after letting that clear and restarting dovecot, it started to work again. I was hoping for something similar since th configuration has not changed.

Invoking from the shell:

 # /usr/lib/dovecot/sieve/sa-learn-spam.sh
SpamAssassin version 3.4.2
Please select either --spam, --ham, --folders, --forget, --sync, --import,
--dump, --clear, --backup or —restore

Mail debug output:
Jun 06 04:43:24 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: Mailbox Junk: Mailbox opened because: UID COPY
Jun 06 04:43:24 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: Mailbox INBOX: UID 17605: Opened mail because: copying
Jun 06 04:43:24 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: imapsieve: mailbox Junk: COPY event
Jun 06 04:43:24 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: imapsieve: Matched static mailbox rule [1]
Jun 06 04:43:24 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: sieve: file storage: Using Sieve script path: /usr/lib/dovecot/sieve/report-spam.sieve
Jun 06 04:43:24 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: sieve: file script: Opened script `report-spam' from `/usr/lib/dovecot/sieve/report-spam.sieve'
Jun 06 04:43:24 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: sieve: Opening script 1 of 1 from `/usr/lib/dovecot/sieve/report-spam.sieve'
Jun 06 04:43:24 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: sieve: Loading script /usr/lib/dovecot/sieve/report-spam.sieve
Jun 06 04:43:24 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: sieve: Script binary /usr/lib/dovecot/sieve/report-spam.svbin successfully loaded
Jun 06 04:43:24 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: sieve: binary save: not saving binary /usr/lib/dovecot/sieve/report-spam.svbin, because it is already stored
Jun 06 04:43:24 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: sieve: Executing script from `/usr/lib/dovecot/sieve/report-spam.svbin'
Jun 06 04:43:24 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: sieve: action pipe: running program: sa-learn-spam.sh
Jun 06 04:43:24 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: Mailbox Junk: UID 303742: Opened mail because: mail stream
Jun 06 04:43:24 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: waiting for program `/usr/lib/dovecot/sieve/sa-learn-spam.sh' to finish after 0 msecs
Jun 06 04:43:25 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Error: program `/usr/lib/dovecot/sieve/sa-learn-spam.sh' terminated abnormally, signal 11
Jun 06 04:43:25 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Error: sieve: pipe action: failed to pipe message to program `sa-learn-spam.sh': refer to server log for more information. [2019-06-06 04:43:25]
Jun 06 04:43:25 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Info: sieve: left message in mailbox 'Junk'
Jun 06 04:43:25 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Error: sieve: Execution of script /usr/lib/dovecot/sieve/report-spam.sieve failed
Jun 06 04:43:26 imap(kreme)<87686><Dq6MXaWKcMdJDqGg>: Debug: imapsieve: mailbox Junk: FLAG event (changed flags: $Junk Junk)
Jun 06 04:43:26 imap(kreme)<87686><Dq6MXaWKcMdJDqGg>: Debug: imapsieve: mailbox Junk: FLAG event (changed flags: $NotJunk NotJunk)
Jun 06 04:43:26 imap(kreme)<86722><7vCHXaWKa8dJDqGg>: Debug: imapsieve: mailbox INBOX: FLAG event (changed flags: \Deleted)


I included the relevant lines from doveconf -n in the original post, but here is the whole thing.


# 2.3.6 (7eab80676): /usr/local/etc/dovecot/dovecot.conf
# Pigeonhole version 0.5.6 (92dc263a)
# OS: FreeBSD 11.2-RELEASE-p10 i386  
# Hostname: mail.covisp.net
auth_failure_delay = 5 secs
auth_mechanisms = PLAIN LOGIN
default_client_limit = 4096
default_process_limit = 1024
default_vsz_limit = 768 M
disable_plaintext_auth = no
first_valid_uid = 89
imap_id_log = *
lda_mailbox_autocreate = yes
lda_mailbox_autosubscribe = yes
login_log_format_elements = user=<%u> %r %m %c
mail_location = maildir:~/Maildir
mail_max_userip_connections = 90
mail_plugins = " lazy_expunge acl"
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 ihave
namespace inbox {
  inbox = yes
  location = 
  mailbox Archive {
    auto = subscribe
    special_use = \Archive
  }
  mailbox Drafts {
    special_use = \Drafts
  }
  mailbox Junk {
    auto = subscribe
    special_use = \Junk
  }
  mailbox Sent {
    special_use = \Sent
  }
  mailbox Trash {
    special_use = \Trash
  }
  prefix = 
}
passdb {
  driver = pam
  username_filter = !*@*
}
passdb {
  args = /usr/local/etc/dovecot/dovecot-sql.conf.ext
  driver = sql
}
plugin {
  imapsieve_mailbox1_before = file:/usr/lib/dovecot/sieve/report-spam.sieve
  imapsieve_mailbox1_causes = COPY
  imapsieve_mailbox1_name = Junk
  imapsieve_mailbox2_before = file:/usr/lib/dovecot/sieve/report-ham.sieve
  imapsieve_mailbox2_causes = COPY
  imapsieve_mailbox2_from = Junk
  imapsieve_mailbox2_name = *
  imapsieve_mailbox3_before = file:/usr/lib/dovecot/sieve/mark-read.sieve
  imapsieve_mailbox3_causes = COPY
  imapsieve_mailbox3_name = Archive
  quota_rule2 = .EXPUNGED:ignore
  sieve = file:~/.sieve;active=~/.active_sieve
  sieve_default = /usr/lib/dovecot/sieve/default.sieve
  sieve_default_name = spamassassin
  sieve_global_extensions = +vnd.dovecot.pipe +vnd.dovecot.environment
  sieve_pipe_bin_dir = /usr/lib/dovecot/sieve
  sieve_plugins = sieve_imapsieve sieve_extprograms
}
protocols = imap pop3
service auth {
  unix_listener /var/spool/postfix/private/auth {
    mode = 0666
  }
}
service imap-login {
  inet_listener imaps {
    port = 993
    ssl = yes
  }
}
service pop3-login {
  inet_listener pop3 {
    port = 0
  }
  inet_listener pop3s {
    port = 995
    ssl = yes
  }
}
service stats {
  unix_listener stats-reader {
    group = dovecot
    mode = 0666
    user = 
  }
  unix_listener stats-writer {
    group = dovecot
    mode = 0666
    user = 
  }
}
ssl_cert = </usr/local/etc/dehydrated/certs/covisp.net/fullchain.pem
ssl_dh = # hidden, use -P to show it
ssl_key = # hidden, use -P to show it
ssl_min_protocol = TLSv1.1
userdb {
  driver = passwd
}
userdb {
  args = /usr/local/etc/dovecot/dovecot-sql.conf.ext
  default_fields = uid=vpopmail gid=vchkpw mail_location=/usr/local/virtual/%u/Maildir mail=maildir:/usr/local/virtual/%u/Maildir
  driver = sql
}
protocol imap {
  mail_plugins = " lazy_expunge acl imap_sieve"
}