Re: Dovecot 2.4 doveadm_worker_count corrupts tab-formatted output

Some more insights about this issue... It happens every time (on different users) on quota lookup for all users:

$ doveadm quota get -A > /dev/null; echo $?
doveadm([email protected]): Error: auth-master: userdb list: User listing returned failure
doveadm: Error: cmd quota get: Failed to iterate through some users
75

Full debug output see [1].

In mail.log, I then find this line:

dovecot: auth: Error: auth-worker: Aborted LIST request for *: Shutting down

The weird thing is that this problem happens always one one server (2200 users), while never happening on another (1200 users). Both running 100% same configuration / same versions (Dovecot 2.4.2 / Debian Bookworm, Percona for MySQL 8.4.7), and both now with disabled IMAPSieve Plugin (imap-sieve) which is broken in 2.4.2.
Above problem occurs both with or without `doveadm_worker_count = 4`, so that's not the culprit.
The whole `doveadm quota get -A` always runs in less than 3s, so I cannot imagine any MySQL connection issues with the iterate_query.

I did not override anything in `service auth` or `service auth-worker` sections.

Any recommendations?

Thanks,
Philip



[1]
$ doveadm -Dv quota get -A 2>&1 | tee /tmp/debug.log
(...)
Feb 26 13:06:17 doveadm([email protected])<358389><>: Debug: auth-master: userdb lookup([email protected]): Started userdb lookup
Feb 26 13:06:17 doveadm([email protected])<358389><>: Debug: auth-master: request [4211869176]: Created
Feb 26 13:06:17 doveadm([email protected])<358389><>: Debug: auth-master: userdb lookup([email protected]): request [4211869176]: Waiting for request to complete
Feb 26 13:06:17 doveadm([email protected])<358389><>: Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=353974,uid=0): Sending requests
Feb 26 13:06:17 doveadm([email protected])<358389><>: Debug: auth-master: userdb lookup([email protected]): request [4211869176]: Sent
Feb 26 13:06:17 doveadm([email protected])<358389><>: Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=353974,uid=0): auth input: USER	4211869176	[email protected]	home=/var/vmail/example.com/demo	uid=998	gid=998	quota_storage_size=300M
Feb 26 13:06:17 doveadm([email protected])<358389><>: Debug: auth-master: userdb lookup([email protected]): request [4211869176]: Got reply: USER [email protected] home=/var/vmail/example.com/demo uid=998 gid=998 quota_storage_size=300M
Feb 26 13:06:17 doveadm([email protected])<358389><>: Debug: auth-master: userdb lookup([email protected]): auth USER input: [email protected] home=/var/vmail/example.com/demo uid=998 gid=998 quota_storage_size=300M
Feb 26 13:06:17 doveadm([email protected])<358389><>: Debug: auth-master: userdb lookup([email protected]): Finished userdb lookup ([email protected] home=/var/vmail/example.com/demo uid=998 gid=998 quota_storage_size=300M)
Feb 26 13:06:17 doveadm([email protected])<358389><>: Debug: auth-master: userdb lookup([email protected]): request [4211869176]: Remove
Feb 26 13:06:17 doveadm([email protected])<358389><>: Debug: auth-master: userdb lookup([email protected]): request [4211869176]: Finished waiting for request
Feb 26 13:06:17 doveadm([email protected])<358389><>: Debug: auth-master: userdb lookup([email protected]): request [4211869176]: Destroy
Feb 26 13:06:17 doveadm([email protected])<358389><>: Debug: Added setting via userdb: quota_storage_size=300M
Feb 26 13:06:17 doveadm([email protected]): Debug: Effective uid=998, gid=998, home=/var/vmail/example.com/demo
Feb 26 13:06:17 doveadm([email protected]): Debug: acl: Shared mailbox listing disabled: dict { .. } named list filter is missing
Feb 26 13:06:17 doveadm([email protected]): Debug: Namespace inbox: type=private, prefix=INBOX/, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes
Feb 26 13:06:17 doveadm([email protected]): Debug: fs: root=/var/vmail/example.com/demo/sdbox, index=, indexpvt=, control=, inbox=, alt=
Feb 26 13:06:17 doveadm([email protected]): Debug: acl: initializing backend vfile
Feb 26 13:06:17 doveadm([email protected]): Debug: acl: acl username = [email protected]
Feb 26 13:06:17 doveadm([email protected]): Debug: acl: owner = yes
Feb 26 13:06:17 doveadm([email protected]): Debug: acl: ignore = no
Feb 26 13:06:17 doveadm([email protected]): Debug: acl: vfile: Deprecated Global ACL file: /etc/dovecot/dovecot-acl
Feb 26 13:06:17 doveadm([email protected]): Debug: Namespace : type=private, prefix=, sep=, inbox=no, hidden=yes, list=no, subscriptions=no
Feb 26 13:06:17 doveadm([email protected]): Debug: none: root=/var/vmail/example.com/demo/sdbox, index=, indexpvt=, control=, inbox=, alt=
Feb 26 13:06:17 doveadm([email protected]): Debug: quota-count: quota_over_status check: quota_over_mask unset - skipping
Feb 26 13:06:17 doveadm([email protected]): Debug: Mailbox INBOX: Mailbox opened
Feb 26 13:06:17 doveadm([email protected]): Debug: User session is finished
Feb 26 13:06:17 doveadm([email protected]): Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=353974,uid=0): auth input: DONE	2802712577	fail
Feb 26 13:06:17 doveadm([email protected]): Debug: auth-master: userdb list: request [2802712577]: Got reply: DONE fail
Feb 26 13:06:17 doveadm([email protected]): Error: auth-master: userdb list: User listing returned failure
Feb 26 13:06:17 doveadm([email protected]): Debug: auth-master: userdb list: request [2802712577]: Remove
Feb 26 13:06:17 doveadm([email protected]): Debug: auth-master: userdb list: request [2802712577]: Destroy
Feb 26 13:06:17 doveadm([email protected]): Debug: auth-master: userdb list: Listing users failed
Feb 26 13:06:17 doveadm([email protected]): Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=353974,uid=0): Disconnected: Connection closed (fd=9)
Feb 26 13:06:17 doveadm([email protected]): Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=353974,uid=0): Disconnected from auth service
Feb 26 13:06:17 doveadm: Error: cmd quota get: Failed to iterate through some users
Feb 26 13:06:17 doveadm: Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=353974,uid=0): Disconnected: Connection closed (fd=10)
Feb 26 13:06:17 doveadm: Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=353974,uid=0): Disconnected from auth service



> On 25 Feb 2026, at 15:48, Philip Iezzi via dovecot <[email protected]> wrote:
> 
> Hi there
> 
> On a Dovecot 2.4.2 (Debian Bookworm) server with over 1300 users, I am using the following config to retrieve quota usage information with doveadm:
> 
> ---------------------------------------
> 
> quota "User quota" {
> }
> 
> mail_plugins = quota acl mail_log notify
> 
> userdb sql {
>  iterate_query = SELECT username AS user, CONCAT(quota, 'M') AS quota_storage_size FROM mailaccounts WHERE active = 1
> 
>  query = \
>    SELECT '/var/vmail/%{user | domain}/%{user | username}' AS home, 'vmail' AS uid, 'vmail' AS gid, CONCAT(quota, 'M') AS quota_storage_size \
>    FROM mailaccounts \
>    WHERE username = '%{user}' AND (active = 1 OR transport_suspended = 0)
> }
> 
> ---------------------------------------
> 
> Initially, I had to run `doveadm quota recalc -A` to recalc quotas and populate the `count` quota driver which is enabled by default for "User quota".
> But still, it took roughly 20ms per single user or 15-20s for all users:
> 
> $ time doveadm -f tab quota get -u [email protected]
> real	0m0.020s
> $ time doveadm -f tab quota get -A
> real	0m16.800s
> 
> Now, to greatly speed this up, I have introduced parallel processing:
> 
> doveadm_worker_count = 4
> 
> Like this, `doveadm -f tab quota get -A` runs approx 10x faster, done in 1.5 - 2.5s
> But there is one major drawback which I assume to be a bug:
> 
> # sane output without `doveadm_worker_count = 4` => always 6 fields
> [email protected]	User quota	STORAGE	29	204800	0
> [email protected]	User quota	MESSAGE	1	-	0
> 
> # broken output with `doveadm_worker_count = 4` => sometimes 7 fields
> [email protected]	User quota	STORAGE	29	2048	00		0
> [email protected]	User quota	MESSAGE	1	-	0
> 
> Somehow, the tab formatter does not play nicely together with parallel processing. On some output, the value gets split apart by an extra tab, e.g. '2024<TAB>00' in above example. Can you explain this corrupted data? Some kind of "output interleaving" seems to happen when running parallel workers.
> If I switch to json output (`doveadm -f json quota get -A`), this does not seem to happen and I always get valid JSON output, even with `doveadm_worker_count = 4`.
> 
> Cheers,
> Philip
> 
> _______________________________________________
> dovecot mailing list -- [email protected]
> To unsubscribe send an email to [email protected]

_______________________________________________
dovecot mailing list -- [email protected]
To unsubscribe send an email to [email protected]