dovecot - Jul 2009 - Newbie: unable to access mailbox more than once

Hello,

I'm using dovecot as a mail relay so that I can back up my providers 
IMAP mail locally. I'm impressed how easy this was to set up, but I'm 
having a quirk that I would like help with, if possible.

There are many weak links in my set-up chain, if you will, but I think 
I've narrowed the problem. I'll describe my set-up anyway. I'm
running
dovecot 1.1.4 on ubuntu 8.10. I have a shared NAS drive running a NFS 
server. I have chosen to store the .indexes and .control directories on 
the NAS also, since I want a set-up that will remain backed up and 
easily replicated if I (accidentally) erase the ubuntu install in the 
future.

I'm using imapsync to copy messages from my email provider. It works 
once only, and subsequent attempts seem to hang when accessing any local 
dovecot mailbox folders that were changed last time.

I have succeeded in using Thunderbird to access the dovecot mailboxes once.

I know the paths are being found, because I can 'list' mailboxes when I 
telnet locally:

b list "" *
* LIST (\HasNoChildren) "." "Trash"
* LIST (\HasNoChildren) "." "Drafts"
* LIST (\HasNoChildren) "." "indexes"
* LIST (\HasNoChildren) "." "control"
* LIST (\HasNoChildren) "." "Junk"
* LIST (\HasNoChildren) "." "Sent"
* LIST (\HasNoChildren) "." "INBOX"
* LIST (\HasNoChildren) "." "Trash-1000"
b OK List completed.

However, a 'select' command will only work for empty folders (such as 
.Trash). If I try to select a full folder such as ".Sent" then the 
process just hangs.

The logs don't mention anything interesting, even though I have enabled 
debug_on and auth_debug.

However, I attached a trace to the 'imap' process and got something 
interesting. I think maybe the lock process is failing for some reason? 
Here's a snip of the failure when selecting the .Sent folder:

12:00:21.190011 gettimeofday({1248141621, 190099}, NULL) = 0
12:00:21.190503 read(0, "f select Sent\r\n", 4034) = 15
12:00:21.190906 stat64("/mnt/Mail/.Sent/tmp", {st_mode=S_IFDIR|0700, 
st_size=4096, ...}) = 0
12:00:21.241561 stat64("/mnt/Mail/.indexes/.Sent", 
{st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
12:00:21.248325 stat64("/mnt/Mail/.Sent/dovecot-shared", 0xbf86c6c8) =
-1 ENOENT (No such file or directory)
12:00:21.248847 time(NULL)              = 1248141621
12:00:21.249060 open("/mnt/Mail/.indexes/.Sent/dovecot.index.log", 
O_RDWR|O_LARGEFILE) = 7
12:00:21.286953 fstat64(7, {st_mode=S_IFREG|0600, st_size=26472, ...}) = 0
12:00:21.287423 pread64(7, 
"\1\0\30\0\264:dJ\4\0\0\0\3\0\0\0\\\200\0\0\374?dJ", 24, 0) = 24
12:00:21.287696 stat64("/mnt/Mail/.indexes/.Sent/dovecot.index.log.2",
0xbf86c5ac) = -1 ENOENT (No such file or directory)
12:00:21.288070 open("/mnt/Mail/.indexes/.Sent/dovecot.index.log.2", 
O_RDWR|O_LARGEFILE) = -1 ENOENT (No such file or directory)
12:00:21.288614 open("/mnt/Mail/.indexes/.Sent/dovecot.index", 
O_RDWR|O_LARGEFILE) = 9
12:00:21.296814 alarm(60)               = 0
12:00:21.297181 fcntl64(9, F_SETLKW64, {type=F_RDLCK, whence=SEEK_SET, 
start=0, len=0}

I have set the locks to dotlock_try followed by fcntl. The trace above 
seemed to fail with the dotlock, and proceed to fcntl?

Here is the output from dovecot -n

# 1.1.4: /etc/dovecot/dovecot.conf
log_path: /var/log/dovecot.log
log_timestamp: %Y-%m-%d %H:%M:%S
login_dir: /var/run/dovecot/login
login_executable: /usr/lib/dovecot/imap-login
login_greeting_capability: yes
mail_max_userip_connections: 0
mail_privileged_group: mail
mail_location: 
maildir:/mnt/Mail:INBOX=/mnt/Mail/.INBOX:INDEX=/mnt/Mail/.indexes/:CONTROL=/mnt/Mail/.control
mail_debug: yes
mail_full_filesystem_access: yes
mmap_disable: yes
dotlock_use_excl: no
mail_nfs_storage: yes
mail_nfs_index: yes
lock_method: dotlock
maildir_stat_dirs: yes
mbox_read_locks: dotlock_try fcntl
mbox_write_locks: dotlock_try fcntl
imap_client_workarounds: tb-extra-mailbox-sep
auth default:
  verbose: yes
  debug: yes
  passdb:
    driver: pam
  userdb:
    driver: passwd


Sorry if this is a long post. The summary, I guess, is that I can't 
access mailbox folders with emails inside. I'm very new at all this, and 
only got this far from the excellent wiki. But now I'm stumped.

Thanks heaps,
Matt P

I can fix the problem by deleting the index files for each non-compliant
mailbox. eg: /.indexes/.Sent/dovecot.index

Dovecot then recreates the index files. The ownership and permissions of the new
& deleted indexes are the same.

However, these index files soon get corrupted. I think it might be imapsync
corrupting them because I can access the mail using Thunderbird, and run
imapsync successfully *once* (again), but after that the index files appear to
be corrupt because the mailbox stops allowing access until I delete the index
files again.

Anyone have any experience with index files becoming corrupted or inaccessible?
Maybe I should try moving them off the network drive....


cheers
matt p

On Wed, 2009-07-22 at 13:50 +1000, Matt Petoe wrote:
> 12:00:21.297181 fcntl64(9, F_SETLKW64, {type=F_RDLCK, whence=SEEK_SET, 
> start=0, len=0}
> 
> I have set the locks to dotlock_try followed by fcntl. The trace above 
> seemed to fail with the dotlock, and proceed to fcntl?
..
> mbox_read_locks: dotlock_try fcntl
> mbox_write_locks: dotlock_try fcntl
1) This setting means that it uses BOTH dotlock_try and fcntl. You
probably want to set it to just "dotlock".

2) The mbox_*_locks settings affect only when locking mbox. It doesn't
affect index file locking, which is where the above strace hangs. So you
should also set "lock_method = dotlock".

In any case there's something wrong in your NFS setup's lockd. It just
shouldn't be hanging there.

As for looking at the index file contents, you could use "idxview" to
look at dovecot.index and "logview" to look at dovecot.index.log
files.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 197 bytes
Desc: This is a digitally signed message part
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20090726/17f64f40/attachment-0002.bin>

Ahhh, okay - I presumed that 'dotlock_try' required something else to 
'try' after....

Replacing 'dotlock_try fnctl' with just 'dotlock_try' seems to
have
fixed my problem.

The idxview & logview tools are useful to learn about. Thanks.

thanks again
matt p


Timo Sirainen wrote:
> On Wed, 2009-07-22 at 13:50 +1000, Matt Petoe wrote:
>   
>> 12:00:21.297181 fcntl64(9, F_SETLKW64, {type=F_RDLCK, whence=SEEK_SET, 
>> start=0, len=0}
>>
>> I have set the locks to dotlock_try followed by fcntl. The trace above 
>> seemed to fail with the dotlock, and proceed to fcntl?
>>     
> ..
>   
>> mbox_read_locks: dotlock_try fcntl
>> mbox_write_locks: dotlock_try fcntl
>>     
>
> 1) This setting means that it uses BOTH dotlock_try and fcntl. You
> probably want to set it to just "dotlock".
>
> 2) The mbox_*_locks settings affect only when locking mbox. It doesn't
> affect index file locking, which is where the above strace hangs. So you
> should also set "lock_method = dotlock".
>
> In any case there's something wrong in your NFS setup's lockd. It
just
> shouldn't be hanging there.
>
> As for looking at the index file contents, you could use
"idxview" to
> look at dovecot.index and "logview" to look at dovecot.index.log
files.
>