Hello,
I'm trying to configure the dovecot-antispam plugin.
Now I've run into a problem: whenever I try to move/copy a message
in/from the spam mailbox, Thunderbird (and also Sylpheed, haven't tried
anything else) says:
The current command did not succeed. The mail server responded: Failed
to read mail beginning.
and in the logs I get:
dovecot: Aug 07 10:41:23 Error: IMAP(username): Next message
unexpectedly lost from 337928
dovecot: Aug 07 10:41:23 Error: IMAP(username): Next message
unexpectedly lost from 337928
The message is not moved/copied.
My config (dovecot -n):
base_dir: /var/run/dovecot_test/
log_path: /var/log/dovecot/test_log
info_log_path: /var/log/dovecot/test_info_log
protocols: pop3s imaps pop3 imap
listen(default): *:10143
listen(imap): *:10143
listen(pop3): *:10110
ssl_listen(default): *:10993
ssl_listen(imap): *:10993
ssl_listen(pop3): *:10995
ssl_cert_file: /etc/ssl/anxur.pem
ssl_key_file: /etc/ssl/anxur.pem
ssl_parameters_regenerate: 24
login_dir: /var/run/dovecot_test/login
login_executable(default):
/packages/run.64/dovecot-1.1.2/libexec/dovecot/imap-login
login_executable(imap):
/packages/run.64/dovecot-1.1.2/libexec/dovecot/imap-login
login_executable(pop3):
/packages/run.64/dovecot-1.1.2/libexec/dovecot/pop3-login
login_greeting: HI!
login_greeting_capability(default): yes
login_greeting_capability(imap): yes
login_greeting_capability(pop3): no
verbose_proctitle: yes
first_valid_uid: 200
mail_location:
mbox:/home/%u/mail/:INBOX=/var/mail/%u:INDEX=/home/%u/mail/.imap
mail_debug: yes
mail_full_filesystem_access: yes
maildir_copy_with_hardlinks: no
mbox_write_locks: fcntl
mbox_dirty_syncs: no
mbox_lazy_writes: no
dbox_rotate_days: 0
mail_executable(default):
/packages/run.64/dovecot-1.1.2/libexec/dovecot/imap
mail_executable(imap): /packages/run.64/dovecot-1.1.2/libexec/dovecot/imap
mail_executable(pop3): /packages/run.64/dovecot-1.1.2/libexec/dovecot/pop3
mail_plugins(default): antispam
mail_plugins(imap): antispam
mail_plugins(pop3):
mail_plugin_dir(default): /packages/run.64/dovecot-1.1.2/lib/dovecot/imap
mail_plugin_dir(imap): /packages/run.64/dovecot-1.1.2/lib/dovecot/imap
mail_plugin_dir(pop3): /packages/run.64/dovecot-1.1.2//lib/dovecot/pop3
mail_log_max_lines_per_sec: 20
imap_max_line_length(default): 131072
imap_max_line_length(imap): 131072
imap_max_line_length(pop3): 65536
imap_client_workarounds(default): delay-newmail outlook-idle
tb-extra-mailbox-sep
imap_client_workarounds(imap): delay-newmail outlook-idle
tb-extra-mailbox-sep
imap_client_workarounds(pop3):
pop3_uidl_format(default): %08Xu%08Xv
pop3_uidl_format(imap): %08Xu%08Xv
pop3_uidl_format(pop3): %08Xv%08Xu
pop3_client_workarounds(default):
pop3_client_workarounds(imap):
pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh
auth default:
mechanisms: gssapi plain
executable:
/packages/run.64/dovecot-1.1.2/libexec/dovecot/dovecot-auth
krb5_keytab: /etc/krb5.imap
verbose: yes
debug: yes
passdb:
driver: pam
args: dovecot
userdb:
driver: passwd
plugin:
antispam_spam: mailbox.spam
antispam_trash: trash;Trash;Deleted Items
antispam_mail_spam: [EMAIL PROTECTED]
antispam_mail_notspam: [EMAIL PROTECTED]
antispam_mail_sendmail: /home/username/fake_sendmail
Dovecot is version 1.1.2, dovecot-antispam is the latest snapshot.
Running on Red Hat Enterprise Linux Server release 5.2, x86_64,
filesystem is ext3 (on lvm).
Attached is the strace -p of the session.
The code seems to be this in i_stream_raw_mbox_read:
if (stream->istream.v_offset -
rstream->hdr_offset + new_pos > rstream->mail_size) {
/* istream_raw_mbox_set_next_offset() used invalid
cached next_offset? */
i_error("Next message unexpectedly lost from
%"PRIuUOFF_T,
rstream->hdr_offset + rstream->mail_size);
rstream->eof = TRUE;
rstream->corrupted = TRUE;
return -1;
}
If I comment it out (after I backup my mail), everything seems to work
as expected.
Jiri Novosad
epoll_wait(6, {{EPOLLIN, {u32=7035872, u64=7035872}}}, 4, 492) = 1
gettimeofday({1218008692, 930362}, NULL) = 0
gettimeofday({1218008692, 930446}, NULL) = 0
read(0, "452 uid copy 4 \"mailbox.", 24) = 24
gettimeofday({1218008692, 930610}, NULL) = 0
epoll_wait(6, {{EPOLLIN, {u32=7035872, u64=7035872}}}, 4, 423) = 1
gettimeofday({1218008692, 930806}, NULL) = 0
gettimeofday({1218008692, 930903}, NULL) = 0
read(0, "spam\"\r\n", 4087) = 7
stat("/home/username/mail/mailbox.spam", {st_mode=S_IFREG|0644, st_size=140169,
...}) = 0
stat("/home/username/mail/mailbox.spam", {st_mode=S_IFREG|0644, st_size=140169,
...}) = 0
stat("/home/username/mail/.imap/.imap/mailbox.spam", {st_mode=S_IFDIR|0700,
st_size=4096, ...}) = 0
gettimeofday({1218008692, 931707}, NULL) = 0
access("/home/username/mail/mailbox.spam", R_OK|W_OK) = 0
open("/home/username/mail/.imap/.imap/mailbox.spam/dovecot.index.log", O_RDWR)
= 10
fstat(10, {st_mode=S_IFREG|0600, st_size=10908, ...}) = 0
pread(10, "\1\0\30\0\373\264\226H\4\0\0\0\3\0\0\0\364\334\0\0|\"\230H", 24, 0)
= 24
stat("/home/username/mail/.imap/.imap/mailbox.spam/dovecot.index.log.2",
0x7fffd3bb6f50) = -1 ENOENT (No such file or directory)
open("/home/username/mail/.imap/.imap/mailbox.spam/dovecot.index", O_RDWR) = 11
alarm(120) = 0
fcntl(11, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=0, len=0}) = 0
alarm(0) = 120
fstat(11, {st_mode=S_IFREG|0600, st_size=1136, ...}) = 0
pread(11,
"\7\2x\0x\1\0\0(\0\0\0\1\0\0\0\373\264\226H\0\0\0\0\373\264\226H\232\10\0\0"...,
4096, 0) = 1136
fcntl(11, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
stat("/home/username/mail/.imap/.imap/mailbox.spam/dovecot.index.log",
{st_mode=S_IFREG|0600, st_size=10908, ...}) = 0
fstat(10, {st_mode=S_IFREG|0600, st_size=10908, ...}) = 0
pread(10, "\200\200\200\204 \0\0\20P\0\4\0\322P\231H\200\200\200\204
\0\0\0200\0\4\0\232\10\0\0"..., 1024, 10204) = 704
pread(10, "", 1024, 10908) = 0
mkdir("/tmp/antispam-mail-GYlEb4", 0700) = 0
mkdir("/tmp/antispam-mail-Rb3HAN", 0700) = 0
gettimeofday({1218008692, 933917}, NULL) = 0
gettimeofday({1218008692, 934014}, NULL) = 0
stat("/home/username/mail/sent-mail", {st_mode=S_IFREG|0644, st_size=2143,
...}) = 0
gettimeofday({1218008692, 934308}, NULL) = 0
alarm(5) = 0
fcntl(19, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=0, len=0}) = 0
alarm(0) = 5
stat("/home/username/mail/sent-mail", {st_mode=S_IFREG|0644, st_size=2143,
...}) = 0
stat("/home/username/mail/.imap/.imap/sent-mail/dovecot.index.log",
{st_mode=S_IFREG|0600, st_size=2088, ...}) = 0
fstat(8, {st_mode=S_IFREG|0600, st_size=2088, ...}) = 0
fstat(19, {st_mode=S_IFREG|0644, st_size=2143, ...}) = 0
pread(19, "\nFrom [EMAIL PROTECTED] Thu Jul "..., 4096, 551) = 1592
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/home/username/mail/.imap/.imap/sent-mail/dovecot.index.log",
{st_mode=S_IFREG|0600, st_size=2088, ...}) = 0
fstat(8, {st_mode=S_IFREG|0600, st_size=2088, ...}) = 0
gettimeofday({1218008692, 935474}, NULL) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
sendto(7, "<14>Aug 6 09:44:52 imap: antisp"..., 71, MSG_NOSIGNAL, NULL, 0) = 71
gettimeofday({1218008692, 936290}, NULL) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
sendto(7, "<14>Aug 6 09:44:52 imap: antisp"..., 67, MSG_NOSIGNAL, NULL, 0) = 67
gettimeofday({1218008692, 937117}, NULL) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
sendto(7, "<14>Aug 6 09:44:52 imap: antisp"..., 70, MSG_NOSIGNAL, NULL, 0) = 70
gettimeofday({1218008692, 937848}, NULL) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
sendto(7, "<14>Aug 6 09:44:52 imap: antisp"..., 74, MSG_NOSIGNAL, NULL, 0) = 74
gettimeofday({1218008692, 938501}, NULL) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
sendto(7, "<14>Aug 6 09:44:52 imap: antisp"..., 66, MSG_NOSIGNAL, NULL, 0) = 66
gettimeofday({1218008692, 939236}, NULL) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
sendto(7, "<14>Aug 6 09:44:52 imap: antisp"..., 69, MSG_NOSIGNAL, NULL, 0) = 69
gettimeofday({1218008692, 939981}, NULL) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
sendto(7, "<14>Aug 6 09:44:52 imap: antisp"..., 68, MSG_NOSIGNAL, NULL, 0) = 68
gettimeofday({1218008692, 940611}, NULL) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
sendto(7, "<14>Aug 6 09:44:52 imap: antisp"..., 87, MSG_NOSIGNAL, NULL, 0) = 87
gettimeofday({1218008692, 941375}, NULL) = 0
gettimeofday({1218008692, 941511}, NULL) = 0
open("/home/username/mail/mailbox.spam", O_RDWR) = 12
fstat(12, {st_mode=S_IFREG|0644, st_size=140169, ...}) = 0
gettimeofday({1218008692, 941777}, NULL) = 0
alarm(5) = 0
fcntl(12, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}) = 0
alarm(0) = 5
stat("/home/username/mail/mailbox.spam", {st_mode=S_IFREG|0644, st_size=140169,
...}) = 0
stat("/home/username/mail/mailbox.spam", {st_mode=S_IFREG|0644, st_size=140169,
...}) = 0
alarm(180) = 0
fcntl(10, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}) = 0
alarm(0) = 180
stat("/home/username/mail/.imap/.imap/mailbox.spam/dovecot.index.log",
{st_mode=S_IFREG|0600, st_size=10908, ...}) = 0
fstat(10, {st_mode=S_IFREG|0600, st_size=10908, ...}) = 0
fcntl(10, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
stat("/home/username/mail/.imap/.imap/mailbox.spam/dovecot.index.log",
{st_mode=S_IFREG|0600, st_size=10908, ...}) = 0
fstat(10, {st_mode=S_IFREG|0600, st_size=10908, ...}) = 0
fstat(12, {st_mode=S_IFREG|0644, st_size=140169, ...}) = 0
lseek(12, 140168, SEEK_SET) = 140168
read(12, "\n", 1) = 1
fstat(12, {st_mode=S_IFREG|0644, st_size=140169, ...}) = 0
fstat(12, {st_mode=S_IFREG|0644, st_size=140169, ...}) = 0
pread(12, "\n", 4096, 140168) = 1
pread(12, "", 4095, 140169) = 0
pread(19, "Return-Path: <[EMAIL PROTECTED]>\n"..., 4096, 600) = 1543
pread(19, "", 2553, 2143) = 0
pread(19, "", 2553, 2143) = 0
pread(19, "", 2553, 2143) = 0
write(12, "From [EMAIL PROTECTED] Thu Jul 3"..., 1593) = 1593
pwrite(12, "\nContent-Length: 581", 20, 141159) = 20
creat("/tmp/antispam-mail-GYlEb4/0", 0600) = 13
lseek(13, 0, SEEK_CUR) = 0
fstat(13, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0
write(13, "\1\0\0\0", 4) = 4
pread(12, "From [EMAIL PROTECTED] Thu Jul 3"..., 4095, 140169) = 1593
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
write(2, "\1ENext message unexpectedly lost"..., 45) = 45
pread(12, "\nFrom [EMAIL PROTECTED] Thu Jul "..., 4096, 140168) = 1594
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2246, ...}) = 0
write(2, "\1ENext message unexpectedly lost"..., 45) = 45
close(13) = 0
close(13) = -1 EBADF (Bad file descriptor)
rmdir("/tmp/antispam-mail-Rb3HAN") = 0
stat("/home/username/mail/.imap/.imap/sent-mail/dovecot.index.log",
{st_mode=S_IFREG|0600, st_size=2088, ...}) = 0
fstat(8, {st_mode=S_IFREG|0600, st_size=2088, ...}) = 0
fcntl(19, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
alarm(0) = 0
write(12, "\n", 1) = 1
ftruncate(12, 140169) = 0
fcntl(12, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
alarm(0) = 0
unlink("/tmp/antispam-mail-GYlEb4/0") = 0
rmdir("/tmp/antispam-mail-GYlEb4") = 0
close(12) = 0
gettimeofday({1218008692, 946718}, NULL) = 0
write(1, "452 NO Failed to read mail begin"..., 38) = 38
gettimeofday({1218008692, 946937}, NULL) = 0
epoll_wait(6, {}, 4, 407) = 0
gettimeofday({1218008693, 353573}, NULL) = 0
gettimeofday({1218008693, 353660}, NULL) = 0
epoll_wait(6, {{EPOLLIN, {u32=7035872, u64=7035872}}}, 4, 5000) = 1
gettimeofday({1218008694, 161166}, NULL) = 0
gettimeofday({1218008694, 161210}, NULL) = 0
read(0, "453 IDLE\r\n", 4080) = 10
gettimeofday({1218008694, 161352}, NULL) = 0
inotify_add_watch(18, "/home/username/mail/sent-mail",
IN_MODIFY|IN_CLOSE_WRITE|IN_CLOSE_NOWRITE|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF)
= 123
epoll_ctl(6, EPOLL_CTL_ADD, 18, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP,
{u32=7144768, u64=7144768}}) = 0
stat("/home/username/mail/sent-mail", {st_mode=S_IFREG|0644, st_size=2143,
...}) = 0
gettimeofday({1218008694, 161636}, NULL) = 0
epoll_ctl(6, EPOLL_CTL_DEL, 0, {0, {u32=7035872, u64=7035872}}) = 0
epoll_ctl(6, EPOLL_CTL_ADD, 0, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP,
{u32=7035872, u64=7035872}}) = 0
gettimeofday({1218008694, 161895}, NULL) = 0
stat("/home/username/mail/sent-mail", {st_mode=S_IFREG|0644, st_size=2143,
...}) = 0
alarm(180) = 0
fcntl(8, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}) = 0
alarm(0) = 180
stat("/home/username/mail/.imap/.imap/sent-mail/dovecot.index.log",
{st_mode=S_IFREG|0600, st_size=2088, ...}) = 0
fstat(8, {st_mode=S_IFREG|0600, st_size=2088, ...}) = 0
fcntl(8, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
mkdir("/tmp/antispam-mail-3WExWz", 0700) = 0
rmdir("/tmp/antispam-mail-3WExWz") = 0
stat("/home/username/mail/.imap/.imap/sent-mail/dovecot.index.log",
{st_mode=S_IFREG|0600, st_size=2088, ...}) = 0
fstat(8, {st_mode=S_IFREG|0600, st_size=2088, ...}) = 0
write(1, "+ idling\r\n", 10) = 10
gettimeofday({1218008694, 164036}, NULL) = 0
epoll_wait(6, {{EPOLLIN, {u32=7144768, u64=7144768}}}, 4, 4189) = 1
gettimeofday({1218008694, 164168}, NULL) = 0
read(18, "z\0\0\0\0\200\0\0\0\0\0\0\0\0\0\0", 32768) = 16
gettimeofday({1218008694, 164332}, NULL) = 0
gettimeofday({1218008694, 164400}, NULL) = 0
epoll_wait(6, ^C <unfinished ...>
