[Dovecot] error in logs, but system appears to work
I'm bringing up a system with dovecot that has been running for years with uw-imap. In making the switch, I put a tail on the log file, made the switch, and sent a test mail and received it. I was able to receive mail with no apparent difficulties, but the log file was disconcerting. A number of users connected during the few minutes I had it running, and for each of them there was an error, e.g., "chown ~user/mail/.imap/INBOX failed: Operation not permitted" and "mkdir ~user/mail/.imap/INBOX failed: not owner". But those directories and files appeared to have been made. The first of those errors finishes with "group based on /var/mail/user". That makes no sense.
I'm hoping someone can give me an idea what might cause this.
Here are the log entries in debug mode and the directories for one such user:
Sep 2 17:31:33 eclogite dovecot: [ID 583609 local2.info] auth(default): new auth connection: pid=7248 Sep 2 17:31:43 eclogite dovecot: [ID 583609 local2.info] auth(default): client in: AUTH 1 PLAIN service=pop3 secured lip=128.119.45.20 rip=128.119.45.9 lport=995 rport=53865 resp=AGVicmFkbGV5AFJvd2luZzEzKg== Sep 2 17:31:43 eclogite dovecot: [ID 583609 local2.info] auth(default): shadow(ebradley,128.119.45.9): lookup Sep 2 17:31:43 eclogite dovecot: [ID 583609 local2.info] auth(default): client out: OK 1 user=ebradley Sep 2 17:31:43 eclogite dovecot: [ID 583609 local2.info] auth(default): master in: REQUEST 37 7248 1 Sep 2 17:31:43 eclogite dovecot: [ID 583609 local2.info] auth(default): passwd(ebradley,128.119.45.9): lookup Sep 2 17:31:43 eclogite dovecot: [ID 583609 local2.info] auth(default): master out: USER 37 ebradley system_groups_user=ebradley uid=6633 gid=100 home=/u1/home/grad/ebradley Sep 2 17:31:43 eclogite dovecot: [ID 583609 local2.info] POP3(ebradley): Effective uid=6633, gid=100, home=/u1/home/grad/ebradley Sep 2 17:31:43 eclogite dovecot: [ID 583609 local2.info] POP3(ebradley): mbox: data=~/mail:INBOX=/var/mail/ebradley Sep 2 17:31:43 eclogite dovecot: [ID 583609 local2.info] POP3(ebradley): fs: root=/u1/home/grad/ebradley/mail, index=, control=, inbox=/var/mail/ebradley Sep 2 17:31:43 eclogite dovecot: [ID 583609 local2.info] POP3(ebradley): Namespace : Using permissions from /u1/home/grad/ebradley/mail: mode=0700 gid=-1 Sep 2 17:31:43 eclogite dovecot: [ID 583609 local2.error] POP3(ebradley): chown(/u1/home/grad/ebradley/mail/.imap/INBOX, -1, 6(mail)) failed: Operation not permitted (egid=100(geolgrad), group based on /var/mail/ebradley) Sep 2 17:31:43 eclogite dovecot: [ID 583609 local2.error] POP3(ebradley): mkdir(/u1/home/grad/ebradley/mail/.imap/INBOX) failed: Not owner Sep 2 17:31:43 eclogite dovecot: [ID 583609 local2.info] pop3-login: Login: user=<ebradley>, method=PLAIN, rip=128.119.45.9, lip=128.119.45.20, TLS
When I looked at their home directory, I found:
drwx------ 4 ebradley geolgrad 512 Jul 28 2009 /u1/home/grad/ebradley drwx------ 4 ebradley geolgrad 512 Sep 2 17:31 /u1/home/grad/ebradley/mail drwx------ 3 ebradley geolgrad 512 Sep 2 17:31 /u1/home/grad/ebradley/mail/.imap drwxrwx--- 2 ebradley geolgrad 512 Sep 2 17:31 /u1/home/grad/ebradley/mail/.imap/INBOX
-rw-rw---- 1 ebradley mail 9484323 Sep 6 15:16 /var/mail/ebradley
My dovecot configuration is at the end. The other pieces are sendmail, milter-greylist, mimedefang, etc.
--
Chris Hoogendyk
- O__ ---- Systems Administrator c/ /'_ --- Biology& Geology Departments (*) \(*) -- 140 Morrill Science Center
<hoogendyk@bio.umass.edu>
---------------
Erdös 4
# dovecot -a
# 1.2.17: /usr/local/etc/dovecot.conf
Warning: fd limit 256 is lower than what Dovecot can use under full load (more than 768). Either grow the limit or change login_max_processes_count and max_mail_processes settings
# OS: SunOS 5.9 sun4u
base_dir: /var/run/dovecot/
log_path:
info_log_path:
log_timestamp: %b %d %H:%M:%S
syslog_facility: local2
protocols: imaps pop3s
listen: *
ssl_listen: *
ssl: required
ssl_ca_file: /etc/mail/certs/ca-bundle.crt
ssl_cert_file: /etc/mail/certs/sendmail.pem
ssl_key_file: /etc/mail/certs/sendmail.pem
ssl_key_password:
ssl_parameters_regenerate: 168
ssl_cipher_list:
ssl_cert_username_field: commonName
ssl_verify_client_cert: no
disable_plaintext_auth: yes
verbose_ssl: no
shutdown_clients: yes
nfs_check: yes
version_ignore: no
login_dir: /var/run/dovecot/login
login_executable(default): /usr/local/libexec/dovecot/imap-login
login_executable(imap): /usr/local/libexec/dovecot/imap-login
login_executable(pop3): /usr/local/libexec/dovecot/pop3-login
login_user: dovecot
login_greeting: ready.
login_log_format_elements: user=<%u> method=%m rip=%r lip=%l %c
login_log_format: %$: %s
login_process_per_connection: yes
login_chroot: yes
login_trusted_networks:
login_process_size: 64
login_processes_count: 3
login_max_processes_count: 128
login_max_connections: 256
valid_chroot_dirs:
mail_chroot:
max_mail_processes: 512
mail_max_userip_connections(default): 10
mail_max_userip_connections(imap): 10
mail_max_userip_connections(pop3): 3
verbose_proctitle: no
first_valid_uid: 1000
last_valid_uid: 0
first_valid_gid: 98
last_valid_gid: 0
mail_access_groups:
mail_privileged_group: mail
mail_uid:
mail_gid:
mail_location: mbox:~/mail:INBOX=/var/mail/%u
mail_cache_fields:
mail_never_cache_fields: imap.envelope
mail_cache_min_mail_count: 0
mailbox_idle_check_interval: 30
mail_debug: yes
mail_full_filesystem_access: no
mail_max_keyword_length: 50
mail_save_crlf: no
mmap_disable: no
dotlock_use_excl: yes
fsync_disable: no
mail_nfs_storage: no
mail_nfs_index: no
mailbox_list_index_disable: yes
lock_method: fcntl
maildir_stat_dirs: no
maildir_copy_with_hardlinks: yes
maildir_copy_preserve_filename: no
maildir_very_dirty_syncs: no
mbox_read_locks: fcntl
mbox_write_locks: dotlock fcntl
mbox_lock_timeout: 300
mbox_dotlock_change_timeout: 120
mbox_min_index_size: 0
mbox_dirty_syncs: yes
mbox_very_dirty_syncs: no
mbox_lazy_writes: yes
dbox_rotate_size: 2048
dbox_rotate_min_size: 16
dbox_rotate_days: 1
mail_drop_priv_before_exec: no
mail_executable(default): /usr/local/libexec/dovecot/imap
mail_executable(imap): /usr/local/libexec/dovecot/imap
mail_executable(pop3): /usr/local/libexec/dovecot/pop3
mail_process_size: 256
mail_plugins:
mail_plugin_dir(default): /usr/local/lib/dovecot/imap
mail_plugin_dir(imap): /usr/local/lib/dovecot/imap
mail_plugin_dir(pop3): /usr/local/lib/dovecot/pop3
mail_log_prefix: %Us(%u):
mail_log_max_lines_per_sec: 10
imap_max_line_length: 65536
imap_capability:
imap_client_workarounds:
imap_logout_format: bytes=%i/%o
imap_id_send:
imap_id_log:
imap_idle_notify_interval: 120
pop3_no_flag_updates: no
pop3_enable_last: no
pop3_reuse_xuidl(default): no
pop3_reuse_xuidl(imap): no
pop3_reuse_xuidl(pop3): yes
pop3_save_uidl: no
pop3_lock_session: no
pop3_uidl_format(default): %08Xu%08Xv
pop3_uidl_format(imap): %08Xu%08Xv
pop3_uidl_format(pop3): %08Xv%08Xu
pop3_client_workarounds(default):
pop3_client_workarounds(imap):
pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh
pop3_logout_format: top=%t/%p, retr=%r/%b, del=%d/%m, size=%s
dict_db_config:
dict_process_count: 1
auth default:
mechanisms: plain
realms:
default_realm:
cache_size: 0
cache_ttl: 3600
cache_negative_ttl: 3600
executable: /usr/local/libexec/dovecot/dovecot-auth
user: root
chroot:
username_chars: abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ01234567890.-_
username_translation:
username_format:
master_user_separator:
anonymous_username: anonymous
krb5_keytab:
gssapi_hostname:
winbind_helper_path: /usr/bin/ntlm_auth
failure_delay: 2
verbose: yes
debug: yes
debug_passwords: yes
ssl_require_client_cert: no
ssl_username_from_cert: no
use_winbind: no
count: 1
worker_max_count: 30
process_size: 256
passdb:
driver: shadow
args:
deny: no
pass: no
master: no
userdb:
driver: passwd
args:
#
On 6.9.2011, at 22.35, Chris Hoogendyk wrote:
-rw-rw---- 1 ebradley mail 9484323 Sep 6 15:16 /var/mail/ebradley
Is there any reason for this to be 0660? Most likely not, so your problem goes away simply with chmod 0600 /var/mail/* and at the same time makes your system more secure.
On 9/6/11 3:51 PM, Timo Sirainen wrote:
On 6.9.2011, at 22.35, Chris Hoogendyk wrote:
-rw-rw---- 1 ebradley mail 9484323 Sep 6 15:16 /var/mail/ebradley Is there any reason for this to be 0660? Most likely not, so your problem goes away simply with chmod 0600 /var/mail/* and at the same time makes your system more secure.
So, looking at my other system that has been running dovecot for over a year, I see that the entries are mostly 0600, but there are a few 0660. The system I was just implementing has mostly 0660, but some 0600. We had seen occasional similar errors on the other system.
If I change both systems so that all the directories in /var/mail are 0600, then everything will be happy?
--
Chris Hoogendyk
- O__ ---- Systems Administrator c/ /'_ --- Biology& Geology Departments (*) \(*) -- 140 Morrill Science Center
<hoogendyk@bio.umass.edu>
---------------
Erdös 4
On 6.9.2011, at 23.09, Chris Hoogendyk wrote:
On 9/6/11 3:51 PM, Timo Sirainen wrote:
On 6.9.2011, at 22.35, Chris Hoogendyk wrote:
-rw-rw---- 1 ebradley mail 9484323 Sep 6 15:16 /var/mail/ebradley Is there any reason for this to be 0660? Most likely not, so your problem goes away simply with chmod 0600 /var/mail/* and at the same time makes your system more secure.
So, looking at my other system that has been running dovecot for over a year, I see that the entries are mostly 0600, but there are a few 0660. The system I was just implementing has mostly 0660, but some 0600. We had seen occasional similar errors on the other system.
If I change both systems so that all the directories in /var/mail are 0600, then everything will be happy?
Yep. Basically the problem is that Dovecot thinks they are shared mailboxes and the "mail" group is supposed to have access to them, so it tries to use the mail group for the index files as well, but the process doesn't belong to mail group so it fails.
participants (2)
-
Chris Hoogendyk
-
Timo Sirainen