dovecot - Oct 2007 - assertion failed: (mailbox_list_is_valid_existing_name(_list, name))

When I was initially testing dovecot 1.1b2,3 I had ACLs turned on and
encountered
this problem below.  I had them turned off until now, I'll need to have ACLs
working
before I can widen testing.  I'm not sure how to make "env
MAIL=maildir:~/Maildir gdb
/tmp/imap" load the ACL plugin so I assume that is why it does not crash;
not getting
any log either from that, maybe I made a mistake?  But when running mutt, I can
load
it up with the inbox, then when I ask for imap://server/mail/ it crashes with
the
assertion at the bottom.  Let me know if I need to provide more info.  Thanks.

Oct 21 12:57:16 gribble dovecot: imap-login: Login: user=<mcdouga9>,
method=PLAIN,
rip=35.9.44.65, lip=35.9.37.169
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): Loading modules from directory:
/usr/local/lib/dovecot/imap
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): Module loaded: 
/usr/local/lib/dovecot/imap/lib01_acl_plugin.so
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): Module loaded: 
/usr/local/lib/dovecot/imap/lib20_mail_log_plugin.so
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): Effective uid=21281, gid=3002, 
home=/home/mcdouga9
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): Namespace: type=public, 
prefix=#shared/decs/, sep=/, inbox=no, hidden=no, list=yes
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): maildir: 
data=/egr/mail/shared/decs:CONTROL=/home/mcdouga9/Maildir/dovecot11testing/public/control/decs:INDEX=/home/mcdouga9/Maildir/dovecot11testing/public/indexes/decs
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): maildir++:
root=/egr/mail/shared/decs,
index=/home/mcdouga9/Maildir/dovecot11testing/public/indexes/decs, 
control=/home/mcdouga9/Maildir/dovecot11testing/public/control/decs, 
inbox=/egr/mail/shared/decs
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): acl: initializing backend with
data:
vfile:/usr/local/etc/dovecot-acls
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): acl: acl username = mcdouga9
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): acl: owner = 0
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): acl vfile: Global ACL
directory:
/usr/local/etc/dovecot-acls
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): Namespace: type=private,
prefix=mail/,
sep=/, inbox=no, hidden=yes, list=no
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): maildir: 
data=/home/mcdouga9/Maildir:CONTROL=/home/mcdouga9/Maildir/dovecot11testing/private/control:INDEX=/home/mcdouga9/Maildir/dovecot11testing/private/indexes
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): maildir++:
root=/home/mcdouga9/Maildir,
index=/home/mcdouga9/Maildir/dovecot11testing/private/indexes, 
control=/home/mcdouga9/Maildir/dovecot11testing/private/control, 
inbox=/home/mcdouga9/Maildir
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): acl: initializing backend with
data:
vfile:/usr/local/etc/dovecot-acls
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): acl: acl username = mcdouga9
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): acl: owner = 1
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): acl vfile: Global ACL
directory:
/usr/local/etc/dovecot-acls
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): Namespace: type=private,
prefix=, sep=/,
inbox=yes, hidden=no, list=yes
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): maildir: 
data=/home/mcdouga9/Maildir:CONTROL=/home/mcdouga9/Maildir/dovecot11testing/private/control:INDEX=/home/mcdouga9/Maildir/dovecot11testing/private/indexes
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): maildir++:
root=/home/mcdouga9/Maildir,
index=/home/mcdouga9/Maildir/dovecot11testing/private/indexes, 
control=/home/mcdouga9/Maildir/dovecot11testing/private/control, 
inbox=/home/mcdouga9/Maildir
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): acl: initializing backend with
data:
vfile:/usr/local/etc/dovecot-acls
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): acl: acl username = mcdouga9
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): acl: owner = 1
Oct 21 12:57:16 gribble dovecot: IMAP(mcdouga9): acl vfile: Global ACL
directory:
/usr/local/etc/dovecot-acls
Oct 21 12:57:20 gribble dovecot: IMAP(mcdouga9): acl vfile: file 
/usr/local/etc/dovecot-acls//.DEFAULT not found
Oct 21 12:57:20 gribble dovecot: IMAP(mcdouga9): acl vfile: file 
/home/mcdouga9/Maildir/dovecot-acl not found
Oct 21 12:57:20 gribble dovecot: IMAP(mcdouga9): acl vfile: file 
/usr/local/etc/dovecot-acls//.DEFAULT not found
Oct 21 12:57:20 gribble dovecot: IMAP(mcdouga9): acl vfile: file 
/home/mcdouga9/Maildir/dovecot-acl not found
Oct 21 12:57:20 gribble dovecot: IMAP(mcdouga9): file mailbox-list-maildir.c:
line 186
(maildir_list_get_path): assertion failed:
(mailbox_list_is_valid_existing_name(_list,
name))
Oct 21 12:57:20 gribble dovecot: child 72205 (imap) killed with signal 6

On Sun, Oct 21, 2007 at 01:09:43PM -0400, Adam McDougall wrote:

  When I was initially testing dovecot 1.1b2,3 I had ACLs turned on and
encountered
  this problem below.  I had them turned off until now, I'll need to have
ACLs working
  before I can widen testing.  I'm not sure how to make "env
MAIL=maildir:~/Maildir gdb
  /tmp/imap" load the ACL plugin so I assume that is why it does not crash;
not getting
  any log either from that, maybe I made a mistake?  But when running mutt, I
can load
  it up with the inbox, then when I ask for imap://server/mail/ it crashes with
the
  assertion at the bottom.  Let me know if I need to provide more info.  Thanks.
  
  Oct 21 12:57:20 gribble dovecot: IMAP(mcdouga9): acl vfile: file 
  /home/mcdouga9/Maildir/dovecot-acl not found
  Oct 21 12:57:20 gribble dovecot: IMAP(mcdouga9): file mailbox-list-maildir.c:
line 186
  (maildir_list_get_path): assertion failed:
(mailbox_list_is_valid_existing_name(_list,
  name))
  Oct 21 12:57:20 gribble dovecot: child 72205 (imap) killed with signal 6
  
I forgot to mention, heres the command trace:

a0006 LIST "" "mail"
* LIST (\Noselect \HasChildren) "/" "mail"
a0006 OK List completed.
a0007 LIST "" "mail/%"
(disconnected)

On Sun, 2007-10-21 at 13:09 -0400, Adam McDougall wrote:
> When I was initially testing dovecot 1.1b2,3 I had ACLs turned on and
encountered
> this problem below.  I had them turned off until now, I'll need to have
ACLs working
> before I can widen testing.  I'm not sure how to make "env
MAIL=maildir:~/Maildir gdb
> /tmp/imap" load the ACL plugin so I assume that is why it does not
crash;
MAIL=~/Maildir MAIL_PLUGINS=acl ACL=vfile gdb imap

"Running environment" in http://wiki.dovecot.org/PostLoginScripting
explains a bit more.
> Oct 21 12:57:20 gribble dovecot: IMAP(mcdouga9): file
mailbox-list-maildir.c: line 186
> (maildir_list_get_path): assertion failed:
(mailbox_list_is_valid_existing_name(_list,
> name))
I'm not exactly sure how this happens. I tried a few ways to reproduce
it, but it didn't crash. Once you get it working with gdb, could you do
"p name"?

Or you should be able to gdb the core dump as well if you run it with
"dovecot --exec-mail imap". Just make sure you do ulimit -c unlimited
first. The core should get written to home dir.

-------------- 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/20071021/04de9f6e/attachment-0002.bin>

Do you need a gdb backtrace for this one?  

I'm not sure why all of a sudden this started happening, its probably due to
me adding a folder somewhere?  not sure.  It happened when I went to open my
folder subscriptions in thunderbird.  It was taking longer than usual (call this
phase 1) and I noticed this in the logs:

(cant remember if this was phase 1 or 2 but the error is probably the same)
Nov 11 00:38:38 boomhauer dovecot: imap-login: Login: user=<mcdouga9>,
method=PLAIN,
rip=208.53.102.126, lip=35.9.37.190, TLS
Nov 11 00:38:39 boomhauer dovecot: IMAP(mcdouga9): 
fchown(/egr/mail/shared/decs/temp.boomhauer.3050.af3db3ac545170a7) failed:
Operation not
permitted
Nov 11 00:38:44 boomhauer dovecot: IMAP(mcdouga9): file mailbox-list-maildir.c:
line 186
(maildir_list_get_path): assertion failed:
(mailbox_list_is_valid_existing_name(_list,
name))
Nov 11 00:38:44 boomhauer dovecot: child 3050 (imap) killed with signal 6
Nov 11 00:38:45 boomhauer dovecot: imap-login: Login: user=<mcdouga9>,
method=PLAIN,
rip=208.53.102.126, lip=35.9.37.190, TLS
Nov 11 00:38:45 boomhauer dovecot: IMAP(mcdouga9): 
fchown(/egr/mail/shared/decs/temp.boomhauer.3052.5538be060c2f9c7d) failed:
Operation not
permitted
Nov 11 00:38:46 boomhauer dovecot: IMAP(mcdouga9): file mailbox-list-maildir.c:
line 186
(maildir_list_get_path): assertion failed:
(mailbox_list_is_valid_existing_name(_list,
name))
Nov 11 00:38:46 boomhauer dovecot: child 3052 (imap) killed with signal 6

When I cancelled the subscription window, "phase 2" is the same thing
but happening
more rapidly.  I traced what tbird is doing and can reproduce it with:

? OK Logged in.
a list "" "#shared/decs/%/%"
Connection closed by foreign host.


Doing a list on #shared/decs/% works though.