dovecot - Aug 2007 - Dovecot 1.0.3: mbox problems for newly created users

Hi,

I am having problems with Dovecot 1.0.3 and Thunderbird 2.0.0.6 when
using a new user account without any mbox files present.

Directory /home/$user/.imap_mail/ does not exist when Thunderbird first
tries to login using IMAP to the account. On login this directory is
created with a zero byte Trash file and .subscriptions containing string
"Trash", so far, so good.

Now I create a new message in Thunderbird and save it as draft. A zero
byte file "Drafts" is created in /home/$user/.imap_mail/ but the
message
I wanted to save got _lost_, /home/$user/.imap_mail/Drafts stays at zero
bytes. The next message I try to save as draft finds its way to the Drafts
mbox however.

Please note that no /home/$user/.imap_mail/inbox has been created although
a inbox is shown in Thunderbird. When I move the saved message from Drafts
to the inbox folder shown in Thunderbird, it gets saved in /var/mail/$user
instead of /home/$user/.imap_mail/inbox, I guess this is due to the use
of the mbox_snarf plugin, right?

/home/$user/.imap_mail/inbox is the maildrop for Exim, which handles
incoming mails, but in this scenario the user did not receive any
emails yet.

If I manually create /home/$user/.imap_mail/inbox, then moving a message
from Drafts to the Thunderbird-displayed inbox works.

How to fix this problem? Especially messages getting lost is really bad
because I am in the process of changing our mail server setup from
Exim/UW-Imapd to Exim/Dovecot, where I have to move 100+ /var/mail/$user
mbox files to /home/$user/.imap_mail/inbox. But when Dovecot can not
properly save files to previous non-existing mbox files, like Drafts,
this is really a problem.

Greetings, Bernd Kuhls

PS: Here are the Dovecot settings:
# dovecot -n
# 1.0.3: /etc/dovecot/dovecot.conf
log_path: /var/log/dovecot/dovecot.main
log_timestamp: %Y-%m-%d %H:%M:%S
protocols: imap imaps pop3 pop3s
login_dir: /var/run/dovecot/login
login_executable(default): /usr/lib/dovecot/imap-login
login_executable(imap): /usr/lib/dovecot/imap-login
login_executable(pop3): /usr/lib/dovecot/pop3-login
mail_extra_groups: mail
mail_location: 
mbox:~/.imap_mail:INBOX=/var/mail/%u:INDEX=/var/mail/indexes/%u
mail_executable(default): /usr/lib/dovecot/imap
mail_executable(imap): /usr/lib/dovecot/imap
mail_executable(pop3): /usr/lib/dovecot/pop3
mail_plugins(default): quota imap_quota mbox_snarf
mail_plugins(imap): quota imap_quota mbox_snarf
mail_plugins(pop3): mbox_snarf
mail_plugin_dir(default): /usr/lib/dovecot/modules/imap
mail_plugin_dir(imap): /usr/lib/dovecot/modules/imap
mail_plugin_dir(pop3): /usr/lib/dovecot/modules/pop3
imap_client_workarounds(default): outlook-idle netscape-eoh 
tb-extra-mailbox-sep delay-newmail
imap_client_workarounds(imap): outlook-idle netscape-eoh 
tb-extra-mailbox-sep delay-newmail
imap_client_workarounds(pop3): outlook-idle
pop3_uidl_format(default):
pop3_uidl_format(imap):
pop3_uidl_format(pop3): %08Xu%08Xv
auth default:
   passdb:
     driver: pam
   userdb:
     driver: passwd
plugin:
   quota: fs
   mbox_snarf: ~/.imap_mail/inbox

Bernd Kuhls wrote:
> Now I create a new message in Thunderbird and save it as draft. A zero
> byte file "Drafts" is created in /home/$user/.imap_mail/ but the
message
> I wanted to save got _lost_, /home/$user/.imap_mail/Drafts stays at zero
> bytes. The next message I try to save as draft finds its way to the Drafts
> mbox however.
Hi,

this problem still exists with Dovecot 1.0.3 + mbox-snarf patch 
(http://hg.dovecot.org/dovecot-1.0/rev/1b6c41524c6a)

Greetings, Bernd

On Tue, 2007-08-07 at 12:21 +0200, Bernd Kuhls wrote:
> Now I create a new message in Thunderbird and save it as draft. A zero
> byte file "Drafts" is created in /home/$user/.imap_mail/ but the
message
> I wanted to save got _lost_, /home/$user/.imap_mail/Drafts stays at zero
> bytes. The next message I try to save as draft finds its way to the Drafts
> mbox however.
Did you check what commands Thunderbird sends? Use e.g. rawlog
(http://dovecot.org/bugreport.html). I don't think snarf plugin should
cause this, and in general I can't think of a bug in Dovecot that would
cause this.

I'm guessing what happens is:

C: 1 APPEND Drafts {...}
S: 1 NO [TRYCREATE] Mailbox doesn't exist.
C: 2 CREATE Drafts
S: 2 OK

Maybe at that point Thunderbird doesn't bother to try again anymore.
> Please note that no /home/$user/.imap_mail/inbox has been created although
> a inbox is shown in Thunderbird. When I move the saved message from Drafts
> to the inbox folder shown in Thunderbird, it gets saved in /var/mail/$user
> instead of /home/$user/.imap_mail/inbox, I guess this is due to the use
> of the mbox_snarf plugin, right?
Right. If you want .imap_mail/inbox to be used always, either change the
mbox snarf code (remove stat(mstorage->snarf_inbox_path, &st) check) or
make sure to create the file when creating new users.
> If I manually create /home/$user/.imap_mail/inbox, then moving a message
> from Drafts to the Thunderbird-displayed inbox works.
Doesn't Dovecot use /var/mail/$user then as the INBOX if
the .imap_mail/inbox doesn't exist?

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 189 bytes
Desc: This is a digitally signed message part
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20070909/7bc77017/attachment-0002.bin>

Hi,

Timo Sirainen wrote:
> On Tue, 2007-08-07 at 12:21 +0200, Bernd Kuhls wrote:
>> Now I create a new message in Thunderbird and save it as draft. A zero
>> byte file "Drafts" is created in /home/$user/.imap_mail/ but
the message
>> I wanted to save got _lost_, /home/$user/.imap_mail/Drafts stays at
zero
>> bytes. The next message I try to save as draft finds its way to the
Drafts
>> mbox however.
> 
> Did you check what commands Thunderbird sends? Use e.g. rawlog
> (http://dovecot.org/bugreport.html). I don't think snarf plugin should
> cause this, and in general I can't think of a bug in Dovecot that would
> cause this.
I reproduced the bug with Dovecot 1.0.5 without snarf plugin and it
happened again.

The user I used is "kuhls2", its home is /home/kuhls2, the mail folder
(mbox format) is "/home/kuhls2/.imap_mail". This directory does not
exist when I started my tests with a fresh install of Thunderbird
2.0.0.6 on Windows XP. I need this scenario working because I am about
to switch from a working UW-IMAP install using /var/mail/$USER to
Dovecot using "$HOME/.imap_mail/". Saved mails should not get lost
with
the new setup.

After setting up Thunderbird with IMAP/SSL access I connected to the
Dovecot server and logged in, .imap_mail looks like this after login:
> bach:/home/kuhls2/dovecot.rawlog# ls -la ../.imap_mail/
> total 12
> -rw------- 1 kuhls2 worker    0 2007-09-09 22:49 inbox
> -rw------- 1 kuhls2 worker    6 2007-09-09 22:49 .subscriptions
> -rw------- 1 kuhls2 worker    0 2007-09-09 22:49 Trash
These files were created during the first login with Thunderbird, note
that neither a mbox "Drafts" is created nor is it visible in
Thunderbirds folder list, which is ok.

Here is the rawlog of this transaction:
> # cat 20070909-234323-10517.in
> 3 namespace
> 4 lsub "" "*"
> 5 list "" "INBOX"
> 6 list "" "Trash"
> 7 create "Trash"
> 8 subscribe "Trash"
> 9 list "" "Trash"
> 10 select "INBOX"
> 11 getquotaroot "INBOX"
> 12 IDLE
> 
> # cat 20070909-234323-10517.out
> * OK [RAWLOG TIMESTAMP] 2007-09-09 23:43:23
> * NAMESPACE (("" "/")) NIL NIL
> 3 OK Namespace completed.
> 4 OK Lsub completed.
> * LIST (\NoInferiors \UnMarked) "/" "INBOX"
> 5 OK List completed.
> 6 OK List completed.
> 7 OK Create completed.
> 8 OK Subscribe completed.
> * LIST (\NoInferiors \UnMarked) "/" "Trash"
> 9 OK List completed.
> * FLAGS (\Answered \Flagged \Deleted \Seen \Draft)
> * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft \*)] Flags
permitted.
> * 0 EXISTS
> * 0 RECENT
> * OK [UIDVALIDITY 1189369511] UIDs valid
> * OK [UIDNEXT 1] Predicted next UID
> 10 OK [READ-WRITE] Select completed.
> * QUOTAROOT "INBOX" ""
> * QUOTA "" (STORAGE 84 0)
> 11 OK Getquotaroot completed.
> + idling
Then I started to write a new mail and saved it as Draft, mbox Drafts
gets created with 0 byte length, no error message in Dovecot logfile nor
in Thunderbird, the mail content was not saved at all:
> bach:/home/kuhls2/dovecot.rawlog# ls -la ../.imap_mail/
> total 12
> -rw------- 1 kuhls2 worker    0 2007-09-09 22:51 Drafts
> -rw------- 1 kuhls2 worker    0 2007-09-09 22:49 inbox
> -rw------- 1 kuhls2 worker   13 2007-09-09 22:51 .subscriptions
> -rw------- 1 kuhls2 worker    0 2007-09-09 22:49 Trash
> bach:/home/kuhls2/dovecot.rawlog# cat ../.imap_mail/.subscriptions
> Trash
> Drafts
Here is the rawlog when saving the mail into drafts folder.
The first two log files had some lines added:
> # cat 20070909-234323-10517.in
> ...
> DONE
> 13 list "" "Drafts"
> 14 create "Drafts"
> 15 subscribe "Drafts"
> 16 list "" "Drafts"
> 17 IDLE
> 
> 
> # cat 20070909-234323-10517.out
> ...
> 12 OK Idle completed.
> 13 OK List completed.
> 14 OK Create completed.
> 15 OK Subscribe completed.
> * LIST (\NoInferiors \UnMarked) "/" "Drafts"
> 16 OK List completed.
> + idling
And two new logfiles were created:
> # cat 20070909-234439-10531.in
> 3 select "Drafts"
> 4 IDLE
> 
> 
> # cat 20070909-234439-10531.out
> * OK [RAWLOG TIMESTAMP] 2007-09-09 23:44:39
> * FLAGS (\Answered \Flagged \Deleted \Seen \Draft)
> * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft \*)] Flags
permitted.
> * 0 EXISTS
> * 0 RECENT
> * OK [UIDVALIDITY 1189370254] UIDs valid
> * OK [UIDNEXT 1] Predicted next UID
> 3 OK [READ-WRITE] Select completed.
> + idling
Please note that I start Dovecot using inetd:
> imap    stream  tcp     nowait  root    /usr/sbin/tcpd
/usr/lib/dovecot/imap-login
> imaps   stream  tcp     nowait  root    /usr/sbin/tcpd
/usr/lib/dovecot/imap-login --ssl
> pop3    stream  tcp     nowait  root    /usr/sbin/tcpd
/usr/lib/dovecot/pop3-login
> pop3s   stream  tcp     nowait  root    /usr/sbin/tcpd
/usr/lib/dovecot/pop3-login --ssl
> Doesn't Dovecot use /var/mail/$user then as the INBOX if
> the .imap_mail/inbox doesn't exist?
Yes, it seems so but its not a problem for me because the mails get
snarfed later on.

Here is the config:
> # dovecot -n
> # 1.0.5: /etc/dovecot/dovecot.conf
> log_path: /var/log/dovecot/dovecot.main
> log_timestamp: %Y-%m-%d %H:%M:%S
> protocols: imap imaps pop3 pop3s
> login_dir: /var/run/dovecot/login
> login_executable(default): /usr/lib/dovecot/imap-login
> login_executable(imap): /usr/lib/dovecot/imap-login
> login_executable(pop3): /usr/lib/dovecot/pop3-login
> mail_extra_groups: mail
> mail_location: mbox:~/.imap_mail:INDEX=/var/mail/indexes/%u
> mail_executable(default): /usr/lib/dovecot/rawlog /usr/lib/dovecot/imap
> mail_executable(imap): /usr/lib/dovecot/rawlog /usr/lib/dovecot/imap
> mail_executable(pop3): /usr/lib/dovecot/pop3
> mail_plugins(default): quota imap_quota
> mail_plugins(imap): quota imap_quota
> mail_plugins(pop3):
> mail_plugin_dir(default): /usr/lib/dovecot/modules/imap
> mail_plugin_dir(imap): /usr/lib/dovecot/modules/imap
> mail_plugin_dir(pop3): /usr/lib/dovecot/modules/pop3
> imap_client_workarounds(default): outlook-idle netscape-eoh
tb-extra-mailbox-sep delay-newmail
> imap_client_workarounds(imap): outlook-idle netscape-eoh
tb-extra-mailbox-sep delay-newmail
> imap_client_workarounds(pop3): outlook-idle
> pop3_uidl_format(default):
> pop3_uidl_format(imap):
> pop3_uidl_format(pop3): %08Xv%08Xu
> auth default:
>   passdb:
>     driver: pam
>   userdb:
>     driver: passwd
> plugin:
>   quota: fs
Greetings, Bernd Kuhls

Hi,

Timo Sirainen wrote:
> On Tue, 2007-08-07 at 12:21 +0200, Bernd Kuhls wrote:
>> Now I create a new message in Thunderbird and save it as draft. A zero
>> byte file "Drafts" is created in /home/$user/.imap_mail/ but
the message
>> I wanted to save got _lost_, /home/$user/.imap_mail/Drafts stays at
zero
>> bytes. The next message I try to save as draft finds its way to the
Drafts
>> mbox however.
> 
> Did you check what commands Thunderbird sends? Use e.g. rawlog
> (http://dovecot.org/bugreport.html). I don't think snarf plugin should
> cause this, and in general I can't think of a bug in Dovecot that would
> cause this.
I reproduced the bug with Dovecot 1.0.5 without snarf plugin and it
happened again.

The user I used is "kuhls2", its home is /home/kuhls2, the mail folder
(mbox format) is "/home/kuhls2/.imap_mail". This directory does not
exist when I started my tests with a fresh install of Thunderbird
2.0.0.6 on Windows XP. I need this scenario working because I am about
to switch from a working UW-IMAP install using /var/mail/$USER to
Dovecot using "$HOME/.imap_mail/". Saved mails should not get lost
with
the new setup.

After setting up Thunderbird with IMAP/SSL access I connected to the
Dovecot server and logged in, .imap_mail looks like this after login:
> bach:/home/kuhls2/dovecot.rawlog# ls -la ../.imap_mail/
> total 12
> -rw------- 1 kuhls2 worker    0 2007-09-09 22:49 inbox
> -rw------- 1 kuhls2 worker    6 2007-09-09 22:49 .subscriptions
> -rw------- 1 kuhls2 worker    0 2007-09-09 22:49 Trash
These files were created during the first login with Thunderbird, note
that neither a mbox "Drafts" is created nor is it visible in
Thunderbirds folder list, which is ok.

Here is the rawlog of this transaction:
> # cat 20070909-234323-10517.in
> 3 namespace
> 4 lsub "" "*"
> 5 list "" "INBOX"
> 6 list "" "Trash"
> 7 create "Trash"
> 8 subscribe "Trash"
> 9 list "" "Trash"
> 10 select "INBOX"
> 11 getquotaroot "INBOX"
> 12 IDLE
> 
> # cat 20070909-234323-10517.out
> * OK [RAWLOG TIMESTAMP] 2007-09-09 23:43:23
> * NAMESPACE (("" "/")) NIL NIL
> 3 OK Namespace completed.
> 4 OK Lsub completed.
> * LIST (\NoInferiors \UnMarked) "/" "INBOX"
> 5 OK List completed.
> 6 OK List completed.
> 7 OK Create completed.
> 8 OK Subscribe completed.
> * LIST (\NoInferiors \UnMarked) "/" "Trash"
> 9 OK List completed.
> * FLAGS (\Answered \Flagged \Deleted \Seen \Draft)
> * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft \*)] Flags
permitted.
> * 0 EXISTS
> * 0 RECENT
> * OK [UIDVALIDITY 1189369511] UIDs valid
> * OK [UIDNEXT 1] Predicted next UID
> 10 OK [READ-WRITE] Select completed.
> * QUOTAROOT "INBOX" ""
> * QUOTA "" (STORAGE 84 0)
> 11 OK Getquotaroot completed.
> + idling
Then I started to write a new mail and saved it as Draft, mbox Drafts
gets created with 0 byte length, no error message in Dovecot logfile nor
in Thunderbird, the mail content was not saved at all:
> bach:/home/kuhls2/dovecot.rawlog# ls -la ../.imap_mail/
> total 12
> -rw------- 1 kuhls2 worker    0 2007-09-09 22:51 Drafts
> -rw------- 1 kuhls2 worker    0 2007-09-09 22:49 inbox
> -rw------- 1 kuhls2 worker   13 2007-09-09 22:51 .subscriptions
> -rw------- 1 kuhls2 worker    0 2007-09-09 22:49 Trash
> bach:/home/kuhls2/dovecot.rawlog# cat ../.imap_mail/.subscriptions
> Trash
> Drafts
Here is the rawlog when saving the mail into drafts folder.
The first two log files had some lines added:
> # cat 20070909-234323-10517.in
> ...
> DONE
> 13 list "" "Drafts"
> 14 create "Drafts"
> 15 subscribe "Drafts"
> 16 list "" "Drafts"
> 17 IDLE
> 
> 
> # cat 20070909-234323-10517.out
> ...
> 12 OK Idle completed.
> 13 OK List completed.
> 14 OK Create completed.
> 15 OK Subscribe completed.
> * LIST (\NoInferiors \UnMarked) "/" "Drafts"
> 16 OK List completed.
> + idling
And two new logfiles were created:
> # cat 20070909-234439-10531.in
> 3 select "Drafts"
> 4 IDLE
> 
> 
> # cat 20070909-234439-10531.out
> * OK [RAWLOG TIMESTAMP] 2007-09-09 23:44:39
> * FLAGS (\Answered \Flagged \Deleted \Seen \Draft)
> * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft \*)] Flags
permitted.
> * 0 EXISTS
> * 0 RECENT
> * OK [UIDVALIDITY 1189370254] UIDs valid
> * OK [UIDNEXT 1] Predicted next UID
> 3 OK [READ-WRITE] Select completed.
> + idling
Please note that I start Dovecot using inetd:
> imap    stream  tcp     nowait  root    /usr/sbin/tcpd
/usr/lib/dovecot/imap-login
> imaps   stream  tcp     nowait  root    /usr/sbin/tcpd
/usr/lib/dovecot/imap-login --ssl
> pop3    stream  tcp     nowait  root    /usr/sbin/tcpd
/usr/lib/dovecot/pop3-login
> pop3s   stream  tcp     nowait  root    /usr/sbin/tcpd
/usr/lib/dovecot/pop3-login --ssl
> Doesn't Dovecot use /var/mail/$user then as the INBOX if
> the .imap_mail/inbox doesn't exist?
Yes, it seems so but its not a problem for me because the mails get
snarfed later on.

Here is the config:
> # dovecot -n
> # 1.0.5: /etc/dovecot/dovecot.conf
> log_path: /var/log/dovecot/dovecot.main
> log_timestamp: %Y-%m-%d %H:%M:%S
> protocols: imap imaps pop3 pop3s
> login_dir: /var/run/dovecot/login
> login_executable(default): /usr/lib/dovecot/imap-login
> login_executable(imap): /usr/lib/dovecot/imap-login
> login_executable(pop3): /usr/lib/dovecot/pop3-login
> mail_extra_groups: mail
> mail_location: mbox:~/.imap_mail:INDEX=/var/mail/indexes/%u
> mail_executable(default): /usr/lib/dovecot/rawlog /usr/lib/dovecot/imap
> mail_executable(imap): /usr/lib/dovecot/rawlog /usr/lib/dovecot/imap
> mail_executable(pop3): /usr/lib/dovecot/pop3
> mail_plugins(default): quota imap_quota
> mail_plugins(imap): quota imap_quota
> mail_plugins(pop3):
> mail_plugin_dir(default): /usr/lib/dovecot/modules/imap
> mail_plugin_dir(imap): /usr/lib/dovecot/modules/imap
> mail_plugin_dir(pop3): /usr/lib/dovecot/modules/pop3
> imap_client_workarounds(default): outlook-idle netscape-eoh
tb-extra-mailbox-sep delay-newmail
> imap_client_workarounds(imap): outlook-idle netscape-eoh
tb-extra-mailbox-sep delay-newmail
> imap_client_workarounds(pop3): outlook-idle
> pop3_uidl_format(default):
> pop3_uidl_format(imap):
> pop3_uidl_format(pop3): %08Xv%08Xu
> auth default:
>   passdb:
>     driver: pam
>   userdb:
>     driver: passwd
> plugin:
>   quota: fs
Greetings, Bernd Kuhls