Weird problem with user folders

Mon Jan 26 04:23:08 EST 2004

[sending this message third time, let's see if it passes through]

Weird things are happening with my cyrus test installation. It seems that 
some users can change and create folders as normal, but some can not. I 
have been unable to determine anything common linking these problematic 
and non-problematic users.

This is hard to explain but I'll try. I have used 2 imap clients: mutt and
pine. Let's start with mutt.

When "working" user logs in and tries to change folder (keys c and ? 
pressed in mutt) mutt displays folder list and lets user choose folder 
(INBOX.toinen in this example) without problems. Logs related to this case 
look like this:

---8<---
Jan 23 15:48:25 torakka1 master[20335]: about to exec /v/net/imap.cc.jyu.fi/cyrus/bin/imapd
Jan 23 15:48:25 torakka1 imap[20335]: executed
Jan 23 15:48:25 torakka1 imapd[20335]: accepted connection
Jan 23 15:48:25 torakka1 imapd[20335]: mystore: starting txn 2147483667
Jan 23 15:48:25 torakka1 imapd[20335]: mystore: committing txn 2147483667
Jan 23 15:48:25 torakka1 imapd[20335]: starttls: TLSv1 with cipher AES256-SHA (256/256 bits new) no authentication
Jan 23 15:48:33 torakka1 imapd[20335]: login: localhost.localdomain[127.0.0.1] tjt plaintext+TLS
Jan 23 15:48:33 torakka1 imapd[20335]: seen_db: user tjt opened /v/net/imap.cc.jyu.fi/var/user/t/tjt.seen
Jan 23 15:48:33 torakka1 imapd[20335]: open: user tjt opened INBOX
Jan 23 15:49:11 torakka1 imapd[20335]: open: user tjt opened INBOX.toinen
---8<---

Also creating new folder in mutt (c,?,C) works fine.

Then, using problematic user account and trying to change folders (c,?)
results in mutt opening new connection and asking login/pass again. This
happens 3 times (first after ?, second after choosing INBOX. tree and
third when opening folder).

---8<---
Jan 23 15:53:54 torakka1 master[20345]: about to exec /v/net/imap.cc.jyu.fi/cyrus/bin/imapd
Jan 23 15:53:54 torakka1 imap[20345]: executed
Jan 23 15:53:54 torakka1 imapd[20345]: accepted connection
Jan 23 15:53:54 torakka1 imapd[20345]: mystore: starting txn 2147483679
Jan 23 15:53:54 torakka1 imapd[20345]: mystore: committing txn 2147483679
Jan 23 15:53:54 torakka1 imapd[20345]: starttls: TLSv1 with cipher AES256-SHA (256/256 bits new) no authentication
Jan 23 15:53:58 torakka1 imapd[20345]: login: localhost.localdomain[127.0.0.1] aapo plaintext+TLS
Jan 23 15:53:58 torakka1 imapd[20345]: seen_db: user aapo opened /v/net/imap.cc.jyu.fi/var/user/a/aapo.seen
Jan 23 15:53:58 torakka1 imapd[20345]: open: user aapo opened INBOX
Jan 23 15:54:02 torakka1 master[20346]: about to exec /v/net/imap.cc.jyu.fi/cyrus/bin/imapd
Jan 23 15:54:02 torakka1 imap[20346]: executed
Jan 23 15:54:02 torakka1 imapd[20346]: accepted connection
Jan 23 15:54:02 torakka1 imapd[20346]: mystore: starting txn 2147483684
Jan 23 15:54:02 torakka1 imapd[20346]: mystore: committing txn 2147483684
Jan 23 15:54:02 torakka1 imapd[20346]: starttls: TLSv1 with cipher AES256-SHA (256/256 bits new) no authentication
Jan 23 15:54:07 torakka1 imapd[20346]: login: localhost.localdomain[127.0.0.1] aapo plaintext+TLS
Jan 23 15:54:08 torakka1 master[20347]: about to exec /v/net/imap.cc.jyu.fi/cyrus/bin/imapd
Jan 23 15:54:08 torakka1 imap[20347]: executed
Jan 23 15:54:08 torakka1 imapd[20347]: accepted connection
Jan 23 15:54:08 torakka1 imapd[20347]: mystore: starting txn 2147483689
Jan 23 15:54:08 torakka1 imapd[20347]: mystore: committing txn 2147483689
Jan 23 15:54:08 torakka1 imapd[20347]: starttls: TLSv1 with cipher AES256-SHA (256/256 bits new) no authentication
Jan 23 15:54:13 torakka1 imapd[20347]: login: localhost.localdomain[127.0.0.1] aapo plaintext+TLS
Jan 23 15:54:18 torakka1 master[20348]: about to exec /v/net/imap.cc.jyu.fi/cyrus/bin/imapd
Jan 23 15:54:18 torakka1 imap[20348]: executed
Jan 23 15:54:18 torakka1 imapd[20348]: accepted connection
Jan 23 15:54:18 torakka1 imapd[20348]: mystore: starting txn 2147483694
Jan 23 15:54:18 torakka1 imapd[20348]: mystore: committing txn 2147483694
Jan 23 15:54:18 torakka1 imapd[20348]: starttls: TLSv1 with cipher AES256-SHA (256/256 bits new) no authentication
Jan 23 15:54:22 torakka1 imapd[20348]: login: localhost.localdomain[127.0.0.1] aapo plaintext+TLS
Jan 23 15:54:22 torakka1 imapd[20348]: seen_db: user aapo opened /v/net/imap.cc.jyu.fi/var/user/a/aapo.seen
Jan 23 15:54:22 torakka1 imapd[20348]: open: user aapo opened INBOX.testi
---8<---

Same things happen with pine, it asks login 3 times. With working user
pine doesn't ask login more than 1 time.

With problem user mutt refuses to create new folders, pressing C results
always in new connection and nothing else. Pine still creates folders, but
asks login every time 2 times.

I have tried to debug this a lot and searched mailing list, but have found
nothing. So please, if someone could tell me what's going wrong, i'd be
very happy.

Here is my cyrus imapd.conf:

---8<---
postmaster: postmaster
configdirectory: /v/net/imap.cc.jyu.fi/var
partition-default: /v/net/imap.cc.jyu.fi/var/spool/imap
sasl_saslauthd_path: /v/net/imap.cc.jyu.fi/var/run/saslauthd/mux
sasl_pwcheck_method: saslauthd
lmtp_admins: lmtpadmin
admins: cyrus
allowanonymouslogin: no
allowplaintext: yes
sasl_mech_list: PLAIN
servername: torakka1.cc.jyu.fi
autocreatequota: 10000
reject8bit: no
quotawarn: 90
timeout: 30
poptimeout: 10
sievedir: /v/net/imap.cc.jyu.fi/sieve
sendmail: /usr/sbin/sendmail
sieve_maxscriptsize: 32
sieve_maxscripts: 5
tls_ca_file: /v/net/imap.cc.jyu.fi/var/imap/server.pem
tls_cert_file: /v/net/imap.cc.jyu.fi/var/imap/server.pem
tls_key_file: /v/net/imap.cc.jyu.fi/var/imap/server.pem
---8<---

I also have tried logging to /v/net/imap.cc.jyu.fi/var/log/<user>, but the 
logs have revealed nothing. Everything is identical between working and 
non-working user, as long as it comes to listing folders.

Working user:
---8<---
>1074868578>a0003 OK User logged in
<1074868578<a0004 LIST "" ""
>1074868578>* LIST (\Noselect) "." ""
a0004 OK Completed (0.000 secs 0 calls)
<1074868578<a0005 SELECT "INBOX"
>1074868578>* FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
* OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)]
* 0 EXISTS
* 0 RECENT
* OK [UIDVALIDITY 1074864825]
* OK [UIDNEXT 1]
a0005 OK [READ-WRITE] Completed
<1074868578<a0006 MYRIGHTS "INBOX"
>1074868578>* MYRIGHTS INBOX lrswipcda
a0006 OK Completed
<1074868578<a0007 NOOP
>1074868578>a0007 OK Completed
<1074868581<a0008 NAMESPACE
>1074868581>* NAMESPACE (("INBOX." ".")) (("user." ".")) (("" "."))
a0008 OK Completed
<1074868581<a0009 LIST "" "INBOX.%"
>1074868581>* LIST (\HasNoChildren) "." "INBOX.kolmas"
* LIST (\HasNoChildren) "." "INBOX.toinen"
a0009 OK Completed (0.010 secs 3 calls)
<1074868581<a0010 LIST "" "user.%"
>1074868581>a0010 OK Completed (0.000 secs 1 calls)
<1074868581<a0011 LIST "" "%"
>1074868581>* LIST (\HasChildren) "." "INBOX"
a0011 OK Completed (0.000 secs 4 calls)
<1074868583<a0012 LIST "" "INBOX.%"
>1074868583>* LIST (\HasNoChildren) "." "INBOX.kolmas"
* LIST (\HasNoChildren) "." "INBOX.toinen"
a0012 OK Completed (0.000 secs 3 calls)
<1074868585<a0013 CLOSE
>1074868585>a0013 OK Completed
<1074868586<a0014 SELECT "INBOX.toinen"
>1074868586>* FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
* OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)]
* 0 EXISTS
* 0 RECENT
* OK [UIDVALIDITY 1074864843]
* OK [UIDNEXT 1]
a0014 OK [READ-WRITE] Completed
<1074868586<a0015 MYRIGHTS "INBOX.toinen"
>1074868586>* MYRIGHTS INBOX.toinen lrswipcda
a0015 OK Completed
<1074868587<a0016 CLOSE
>1074868587>a0016 OK Completed
<1074868587<a0017 LOGOUT
>1074868587>* BYE LOGOUT received
a0017 OK Completed
---8<---

And non-working user, first connection:
---8<---
>1074868859>a0003 OK User logged in
<1074868859<a0004 LIST "" ""
>1074868859>* LIST (\Noselect) "." ""
a0004 OK Completed (0.000 secs 0 calls)
<1074868859<a0005 SELECT "INBOX"
>1074868859>* FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
* OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)]
* 0 EXISTS
* 0 RECENT
* OK [UIDVALIDITY 1074862204]
* OK [UIDNEXT 1]
a0005 OK [READ-WRITE] Completed
<1074868859<a0006 MYRIGHTS "INBOX"
>1074868859>* MYRIGHTS INBOX lrswipcda
a0006 OK Completed
<1074868859<a0007 NOOP
>1074868859>a0007 OK Completed
---8<---

second connection:
---8<---
>1074868864>a0003 OK User logged in
<1074868864<a0004 LIST "" ""
>1074868864>* LIST (\Noselect) "." ""
a0004 OK Completed (0.000 secs 0 calls)
<1074868864<a0005 NAMESPACE
>1074868864>* NAMESPACE (("INBOX." ".")) (("user." ".")) (("" "."))
a0005 OK Completed
<1074868864<a0006 LIST "" "INBOX.%"
>1074868864>* LIST (\HasNoChildren) "." "INBOX.atoinen"
a0006 OK Completed (0.000 secs 2 calls)
<1074868864<a0007 LIST "" "user.%"
>1074868864>a0007 OK Completed (0.000 secs 1 calls)
<1074868864<a0008 LIST "" "%"
>1074868864>* LIST (\HasChildren) "." "INBOX"
a0008 OK Completed (0.000 secs 3 calls)
---8<---

It looks like working user's client says NAMESPACE when non-working's one
opens new connection in which second command after login and LIST is the
same NAMESPACE, getting same reply. I would blame mutt if it was the only
client, but as pine behaves roughly same way, and with other users they
both work, I cant believe this is client's fault.

I have installed cyrus-imapd 2.1.16 on 3 different redhat 9 and 2 fedora
machines. No difference.

I'm starting to think if I have ate too many red mushrooms ;)