I upgraded from 1.1 to 1.2 a couple months ago and now we are seeing this:
Aug 20 05:34:38 kelly dovecot: auth(default): auth workers: Auth request
was queued for 7 seconds, 10 left in queue
...
Aug 20 05:34:38 kelly dovecot: auth(default): BUG: Worker sent reply
with id 53, expected 54
Aug 20 05:34:38 kelly dovecot: auth(default):
worker-server(xxx at example.com,dd.dd.dd.dd): Aborted: Worker is buggy
Aug 20 05:34:38 kelly dovecot: auth(default):
passdb(xxx at example.com,dd.dd.dd.dd): Fallbacking to expired data from cache
When I attempt to restart dovecot there is one dovecot-auth process that
won't die and keeps the server from starting. A simple 'killall
dovecot-auth' takes care of it and the server is able to start. I'm not
using anything exotic, dovecot config below.
The most curious fact is that we have identical servers running the same
version of dovecot (1.2.3, happened under 1.2.1 as well) talking to the
same MySQL database and both develop the problem at the same time. The
database is under considerable stress at the time this occurs as the
policyd tables are being cleaned. But this happens twice per hour and
only sometimes does dovecot have trouble. I'm working to move the
policyd database elsewhere, but of course this shouldn't happen in any case.
Any help would be much appreciated. Thanks!
David
# 1.2.3: /etc/dovecot/dovecot.conf
# OS: Linux 2.6.9-42.0.10.ELsmp i686 Red Hat Enterprise Linux ES release
4 (Nahant Update 7)
protocols: imap imaps pop3 pop3s
ssl_cert_file: /etc/dovecot/dovecot.pem
ssl_key_file: /etc/dovecot/dovecot.pem
ssl_cipher_list: ALL:!LOW:!SSLv2
disable_plaintext_auth: no
login_dir: /usr/local/dovecot-1.2/var/run/dovecot/login
login_executable(default): /usr/local/dovecot-1.2/libexec/dovecot/imap-login
login_executable(imap): /usr/local/dovecot-1.2/libexec/dovecot/imap-login
login_executable(pop3): /usr/local/dovecot-1.2/libexec/dovecot/pop3-login
login_process_per_connection: no
verbose_proctitle: yes
first_valid_uid: 89
maildir_stat_dirs: yes
mail_executable(default): /usr/local/dovecot-1.2/libexec/dovecot/imap
mail_executable(imap): /usr/local/dovecot-1.2/libexec/dovecot/imap
mail_executable(pop3): /usr/local/dovecot-1.2/libexec/dovecot/pop3
mail_plugins(default): quota imap_quota
mail_plugins(imap): quota imap_quota
mail_plugins(pop3): quota
mail_plugin_dir(default): /usr/local/dovecot-1.2/lib/dovecot/imap
mail_plugin_dir(imap): /usr/local/dovecot-1.2/lib/dovecot/imap
mail_plugin_dir(pop3): /usr/local/dovecot-1.2/lib/dovecot/pop3
pop3_uidl_format(default): %08Xu%08Xv
pop3_uidl_format(imap): %08Xu%08Xv
pop3_uidl_format(pop3): %f
pop3_client_workarounds(default):
pop3_client_workarounds(imap):
pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh
lda:
postmaster_address: postmaster at no-ip.com
hostname: no-ip.com
mail_plugins: quota
auth_socket_path: /var/run/dovecot/auth-master
auth default:
mechanisms: login plain cram-md5
cache_size: 5000
cache_ttl: 1800
cache_negative_ttl: 60
user: nobody
username_chars: abcdefghijklmnopqrstuvwxyz
ABCDEFGHIJKLMNOPQRSTUVWXYZ01234567890.-_@
username_translation: %@
username_format: %TLu
verbose: yes
passdb:
driver: sql
args: /etc/dovecot/dovecot-sql.conf
userdb:
driver: prefetch
userdb:
driver: sql
args: /etc/dovecot/dovecot-sql.conf
socket:
type: listen
master:
path: /var/run/dovecot/auth-master
mode: 384
user: vmail
group: vmail
plugin:
quota: dict:user:%LTd-%LTn:proxy::quota
quote_rule: *:storage=100G
dict:
quota: mysql:/etc/dovecot/dovecot-dict-sql.conf
## dovecot-sql.conf
driver = mysql
connect = host=192.168.dd.dd dbname=xxx user=xxx password=xxx
user_query=...
password_query=...
## dovecot-dict-sql.conf
connect = host=192.168.dd.dd dbname=xxx user=xxx password=xxx
map {
pattern = priv/quota/storage
table = quota2
username_field = username
value_field = bytes
}
map {
pattern = priv/quota/messages
table = quota2
username_field = username
value_field = messages
}
On Thu, 2009-08-20 at 08:03 -0700, David Jonas wrote:> Aug 20 05:34:38 kelly dovecot: auth(default): BUG: Worker sent reply > with id 53, expected 54http://hg.dovecot.org/dovecot-1.2/rev/0827941c0e7c fixes it, I think. -------------- 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/20090824/148e8da5/attachment-0002.bin>
On 8/24/09 , Aug 24, 11:10 AM, Timo Sirainen wrote:> On Thu, 2009-08-20 at 08:03 -0700, David Jonas wrote: > >> Aug 20 05:34:38 kelly dovecot: auth(default): BUG: Worker sent reply >> with id 53, expected 54 >> > http://hg.dovecot.org/dovecot-1.2/rev/0827941c0e7c fixes it, I think. > >Applied to 1.2.4. It may be a long time until it happens again since I've moved the slow databases, but I'll try to break the old version and the patched version and post the results. Thanks, David