[Dovecot] nfs flush/fsync config settings problem

[Troton_admin]

Hi,

I need to place a maildir storage on a NFS filesystem, so I set up the config like this:

mmap_disable = yes
mail_nfs_storage = yes
mail_nfs_index = yes
mail_fsync = always
lock_method = dotlock (also tried fcntl - local lockd is running, no success, now using dotlock, to be sure while debugging)

The problem is that Dovecot (2.2.9/2.2.10 - the relevant code in mail-index.c is the same) logs a fatal error and quits the session (no daemon crash/coredump).

Jan 07 14:13:31 auth: Debug: client in: AUTH    1       PLAIN   service=pop3    session=fRCRJGHvbADDUKU9        lip=192.168.100.102     rip=IP_ADDR       lport=1110      rport=48236     resp=AHRyb3RvbjEAdHJvdG9uMQ== (previous base64 data may contain sensitive data)
Jan 07 14:13:31 auth: Debug: passwd-file(troton1,IP_ADDR,<fRCRJGHvbADDUKU9>): lookup: user=troton1 file=/usr/local/etc/dovecot/passwd-file
Jan 07 14:13:31 auth: Debug: client passdb out: OK      1       user=troton1
Jan 07 14:13:31 auth: Debug: master in: REQUEST 1289355265      29049   1       4f9fdd9e4069fa503e8e6bcc09d4cf30        session_pid=29089
Jan 07 14:13:31 auth: Debug: passwd-file(troton1,IP_ADDR,<fRCRJGHvbADDUKU9>): lookup: user=troton1 file=/usr/local/etc/dovecot/passwd-file
Jan 07 14:13:31 auth: Debug: master userdb out: USER    1289355265      troton1 uid=81  gid=81  home=/home/troton1      mail=maildir:~/Maildir
Jan 07 14:13:31 pop3-login: Info: Login: user=<troton1>, method=PLAIN, rip=IP_ADDR, lip=192.168.100.102, mpid=29089, session=<fRCRJGHvbADDUKU9>
Jan 07 14:13:31 pop3: Debug: Added userdb setting: mail=maildir:~/Maildir
Jan 07 14:13:31 pop3(troton1): Debug: Effective uid=81, gid=81, home=/home/troton1
Jan 07 14:13:31 pop3(troton1): Debug: Namespace inbox: type=private, prefix=, sep=., inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir
Jan 07 14:13:31 pop3(troton1): Debug: maildir++: root=/home/troton1/Maildir, index=, indexpvt=, control=, inbox=/home/troton1/Maildir, alt=
Jan 07 14:13:31 pop3(troton1): Info: DEBUG1: fsync_mode=2 , mask=0
Jan 07 14:13:31 pop3(troton1): Info: DEBUG2: fsync_mode=2 flags=85
Jan 07 14:13:31 pop3(troton1): Debug: Namespace : Using permissions from /home/troton1/Maildir: mode=0700 gid=default
Jan 07 14:13:31 pop3(troton1): Info: DEBUG2: fsync_mode=0 flags=85

The user/passdb is just a plaintext file, for debugging purposes.

But what is strange, the messages system log shows:
Jan  7 14:13:31 mailhub2 dovecot: pop3(troton1): Fatal: nfs flush requires mail_fsync=always

That is obviously wrong, even its own doveconf -n utility shows the correct value.

# doveconf -n | grep -E 'sync|nfs'
mail_fsync = always
mail_nfs_index = yes
mail_nfs_storage = yes
maildir_very_dirty_syncs = yes

Affected code seems to be in the lib-index/mail-index.c file, mail_index_file function - around line 585 :

	// my custom debug line
       i_info("DEBUG2: fsync_mode=%u flags=%u", (unsigned int)(index->fsync_mode),(unsigned int)flags);
 
        if ((flags & MAIL_INDEX_OPEN_FLAG_NFS_FLUSH) != 0 &&
            index->fsync_mode != FSYNC_MODE_ALWAYS)
                i_fatal("nfs flush requires mail_fsync=always");

The first time it sees fsync_mode=2 (which is correct value of FSYNC_MODE_ALWAYS), but next function call is with index->fsync_mode=0 and an error is raised, see the logfile above.

Dovecot correctly creates its working files in user's home directory - dovecot-uidlist, dovecot-uidvalidity, dovecot-uidvalidity.52cbfd7b, dovecot.index.log .

The complete (testing, not production) doveconf -n is:
==
# 2.2.10: /usr/local/etc/dovecot/dovecot.conf
# OS: FreeBSD 7.3-RELEASE-p3 amd64  
auth_debug = yes
auth_debug_passwords = yes
auth_mechanisms = plain login
auth_verbose = yes
auth_verbose_passwords = sha1
default_process_limit = 200
disable_plaintext_auth = no
first_valid_uid = 81
imap_client_workarounds = delay-newmail tb-extra-mailbox-sep
info_log_path = /var/log/dovecot.log
last_valid_uid = 81
listen = 192.168.100.102
lock_method = dotlock
mail_debug = yes
mail_fsync = always
mail_gid = 81
mail_location = maildir:%h/Maildir
mail_nfs_index = yes
mail_nfs_storage = yes
mail_prefetch_count = 5
mail_uid = 81
mailbox_list_index = yes
maildir_stat_dirs = yes
maildir_very_dirty_syncs = yes
mmap_disable = yes
namespace inbox {
  inbox = yes
  location = 
  mailbox Sent {
    special_use = \Sent
  }
  mailbox "Sent Messages" {
    special_use = \Sent
  }
  mailbox Trash {
    special_use = \Trash
  }
  prefix = 
  separator = .
  type = private
}
passdb {
  args = scheme=plain username_format=%n /usr/local/etc/dovecot/passwd-file
  driver = passwd-file
}
plugin {
  mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename
  mail_log_fields = uid box msgid subject size
}
pop3_enable_last = yes
pop3_save_uidl = yes
protocols = imap pop3
service doveadm {
  inet_listener {
    port = 9292
  }
}
service imap-login {
  inet_listener imap {
    port = 1143
  }
}
service imap {
  process_limit = 250
}
service pop3-login {
  inet_listener pop3 {
    port = 1110
  }
}
service pop3 {
  process_limit = 200
}
ssl = no
userdb {
  args = username_format=%n /usr/local/etc/dovecot/passwd-file
  default_fields = uid=81 gid=0 home=/home/%n
  driver = passwd-file
}
protocol imap {
  mail_max_userip_connections = 5
}
protocol pop3 {
  mail_max_userip_connections = 5
}
==
OS: 7.3-RELEASE-p3 FreeBSD 7.3-RELEASE-p3 #1 amd64
Affected Dovecot version: 2.2.9, 2.2.10
How to repeat: Anytime I enter the correct username/pass pair

And I tried to place the homedir on a local disk too, and I got the same error as on NFS.
Any ideas, what could possibly be wrong ?
Is it a feature or a bug ?

Thanks for your help.
Regards,
Troton