[Dovecot] [Dovecot 1.2.11(NFS used) & dovecot-antispam 1.2]: move message error
Hello! I am really need help!
I am using dovecot installation on ~700 users with dspam integration via dovecot-antispam plugin. Problem in unpredictable result of moving spam-mails from INBOX to Junk and from Junk to INBOX. In some cases it works fine, but sometimes I see error like "It's not possible to move the message" in client (roundcube).
Two different samples on same configuration/server. Moving from INBOX into Junk.
Successful moving (roundcube imap debug): -------------%<------------ [19:05:35]: C: cpy1 UID COPY 2387 "Junk" [19:05:35]: S: cpy1 OK [COPYUID 1273276423 2387 1280] Copy completed. [19:05:35]: C: flg UID STORE 2387 +FLAGS (\Deleted) [19:05:35]: S: * 1471 FETCH (UID 2387 FLAGS (\Deleted \Seen)) [19:05:35]: S: flg OK Store completed. [19:05:35]: C: exp1 UID EXPUNGE 2387 [19:05:35]: S: * 1471 EXPUNGE [19:05:35]: S: exp1 OK Expunge completed. Result: message moved into Junk, dspam retrained. Success. ------------->%------------
Unsuccessful moving -------------%<------------ [19:02:47]: C: cpy1 UID COPY 2386 "Junk" [19:02:57]: S: * OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE AUTH=PLAIN AUTH=LOGIN] Dovecot ready. [19:02:57]: C: cp01 CAPABILITY [19:02:57]: S: * CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE SORT SORT=DISPLAY THREAD=RE FERENCES THREAD=REFS MULTIAPPEND UNSELECT IDLE CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS QUOTA AUTH=PLAIN AUTH=LOGIN [19:02:57]: S: cp01 OK Capability completed. Result: I see moving error in roundcube. Sometimes I see several duplicates of original message in Junk and original message also presented in INBOX. Malfunction. ------------->%------------
Similar symptoms also affected while moving message from Junk into INBOX. One more sample. Junk -> INBOX moving. -------------%<------------ [20:20:16]: C: cpy1 UID COPY 2859 "INBOX" [20:20:20]: S: * OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE AUTH=PLAIN AUTH=LOGIN] Dovecot ready. [20:20:20]: C: cp01 CAPABILITY [20:20:20]: S: * CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE SORT SORT=DISPLAY THREAD=RE FERENCES THREAD=REFS MULTIAPPEND UNSELECT IDLE CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS QUOTA AUTH=PLAIN AUTH=LOGIN [20:20:20]: S: cp01 OK Capability completed. Result: move failure. Duplicates in INBOX. ------------->%------------
Mails stored on NFS server - Ubuntu 9.10 (Linux storage01 2.6.31-21-generic-pae #59-Ubuntu SMP Wed Mar 24 08:47:55 UTC 2010 i686 GNU/Linux). Indexes now stored locally, but I already try to store them on NFS. No difference.
Dovecot and NFS client running under FreeBSD 8.
-------------%<------------
mail01#uname -a
FreeBSD mail01.domain.net 8.0-RELEASE FreeBSD 8.0-RELEASE #0: Sat Nov 21
15:48:17 UTC 2009
root@almeida.cse.buffalo.edu:/usr/obj/usr/src/sys/GENERIC i386
------------->%------------
Mount options. Two variant:
- 192.164.100.103:/mnt/storage/mailstores /var/mail/mymail nfs
rw,acregmin=0,acregmax=0,acdirmin=0,acdirmax=0 0 0 2(current). 192.164.100.103:/mnt/storage/mailstores /var/mail/mymail
nfs rw,bg,tcp,nosuid 0 0 In both variants error detected.
-------------%<------------ mail01# dovecot --version 1.2.11 mail01# pkg_info | grep dspam dovecot-antispam-1.2_4,1 Dovecot plugin to train dspam about spam or false positives dspam-3.9.0_1 Bayesian spam filter - stable maintenance version ------------->%------------ Dspam build with direct dspam training possibility, debug and debug_verbose options.
All installed from ports. Current dovecot configuration: -------------%<------------ mail01# dovecot -n # 1.2.11: /usr/local/etc/dovecot.conf # OS: FreeBSD 8.0-RELEASE i386 nfs base_dir: /var/run/dovecot/ log_path: /var/log/dovecot/dovecot.log protocols: imap pop3 ssl: no disable_plaintext_auth: no login_dir: /var/run/dovecot/login login_executable(default): /usr/local/libexec/dovecot/imap-login login_executable(imap): /usr/local/libexec/dovecot/imap-login login_executable(pop3): /usr/local/libexec/dovecot/pop3-login login_max_processes_count: 256 verbose_proctitle: yes first_valid_uid: 1 last_valid_uid: 10000 last_valid_gid: 10000 mail_privileged_group: mail mail_uid: dovecot mail_gid: mail mail_location: maildir:/var/mail/mymail/%d/%n:INDEX=/var/mail/indexes/%d/%n mail_debug: yes mail_nfs_storage: yes mbox_write_locks: fcntl dotlock mail_executable(default): /usr/local/libexec/dovecot/imap mail_executable(imap): /usr/local/libexec/dovecot/imap mail_executable(pop3): /usr/local/libexec/dovecot/pop3 mail_plugins(default): quota imap_quota convert antispam autocreate mail_plugins(imap): quota imap_quota convert antispam autocreate mail_plugins(pop3): quota convert autocreate mail_plugin_dir(default): /usr/local/lib/dovecot/imap mail_plugin_dir(imap): /usr/local/lib/dovecot/imap mail_plugin_dir(pop3): /usr/local/lib/dovecot/pop3 imap_client_workarounds(default): delay-newmail netscape-eoh tb-extra-mailbox-sep imap_client_workarounds(imap): delay-newmail netscape-eoh tb-extra-mailbox-sep imap_client_workarounds(pop3): pop3_client_workarounds(default): pop3_client_workarounds(imap): pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh lda: postmaster_address: admin@domain.net hostname: mail.domain2.net mail_plugins: quota mail_plugin_dir: /usr/local/lib/dovecot/lda quota_full_tempfail: yes sendmail_path: /usr/sbin/sendmail rejection_reason: Your message to <%t> was automatically rejected:%n%r auth_socket_path: /var/run/dovecot/auth-master log_path: /var/log/dovecot/dovecot-deliver.log info_log_path: /var/log/dovecot/dovecot-deliver.log auth default: mechanisms: plain login default_realm: domain.net username_format: %Lu failure_delay: 3 verbose: yes debug: yes debug_passwords: yes passdb: driver: sql args: /usr/local/etc/dovecot-sql.conf userdb: driver: sql args: /usr/local/etc/dovecot-sql.conf socket: type: listen client: path: /var/run/dovecot/auth-client mode: 438 master: path: /var/run/dovecot/auth-master mode: 384 user: mailnull group: mail plugin: quota_rule: *:storage=50M quota: maildir convert_mail: mbox:/var/mail/old/%u antispam_signature: X-DSPAM-Signature antispam_spam: Junk antispam_trash: Trash antispam_signature_missing: move antispam_dspam_result_header: X-DSPAM-Result antispam_allow_append_to_spam: yes antispam_dspam_binary: /usr/local/bin/dspam antispam_dspam_args: --user;%u antispam_mail_tmpdir: /tmp autocreate: Trash autocreate2: Junk autocreate3: Sent autocreate4: Drafts autosubscribe: Trash autosubscribe2: Junk autosubscribe3: Sent autosubscribe4: Drafts ------------->%------------
User, maildir size independence.
Any ideas? What cause? What can do with this? Really need to solve it.
On Fri, 2010-06-18 at 23:13 +0400, Администратор wrote:
- Unsuccessful moving -------------%<------------ [19:02:47]: C: cpy1 UID COPY 2386 "Junk" [19:02:57]: S: * OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE AUTH=PLAIN AUTH=LOGIN] Dovecot ready.
That looks like it crashes. Did you look at the error log?
On Fri, 18 Jun 2010 20:18:54 +0100, Timo Sirainen <tss@iki.fi> wrote:
On Fri, 2010-06-18 at 23:13 +0400, Администратор wrote:
- Unsuccessful moving -------------%<------------ [19:02:47]: C: cpy1 UID COPY 2386 "Junk" [19:02:57]: S: * OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE AUTH=PLAIN AUTH=LOGIN] Dovecot ready.
That looks like it crashes. Did you look at the error log?
I am afraid yes. There is only Info messages. I can do raw log or activate mail_log if it can be useful.
On Fri, 2010-06-18 at 23:34 +0400, Администратор wrote:
On Fri, 18 Jun 2010 20:18:54 +0100, Timo Sirainen <tss@iki.fi> wrote:
On Fri, 2010-06-18 at 23:13 +0400, Администратор wrote:
- Unsuccessful moving -------------%<------------ [19:02:47]: C: cpy1 UID COPY 2386 "Junk" [19:02:57]: S: * OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE AUTH=PLAIN AUTH=LOGIN] Dovecot ready.
That looks like it crashes. Did you look at the error log?
I am afraid yes. There is only Info messages.
I'd suggest setting info_log_path to a different file than log_path. Then it's much easier to find error messages.
I can do raw log or activate mail_log if it can be useful.
If it's not Dovecot that crashes (it would have logged an Error/Fatal/Panic if it did), then Roundcube decides to disconnect before waitinf ro reply to COPY. Rawlog output could be helpful then to see what's different.
On Fri, 18 Jun 2010 20:38:28 +0100, Timo Sirainen <tss@iki.fi> wrote:
On Fri, 2010-06-18 at 23:34 +0400, Администратор wrote:
On Fri, 18 Jun 2010 20:18:54 +0100, Timo Sirainen <tss@iki.fi> wrote:
On Fri, 2010-06-18 at 23:13 +0400, Администратор wrote:
- Unsuccessful moving -------------%<------------ [19:02:47]: C: cpy1 UID COPY 2386 "Junk" [19:02:57]: S: * OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE AUTH=PLAIN AUTH=LOGIN] Dovecot ready.
That looks like it crashes. Did you look at the error log?
I am afraid yes. There is only Info messages.
I'd suggest setting info_log_path to a different file than log_path. Then it's much easier to find error messages.
I can do raw log or activate mail_log if it can be useful.
If it's not Dovecot that crashes (it would have logged an Error/Fatal/Panic if it did), then Roundcube decides to disconnect before waitinf ro reply to COPY. Rawlog output could be helpful then to see what's different.
Now my settings is log_path = /var/log/dovecot/dovecot_err.log info_log_path = /var/log/dovecot/dovecot.log but error log contains only warning about process kill (restart). It's normal.
I am activate rawlog, but cant reproduce problem, at this moment all works fine. I dont think that it could be result of log_path operations =) I can show another sample those I get several days ago on same server (client Roundcube)
File: 20100609-050318-62156.in -----------%<----------- sel1 SELECT "INBOX" lsb LSUB "" "*" cpy1 UID COPY 1857 "Junk" I LOGOUT ----------->%-----------
File: 20100609-050318-62156.out -----------%<-----------
- OK [RAWLOG TIMESTAMP] 2010-06-09 05:03:18 a001 OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS MULT IAPPEND UNSELECT IDLE CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN C ONTEXT=SEARCH LIST-STATUS QUOTA] Logged in
- FLAGS (\Answered \Flagged \Deleted \Seen \Draft $MDNSent $Forwarded)
- OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft $MDNSent $Forwarded \*)] Flags permitted.
- 1414 EXISTS
- 0 RECENT
- OK [UNSEEN 1403] First unseen.
- OK [UIDVALIDITY 1273276420] UIDs valid
- OK [UIDNEXT 1866] Predicted next UID
- OK [HIGHESTMODSEQ 1] Highest sel1 OK [READ-WRITE] Select completed.
- LSUB () "." "Trash"
- LSUB () "." "Junk"
- LSUB () "." "Sent"
- LSUB () "." "Drafts" lsb OK Lsub completed. cpy1 OK [COPYUID 1273276423 1857 612] Copy completed.
- BYE Logging out ----------->%-----------
So, is this Roundcube issue??
Администратор wrote:
So, is this Roundcube issue??
Try with svn-trunk version. In previous versions of Roundcube there was a 10 seconds limit on socket connection. If copying is slow this would be the issue.
-- Aleksander 'A.L.E.C' Machniak http://alec.pl gg:2275252 LAN Management System Developer http://lms.org.pl Roundcube Webmail Developer http://roundcube.net
participants (3)
-
A.L.E.C
-
Timo Sirainen
-
Администр атор