Re: Dovecot 2.4 doveadm_worker_count corrupts tab-formatted output

> On 26 Feb 2026, at 18:45, John Fawcett via dovecot <[email protected]> wrote:
> 
>   On 26/02/2026 15:42, Philip Iezzi via dovecot wrote:
> 
> 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([1][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].
> 
> ...
> $ doveadm -Dv quota get -A 2>&1 | tee /tmp/debug.log
> (...)
> Feb 26 13:06:17 doveadm([2][email protected])<358389><>: Debug: auth-master: userdb lookup([3][email protected]): Started userdb lookup
> Feb 26 13:06:17 doveadm([4][email protected])<358389><>: Debug: auth-master: request [4211869176]: Created
> Feb 26 13:06:17 doveadm([5][email protected])<358389><>: Debug: auth-master: userdb lookup([6][email protected]): request [4211869176]: Waiting for request to complete
> Feb 26 13:06:17 doveadm([7][email protected])<358389><>: Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=353974,uid=0): Sending requests
> Feb 26 13:06:17 doveadm([8][email protected])<358389><>: Debug: auth-master: userdb lookup([9][email protected]): request [4211869176]: Sent
> Feb 26 13:06:17 doveadm([10][email protected])<358389><>: Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=353974,uid=0): auth input: USER    4211869176      [11][email protected]        home=/var/vmail/example.com/demo        uid=998 gid=998 quota_storage_size=300M
> Feb 26 13:06:17 doveadm([12][email protected])<358389><>: Debug: auth-master: userdb lookup([13][email protected]): request [4211869176]: Got reply: USER [14][email protected] home=/var/vmail/example.com/demo uid=998 gid=998 quota_storage_size=300M
> Feb 26 13:06:17 doveadm([15][email protected])<358389><>: Debug: auth-master: userdb lookup([16][email protected]): auth USER input: [17][email protected] home=/var/vmail/example.com/demo uid=998 gid=998 quota_storage_size=300M
> Feb 26 13:06:17 doveadm([18][email protected])<358389><>: Debug: auth-master: userdb lookup([19][email protected]): Finished userdb lookup ([20][email protected] home=/var/vmail/example.com/demo uid=998 gid=998 quota_storage_size=300M)
> Feb 26 13:06:17 doveadm([21][email protected])<358389><>: Debug: auth-master: userdb lookup([22][email protected]): request [4211869176]: Remove
> Feb 26 13:06:17 doveadm([23][email protected])<358389><>: Debug: auth-master: userdb lookup([24][email protected]): request [4211869176]: Finished waiting for request
> Feb 26 13:06:17 doveadm([25][email protected])<358389><>: Debug: auth-master: userdb lookup([26][email protected]): request [4211869176]: Destroy
> Feb 26 13:06:17 doveadm([27][email protected])<358389><>: Debug: Added setting via userdb: quota_storage_size=300M
> Feb 26 13:06:17 doveadm([28][email protected]): Debug: Effective uid=998, gid=998, home=/var/vmail/example.com/demo
> Feb 26 13:06:17 doveadm([29][email protected]): Debug: acl: Shared mailbox listing disabled: dict { .. } named list filter is missing
> Feb 26 13:06:17 doveadm([30][email protected]): Debug: Namespace inbox: type=private, prefix=INBOX/, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes
> Feb 26 13:06:17 doveadm([31][email protected]): Debug: fs: root=/var/vmail/example.com/demo/sdbox, index=, indexpvt=, control=, inbox=, alt=
> Feb 26 13:06:17 doveadm([32][email protected]): Debug: acl: initializing backend vfile
> Feb 26 13:06:17 doveadm([33][email protected]): Debug: acl: acl username = [34][email protected]
> Feb 26 13:06:17 doveadm([35][email protected]): Debug: acl: owner = yes
> Feb 26 13:06:17 doveadm([36][email protected]): Debug: acl: ignore = no
> Feb 26 13:06:17 doveadm([37][email protected]): Debug: acl: vfile: Deprecated Global ACL file: /etc/dovecot/dovecot-acl
> Feb 26 13:06:17 doveadm([38][email protected]): Debug: Namespace : type=private, prefix=, sep=, inbox=no, hidden=yes, list=no, subscriptions=no
> Feb 26 13:06:17 doveadm([39][email protected]): Debug: none: root=/var/vmail/example.com/demo/sdbox, index=, indexpvt=, control=, inbox=, alt=
> Feb 26 13:06:17 doveadm([40][email protected]): Debug: quota-count: quota_over_status check: quota_over_mask unset - skipping
> Feb 26 13:06:17 doveadm([41][email protected]): Debug: Mailbox INBOX: Mailbox opened
> Feb 26 13:06:17 doveadm([42][email protected]): Debug: User session is finished
> Feb 26 13:06:17 doveadm([43][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([44][email protected]): Debug: auth-master: userdb list: request [2802712577]: Got reply: DONE fail
> Feb 26 13:06:17 doveadm([45][email protected]): Error: auth-master: userdb list: User listing returned failure
> Feb 26 13:06:17 doveadm([46][email protected]): Debug: auth-master: userdb list: request [2802712577]: Remove
> Feb 26 13:06:17 doveadm([47][email protected]): Debug: auth-master: userdb list: request [2802712577]: Destroy
> Feb 26 13:06:17 doveadm([48][email protected]): Debug: auth-master: userdb list: Listing users failed
> Feb 26 13:06:17 doveadm([49][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([50][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
> 
> 
> 
>   Hi
> 
>   I could be wrong but is this debug output complete? It looks like
>   request  2802712577 is failing, but the previous logging relating to
>   [51][email protected] seems to be from request 4211869176.
> 
>   Also, though I don't believe either it is related to the issue:
> 
>   What is the reason for returning quota_storage_size in the iterate_query?
>   It shouldn't matter if you return extra fields, but why do it?
> 
>   Your iterate query can potentially return a subset of the users compared
>   to your user query due to differing where conditions.
> 
>   John

Hi John

Thanks for looking into this. Yes, those were the last lines of `doveadm -Dv quota get -A` debug output, all related to the same user - I have simply redacted the user with [email protected], but did not change anything else / did not remove any lines. And yes, the problem always occurs on another user and is definitely not related to a specific user.
I don't really understand the logic here - so maybe it's just some kind of chained request that triggers the next one (2802712577) via `userdb list`.

I also don't quite remember why I added `quota_storage_size` to the iterate_query. Somehow I struggled to get quotas working during Dovecot 2.3 => 2.4 config migration. I have removed it now and all still seems to be working with:

iterate_query = SELECT username AS user FROM mailaccounts WHERE active = 1

Thanks for this input. But this doesn't make a difference. I always get the same Error:

$ doveadm -f json 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

correlating with exactly 1 such line in mail.log:

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

Here's the thing: This only happens on my mail server with 2200 users, not on the other with "only" 1200 users, both running the exact same config/versions.
I have now invented this nice funky workaround to completely do without depending on the iterate_query. I don't even need to grab a subset of the users / do any sharding, just pipe all users into `-F`:

$ mysql --quick -srN maildb -e 'SELECT username FROM mailaccounts WHERE active=1' | doveadm -f json quota get -F -

It always works, always gives me the full data (checked with `wc -c`, while `-A` always broke in the middle and never returned the quotas for all users), and it never provokes a crashed auth-worker, above Error no longer showing up.

But I'd like to emphasize, that on Dovecot 2.3, I was running `doveadm quota get -A` for years, without ever running into this issue. It ran as a cache warmup job from my application and pulled all quota usages from Dovecot server, every 4 minutes! I know this is probably not recommended and I could easily reduce it to run only every 15mins or even less frequently. But no matter how often I run it on that server with 2200 users, it always runs fast enough, but always breaks since upgrading to Dovecot 2.4

Cheers,
Philip

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