dovecot - Jun 2012 - doveadm purge -A via doveadm-proxy director fails after some users

Hi,

we have configured userdb and passdb in the director and try to  
iterate all users and pass the "purge" command via doveadm proxy to  
port 19000 on the correct director backend host.

A single purge -u username at example.org via doveadm-proxy works correctly,
but iterating over some users with -A fails.

Note: users/domains have been anonymized in output:

------------------------------------------------------------------------

mail04:~# /usr/bin/doveadm -c  
/etc/dovecot-director/dovecot-director.conf -D purge -A 2>&1
doveadm(root): Debug: Loading modules from directory:  
/usr/lib/dovecot/modules/doveadm
doveadm(root): Debug: Skipping module doveadm_acl_plugin, because  
dlopen() failed:  
/usr/lib/dovecot/modules/doveadm/lib10_doveadm_acl_plugin.so:  
undefined symbol: acl_user_module (this is usually intentional, so  
just ignore this message)
doveadm(root): Debug: Skipping module doveadm_expire_plugin, because  
dlopen() failed:  
/usr/lib/dovecot/modules/doveadm/lib10_doveadm_expire_plugin.so:  
undefined symbol: expire_set_lookup (this is usually intentional, so  
just ignore this message)
doveadm(root): Debug: Skipping module doveadm_quota_plugin, because  
dlopen() failed:  
/usr/lib/dovecot/modules/doveadm/lib10_doveadm_quota_plugin.so:  
undefined symbol: quota_user_module (this is usually intentional, so  
just ignore this message)
doveadm(root): Debug: Skipping module doveadm_zlib_plugin, because  
dlopen() failed:  
/usr/lib/dovecot/modules/doveadm/lib10_doveadm_zlib_plugin.so:  
undefined symbol: i_stream_create_deflate (this is usually  
intentional, so just ignore this message)
doveadm(root): Debug: Skipping module doveadm_fts_plugin, because  
dlopen() failed:  
/usr/lib/dovecot/modules/doveadm/lib20_doveadm_fts_plugin.so:  
undefined symbol: fts_list_backend (this is usually intentional, so  
just ignore this message)
doveadm(user01 at domain1.example.org): Debug: auth input:  
user=user01 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user02 at domain1.example.org): Debug: auth input:  
user=user02 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user03 at domain1.example.org): Debug: auth input:  
user=user03 at domain1.example.org proxy host=10.129.3.192  
proxy_refresh=86400
doveadm(user04 at domain1.example.org): Debug: auth input:  
user=user04 at domain1.example.org proxy host=10.129.3.192  
proxy_refresh=86400
doveadm(user05 at domain1.example.org): Debug: auth input:  
user=user05 at domain1.example.org proxy host=10.129.3.190  
proxy_refresh=86400
doveadm(user06 at domain1.example.org): Debug: auth input:  
user=user06 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user07 at domain1.example.org): Debug: auth input:  
user=user07 at domain1.example.org proxy host=10.129.3.190  
proxy_refresh=86400
doveadm(user08 at domain1.example.org): Debug: auth input:  
user=user08 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user01 at domain2.example.org): Debug: auth input:  
user=user01 at domain2.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user09 at domain1.example.org): Debug: auth input:  
user=user09 at domain1.example.org proxy host=10.129.3.190  
proxy_refresh=86400
10 / 94doveadm(user10 at domain1.example.org): Debug: auth input:  
user=user10 at domain1.example.org proxy host=10.129.3.190  
proxy_refresh=86400
doveadm(user11 at domain1.example.org): Debug: auth input:  
user=user11 at domain1.example.org proxy host=10.129.3.191  
proxy_refresh=86400
doveadm(user12 at domain1.example.org): Debug: auth input:  
user=user12 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user13 at domain1.example.org): Debug: auth input:  
user=user13 at domain1.example.org proxy host=10.129.3.190  
proxy_refresh=86400
doveadm(user14 at domain1.example.org): Debug: auth input:  
user=user14 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user15 at domain1.example.org): Debug: auth input:  
user=user15 at domain1.example.org proxy host=10.129.3.191  
proxy_refresh=86400
doveadm(user16 at domain1.example.org): Debug: auth input:  
user=user16 at domain1.example.org proxy host=10.129.3.191  
proxy_refresh=86400
doveadm(user17 at domain1.example.org): Debug: auth input:  
user=user17 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user18 at domain1.example.org): Debug: auth input:  
user=user18 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user19 at domain1.example.org): Debug: auth input:  
user=user19 at domain1.example.org proxy host=10.129.3.192  
proxy_refresh=86400
20 / 94doveadm(user20 at domain1.example.org): Debug: auth input:  
user=user20 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user21 at domain1.example.org): Debug: auth input:  
user=user21 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user22 at domain1.example.org): Debug: auth input:  
user=user22 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user02 at domain2.example.org): Debug: auth input:  
user=user02 at domain2.example.org proxy host=10.129.3.190  
proxy_refresh=86400
doveadm(user23 at domain1.example.org): Debug: auth input:  
user=user23 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user24 at domain1.example.org): Debug: auth input:  
user=user24 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user01 at domain3.example.org): Debug: auth input:  
user=user01 at domain3.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user25 at domain1.example.org): Debug: auth input:  
user=user25 at domain1.example.org proxy host=10.129.3.192  
proxy_refresh=86400
doveadm(user26 at domain1.example.org): Debug: auth input:  
user=user26 at domain1.example.org proxy host=10.129.3.191  
proxy_refresh=86400
doveadm(user27 at domain1.example.org): Debug: auth input:  
user=user27 at domain1.example.org proxy host=10.129.3.190  
proxy_refresh=86400
30 / 94doveadm(user28 at domain1.example.org): Debug: auth input:  
user=user28 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user29 at domain1.example.org): Debug: auth input:  
user=user29 at domain1.example.org proxy host=10.129.3.191  
proxy_refresh=86400
doveadm(user30 at domain1.example.org): Debug: auth input:  
user=user30 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user31 at domain1.example.org): Debug: auth input:  
user=user31 at domain1.example.org proxy host=10.129.3.193  
proxy_refresh=86400
doveadm(user31 at domain1.example.org): Error: doveadm server failure

doveadm: Error: Failed to iterate through some users

------------------------------------------------------------------------

The user "user31 at domain1.example.org" is proxied to the correct  
backend host according to director status, but the dovecot.log on the  
doveadm service
backend host shows the following error:

Jun 29 15:40:31 10.129.3.249 dovecot:  
doveadm(user31 at domain1.example.org): Error: user  
user31 at domain1.example.org: Error reading configuration:  
net_connect_unix(/var/run/dovecot/config) failed: Permission denied
Jun 29 15:40:31 10.129.3.249 dovecot:  
doveadm(user31 at domain1.example.org): Error: purge: User lookup failed:  
Internal error occurred. Refer to server log for more information.

The wiki http://wiki2.dovecot.org/Services#doveadm states that the  
privileges are (temporarily) dropped to the mail user's privileges  
after userdb lookup. It seems that from the second purge on which is  
passed over a single doveadm connection, the user lookup fails.

It also seems a bit strange, that the "-A" parameter
can be observed in the doveadm tcp stream to the backend,
since iteration should be already done in the director and
the backend should purge only a single user:

D username at example.org purge -A

Is there a bug or have I misconfigured/overlooked something?

Configs of mailbox backend and director are attached.

Kind regards
Daniel
-------------- next part --------------
# 2.1.7: /etc/dovecot/dovecot.conf
# OS: Linux 2.6.32-40-server x86_64 Ubuntu 10.04.4 LTS 
auth_cache_negative_ttl = 0
auth_cache_size = 10 M
auth_cache_ttl = 1 mins
auth_verbose = yes
auth_verbose_passwords = sha1
deliver_log_format = mailbox: deliver: msgid=%m from=%f: %$
dict {
  quota = mysql:/etc/dovecot/conf.d/dovecot-dict-sql.conf.ext
}
disable_plaintext_auth = no
doveadm_password = xxx
instance_name = dovecot-mailbox
lda_mailbox_autocreate = yes
lda_mailbox_autosubscribe = yes
login_greeting = Mailbox
login_log_format = mailbox: login: %$: %s
login_trusted_networks = 10.129.3.0/24
mail_debug = yes
mail_fsync = always
mail_gid = vmail
mail_home = /mail/dovecot/%d/%n
mail_location = mdbox:~/mail
mail_log_prefix = "mailbox: mail: %s(%u): "
mail_plugins = quota
mail_privileged_group = vmail
mail_uid = vmail
managesieve_implementation_string = Sieve
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
mdbox_rotate_interval = 1 weeks
mdbox_rotate_size = 50 M
mmap_disable = yes
namespace {
  hidden = yes
  list = no
  location = pop3c:
  prefix = POP3-MIGRATION-NS/
}
passdb {
  args = /etc/dovecot/conf.d/dovecot-sql.conf.ext
  driver = sql
}
plugin {
  pop3_migration_mailbox = POP3-MIGRATION-NS/INBOX
  quota = dict:User quota::proxy::quota
  quota_rule = *:storage=10G
  quota_rule2 = Trash:storage=+100M
  quota_warning = storage=95%% quota-warning 95 %u
  quota_warning2 = storage=80%% quota-warning 80 %u
  sieve = ~/.dovecot.sieve
  sieve_dir = ~/sieve
}
protocols = imap pop3 lmtp sieve
service auth {
  unix_listener auth-userdb {
    group = dovecot
    mode = 0660
    user = dovecot
  }
}
service dict {
  unix_listener dict {
    group = vmail
    mode = 0660
  }
}
service doveadm {
  inet_listener doveadm-server {
    port = 19000
  }
}
service imap-login {
  inet_listener imap {
    port = 19143
  }
}
service imap-postlogin {
  executable = script-login /usr/local/bin/dovecot-postlogin
  user = $default_internal_user
}
service imap {
  executable = imap imap-postlogin
}
service lmtp {
  inet_listener lmtp {
    address = *
    port = 19024
  }
}
service managesieve-login {
  inet_listener sieve {
    port = 19200
  }
}
service pop3-login {
  inet_listener pop3 {
    port = 19110
  }
}
service pop3-postlogin {
  executable = script-login /usr/local/bin/dovecot-postlogin
  user = $default_internal_user
}
service pop3 {
  executable = pop3 pop3-postlogin
}
service quota-warning {
  executable = script /usr/local/bin/quota-warning
  extra_groups = dovecot
  unix_listener quota-warning {
    user = vmail
  }
  user = vmail
}
ssl = no
userdb {
  driver = prefetch
}
userdb {
  args = /etc/dovecot/conf.d/dovecot-sql.conf.ext
  driver = sql
}
verbose_proctitle = yes
protocol imap {
  imap_client_workarounds = delay-newmail tb-extra-mailbox-sep
  mail_plugins = quota imap_quota
}
protocol lmtp {
  mail_plugins = quota sieve
}
protocol doveadm {
  mail_plugins = quota pop3_migration
}
-------------- next part --------------
# 2.1.7: /etc/dovecot-director/dovecot-director.conf
# OS: Linux 2.6.32-40-server x86_64 Ubuntu 10.04.4 LTS 
auth_verbose = yes
auth_verbose_passwords = sha1
base_dir = /var/run/dovecot-director
deliver_log_format = director: deliver: msgid=%m from=%f: %$
director_doveadm_port = 20000
director_mail_servers = 10.129.3.193 10.129.3.192 10.129.3.191 10.129.3.190
director_servers = 10.129.3.193 10.129.3.192 10.129.3.191 10.129.3.190
director_user_expire = 2 days
disable_plaintext_auth = no
doveadm_password = xxx
doveadm_proxy_port = 19000
instance_name = dovecot-director
lmtp_proxy = yes
login_greeting = Mail Balancer
login_log_format = director: login: %$: %s
login_trusted_networks = 10.129.3.0/24
mail_debug = yes
mail_fsync = always
mail_gid = vmail
mail_home = /mail/dovecot/%d/%n
mail_location = mdbox:~/mail
mail_log_prefix = "director: mail: %s(%u): "
mail_privileged_group = vmail
mail_uid = vmail
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
mmap_disable = yes
passdb {
  args = /etc/dovecot-director/conf.d/dovecot-sql.conf.ext
  driver = sql
}
protocols = imap pop3 lmtp sieve
service auth {
  unix_listener auth-userdb {
    user = dovecot
  }
}
service director {
  fifo_listener login/proxy-notify {
    mode = 0666
  }
  inet_listener {
    port = 9090
  }
  unix_listener director-userdb {
    mode = 0600
  }
  unix_listener login/director {
    mode = 0666
  }
}
service doveadm {
  executable = doveadm-server director
  inet_listener doveadm-server {
    port = 20000
  }
}
service imap-login {
  executable = imap-login director
  inet_listener imap {
    port = 20143
  }
  inet_listener imaps {
    port = 20993
    ssl = yes
  }
}
service lmtp {
  inet_listener lmtp {
    address = *
    port = 20024
  }
}
service managesieve-login {
  executable = managesieve-login director
  inet_listener sieve {
    port = 20200
  }
}
service pop3-login {
  executable = pop3-login director
  inet_listener pop3 {
    port = 20110
  }
  inet_listener pop3s {
    port = 20995
    ssl = yes
  }
}
ssl_cert = </etc/certs/wildcard.crt
ssl_key = </etc/certs/wildcard.key
userdb {
  driver = prefetch
}
userdb {
  args = /etc/dovecot-director/conf.d/dovecot-sql.conf.ext
  driver = sql
}
verbose_proctitle = yes
protocol lmtp {
  auth_socket_path = director-userdb
}
protocol sieve {
  auth_socket_path = director-userdb
}
protocol doveadm {
  auth_socket_path = director-userdb
}
protocol imap {
  imap_client_workarounds = delay-newmail tb-extra-mailbox-sep
}

On 29.6.2012, at 19.21, Daniel Parthey wrote:
> Jun 29 15:40:31 10.129.3.249 dovecot: doveadm(user31 at
domain1.example.org): Error: user user31 at domain1.example.org: Error reading
configuration: net_connect_unix(/var/run/dovecot/config) failed: Permission
denied
I've noticed a similar problem happening somewhat randomly, but I still
haven't looked into why exactly it happens. Anyway the attached patch should
fix this specific error, but I'm not sure if there isn't another one.
Try and let me know? :)

-------------- next part --------------
A non-text attachment was scrubbed...
Name: diff
Type: application/octet-stream
Size: 449 bytes
Desc: not available
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20120703/e9d2af9c/attachment-0004.obj>

Timo Sirainen wrote:
> On 29.6.2012, at 19.21, Daniel Parthey wrote:
> 
> > Jun 29 15:40:31 10.129.3.249 dovecot: doveadm(user31 at
domain1.example.org):
> > Error: user user31 at domain1.example.org: Error reading
configuration:
> > net_connect_unix(/var/run/dovecot/config) failed: Permission denied
> 
> I've noticed a similar problem happening somewhat randomly, but I still
> haven't looked into why exactly it happens. Anyway the attached patch
should
> fix this specific error, but I'm not sure if there isn't another
one. Try and
> let me know? :)
Unfortunately, the problem still persists with dovecot 2.1.8,
which already contains the following code:

enum master_service_flags service_flags MASTER_SERVICE_FLAG_KEEP_CONFIG_OPEN;
const char *error;
master_service = master_service_init("doveadm", service_flags,
&argc, &argv, NULL);
if (master_getopt(master_service) > 0)
return FATAL_DEFAULT;

The command
/usr/bin/doveadm -c /etc/dovecot-director/dovecot-director.conf -D purge -A
still generates the following errors after iterating some dozen users:

doveadm(nagios at metaways.de): Error: doveadm server failure
doveadm: Error: Failed to iterate through some users

Which information should I provide to help debugging the problem?

Kind regards
Daniel
-- 
https://plus.google.com/103021802792276734820