[Dovecot] stats + fts squat plugins, indexer-worker error on message indexing

[David Warden]

On RHEL 6.2 + dovecot 2.1.5 with the stats and fts (squat) plugins enabled and each user having their own uid on the system I get the following error in the logs when the indexer-worker process indexes some messages:

Apr 25 09:56:19 wardentest3 dovecot: imap-login: Login: user=warden, method=PLAIN, rip=137.238.60.164, lip=137.238.2.240, lport=1993, mpid=19464, encryption=TLS
Apr 25 09:56:26 wardentest3 dovecot: service=indexer-worker user=warden rip= Indexed 12 messages in INBOX
Apr 25 09:56:26 wardentest3 dovecot: service=indexer-worker user=warden rip= Error: open(/proc/self/io) failed: Permission denied
Apr 25 09:56:29 wardentest3 dovecot: service=imap user=warden rip=137.238.60.164 Disconnected: Logged out bytes(in/out)=46/780

What I did to generate the above was remove the squat indexes for my Inbox then log in via telnet and search for a string in my Inbox, which forced an index of the messages in my Inbox.

Based on http://wiki2.dovecot.org/Services#indexer-worker it seems like this is because the indexer-worker process is created as root but at the time of indexing the indexer-worker drops privs to the mail user. In /proc/<indexer-worker pid>/, io is mode 0400 and owned by root, so it makes sense that the mail user would be unable to read that file.

The strange thing is it looks like the stats are still collected (unless I am reading the output of the stats dump incorrectly):

[root at wardentest3 mailtest]# doveadm stats dump -s /var/run/dovecot/mailtest/stats command user=warden
cmd	args	session	user	last_update	user_cpu	sys_cpu	min_faults	maj_faults	vol_cs	invol_cs	disk_input	disk_output	read_count	read_bytes	write_count	write_bytes	mail_lookup_path	mail_lookup_attr	mail_read_count	mail_read_bytes	mail_cache_hits
select	inbox	27fb87218302984f084c0000ae899e04	warden	1335362182.950250	0.000000	0.000000	172	0	46	0	0	12288	13	7883	4	381	0	0	0	0	0
search	text "warden"	27fb87218302984f084c0000ae899e04	warden	1335362186.588023	0.001000	0.000000	32	0	4	1	0	0	4	108	1	43	0	0	0	0	0
logout		27fb87218302984f084c0000ae899e04	warden	1335362189.161790	0.000000	0.000000	1	0	0	3	0	0	1	108	3	157	0	0	0	0	0

This obviously isn't a show-stopper but if this is causing stats to be incorrect it would be great if this could be fixed.

-David Warden

My doveconf -n:

# 2.1.5: /etc/dovecot/mailtest/dovecot.conf
doveconf: Warning: service auth { client_limit=4096 } is lower than required under max. load (12288)
doveconf: Warning: service anvil { client_limit=4096 } is lower than required under max. load (12291)
# OS: Linux 2.6.32-220.7.1.el6.x86_64 x86_64 Red Hat Enterprise Linux Server release 6.2 (Santiago) nfs
auth_cache_negative_ttl = 0
auth_cache_size = 16 M
auth_gssapi_hostname = $ALL
auth_krb5_keytab = /etc/dovecot/mailtest.combined.keytab
auth_master_user_separator = *
auth_mechanisms = plain login gssapi
auth_username_format = %Ln
base_dir = /var/run/dovecot/mailtest/
default_client_limit = 4096
default_process_limit = 4096
deliver_log_format = msgid="%m" subject="%s" from="%f" size=%p result="%$"
first_valid_uid = 0
hostname = mailtest.geneseo.edu
instance_name = mailtest
lda_mailbox_autocreate = yes
lda_mailbox_autosubscribe = yes
login_log_format_elements = user=%u method=%m rip=%r lip=%l lport=%a mpid=%e encryption=%c
mail_fsync = always
mail_location = maildir:/Mail/mailhome/%Ln/mailtest/Maildir:CONTROL=/Mail/mailhome/%Ln/mailtest/.dovecot-control:INDEX=/Mail/mailhome/%Ln/mailtest/.dovecot-index
mail_log_prefix = "service=%s user=%u rip=%r "
mail_nfs_index = yes
mail_nfs_storage = yes
mail_plugins = zlib quota mail_log notify fts fts_squat stats
maildir_very_dirty_syncs = yes
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date ihave
mbox_write_locks = fcntl
mmap_disable = yes
namespace default {
  inbox = yes
  location = 
  mailbox Drafts {
    auto = subscribe
    special_use = \Drafts
  }
  mailbox Junk {
    auto = no
    special_use = \Junk
  }
  mailbox Sent {
    auto = subscribe
    special_use = \Sent
  }
  mailbox Trash {
    auto = subscribe
    special_use = \Trash
  }
  prefix = 
  separator = .
  type = private
}
passdb {
  args = /etc/dovecot/passwd.masterusers
  driver = passwd-file
  master = yes
}
passdb {
  args = cache_key=%u dovecot
  driver = pam
}
plugin {
  fts = squat
  mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename flag_change append
  mail_log_fields = uid box msgid size from subject flags
  mail_log_group_events = yes
  quota = maildir:User quota
  quota_exceeded_message = Quota exceeded (mailbox for user is full). Please see http://go.geneseo.edu/emailoverquota for help deleting messages while over quota.
  quota_rule = *:storage=200M
  quota_rule2 = Trash:storage=+50M
  sieve = /Mail/mailhome/%Ln/mailtest/.filter.sieve
  sieve_dir = /Mail/mailhome/%Ln/mailtest/.sievedir
  sieve_max_redirects = 25
  stats_memory_limit = 32 M
  stats_refresh = 30 secs
  stats_track_cmds = yes
}
postmaster_address = postmaster at geneseo.edu
protocols = imap sieve lmtp
quota_full_tempfail = yes
service auth {
  unix_listener auth-exim {
    group = exim
    mode = 0660
  }
}
service imap-login {
  inet_listener imap {
    port = 1143
  }
  inet_listener imaps {
    port = 1993
  }
  service_count = 0
  vsz_limit = 256 M
}
service imap {
  process_limit = 4096
}
service lmtp {
  inet_listener lmtp {
    port = 124
  }
}
service managesieve-login {
  inet_listener sieve {
    port = 14190
  }
  inet_listener sieve_deprecated {
    port = 12000
  }
}
service pop3 {
  process_limit = 4096
}
service stats {
  fifo_listener stats-mail {
    mode = 0666
  }
}
ssl_ca = </etc/pki/tls/certs/geotrust-intermediate.pem
ssl_cert = </etc/pki/tls/certs/wildcard-geotrust.geneseo.edu.pem
ssl_key = </etc/pki/tls/private/wildcard-geotrust.geneseo.edu.key
userdb {
  driver = passwd
}
verbose_proctitle = yes
protocol lmtp {
  mail_plugins = zlib quota mail_log notify fts fts_squat stats sieve
}
protocol lda {
  mail_location = maildir:/Mail/mailhome/%Ln/mailtest/Maildir:CONTROL=/Mail/mailhome/%Ln/mailtest/.dovecot-control:INDEX=/Mail/mailhome/%Ln/mailtest/.dovecot-index
  mail_plugins = zlib quota mail_log notify fts fts_squat stats sieve
  plugin {
    quota = maildir:User quota
    quota_rule = *:storage=200M
    quota_rule2 = Trash:storage=+50M
    zlib_save = gz
    zlib_save_level = 6
  }
}
protocol imap {
  imap_logout_format = bytes(in/out)=%i/%o
  mail_max_userip_connections = 50
  mail_plugins = zlib quota mail_log notify fts fts_squat stats imap_quota autocreate imap_zlib imap_stats
}
protocol sieve {
  managesieve_logout_format = bytes(in/out)=%i/%o
}
protocol pop3 {
  pop3_client_workarounds = outlook-no-nuls oe-ns-eoh
  pop3_logout_format = bytes(in/out)=%i/%o, top=%t/%p, retr=%r/%b, del=%d/%m, mailbox-size=%s
  pop3_uidl_format = UID%u-%v
}
remote 137.238.0.0/16/16 {
  disable_plaintext_auth = no
}