Problem getting quota-warning script to function.

Ted ted at easydns.com
Wed Sep 19 21:42:40 EEST 2018 

Hello,

Here are the logs of the emails which sent the usage from 79% to 80%,
this is from Friday but  it was made using the same configs I sent earlier:

Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Added userdb setting:
mail=maildir:/svmail/04/quailmail.ca/other/Maildir
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Added userdb setting: plugin/quota_rule=*:storage=1G
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Effective uid=5000, gid=5000, home=/svmail/04/quailmail.ca/other
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Quota root: name=User quota backend=count args=
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Quota rule: root=User quota mailbox=* bytes=1073741824 messages=0
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Quota warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 other at quailmail.ca
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Quota warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 other at quailmail.ca
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Quota warning: bytes=858993459 (80%) messages=0 reverse=no
command=quota-warning 80 other at quailmail.ca
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Quota grace: root=User quota bytes=107374182 (10%)
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Namespace : type=private, prefix=INBOX., sep=., inbox=yes,
hidden=no, list=yes, subscriptions=yes
location=maildir:/svmail/04/quailmail.ca/other/Maildir
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: maildir++: root=/svmail/04/quailmail.ca/other/Maildir, index=,
indexpvt=, control=, inbox=/svmail/04/quailmail.ca/other/Maildir, alt=
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Namespace : type=private, prefix=, sep=, inbox=no, hidden=yes,
list=no, subscriptions=no location=fail::LAYOUT=none
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: none: root=, index=, indexpvt=, control=, inbox=, alt=
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Namespace INBOX.: Using permissions from
/svmail/04/quailmail.ca/other/Maildir: mode=0700 gid=default
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: quota: quota_over_flag check: STORAGE ret=1 value=836364
limit=1048576
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: quota: quota_over_flag check: MESSAGE ret=0 value=7577 limit=0
Sep 14 18:10:32 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: quota: quota_over_flag=0((null)) vs currently overquota=0
Sep 14 18:10:32 ezm11-pco amavis[1132]: (01132-02) ESMTP
[127.0.0.1]:10024
/var/lib/amavis/tmp/amavis-20180914T172035-01132-s1SrEj_J:
<ted at easydns.com> -> <other at quailmail.ca> SIZE=10997937 BODY=7BIT
Received: from smtp.easymail.ca ([127.0.0.1]) by localhost
(ezm11-pco.easydns.vpn [127.0.0.1]) (amavisd-new, port 10024) with ESMTP
for <other at quailmail.ca>; Fri, 14 Sep 2018 18:10:32 +0000 (UTC)
Sep 14 18:10:32 ezm11-pco amavis[1132]: (01132-02) Checking:
sFADxdNkitz8 [64.68.203.197] <ted at easydns.com> -> <other at quailmail.ca>
Sep 14 18:10:33 ezm11-pco amavis[1132]: (01132-02) spam-tag,
<ted at easydns.com> -> <other at quailmail.ca>, No, score=0 required=4
tests=[SPF_PASS=-0.001, TVD_SPACE_RATIO=0.001] autolearn=ham
autolearn_force=no
Sep 14 18:10:33 ezm11-pco amavis[1132]: (01132-02) sFADxdNkitz8 FWD from
<ted at easydns.com> -> <other at quailmail.ca>, BODY=7BIT 250 2.0.0 from
MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as A3FC4207A5
Sep 14 18:10:33 ezm11-pco amavis[1132]: (01132-02) Passed CLEAN
{RelayedInbound}, [64.68.203.197]:9154 [64.68.203.197] <ted at easydns.com>
-> <other at quailmail.ca>, Queue-ID: 3CF122077F, Message-ID:
<aeb7398b-0ce0-187b-9ac5-8ca76375edb5 at easydns.com>, mail_id:
sFADxdNkitz8, Hits: 0, size: 10997937, queued_as: A3FC4207A5, 1310 ms
Sep 14 18:10:33 ezm11-pco postfix/smtp[17037]: 3CF122077F:
to=<other at quailmail.ca>, relay=127.0.0.1[127.0.0.1]:10024, delay=1.8,
delays=0.5/0.01/0/1.3, dsn=2.0.0, status=sent (250 2.0.0 from
MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as A3FC4207A5)
Sep 14 18:10:33 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug:
Loading modules from directory: /usr/lib/dovecot/modules
Sep 14 18:10:33 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug:
Module loaded: /usr/lib/dovecot/modules/lib90_sieve_plugin.so
Sep 14 18:10:33 ezm11-pco dovecot: auth: Debug: master in:
USER#0111#011other at quailmail.ca#011service=lmtp
Sep 14 18:10:33 ezm11-pco dovecot: auth-worker(17035): Debug:
sql(other at quailmail.ca): SELECT
CONCAT('maildir:/',volume,'/',SUBSTRING_INDEX(email,'@',-1),'/',SUBSTRING_INDEX(email,'@',1),'/Maildir')
AS mail,
CONCAT('/',volume,'/',SUBSTRING_INDEX(email,'@',-1),'/',SUBSTRING_INDEX(email,'@',1))
AS home, 5000 AS uid, 5000 AS gid, concat('*:storage=', volume_limit
,'G') AS quota_rule from easymail_users where email =
'other at quailmail.ca' and banned = '0' and active = '1'
Sep 14 18:10:33 ezm11-pco dovecot: auth: Debug: userdb out:
USER#0111#011other at quailmail.ca#011mail=maildir:/svmail/04/quailmail.ca/other/Maildir#011home=/svmail/04/quailmail.ca/other#011uid=5000#011gid=5000#011quota_rule=*:storage=1G
Sep 14 18:10:33 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug: auth
USER input: other at quailmail.ca
mail=maildir:/svmail/04/quailmail.ca/other/Maildir
home=/svmail/04/quailmail.ca/other uid=5000 gid=5000 quota_rule=*:storage=1G
Sep 14 18:10:33 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug:
Added userdb setting: mail=maildir:/svmail/04/quailmail.ca/other/Maildir
Sep 14 18:10:33 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug:
Added userdb setting: plugin/quota_rule=*:storage=1G
Sep 14 18:10:34 ezm11-pco dovecot: lmtp(17044, other at quailmail.ca):
Debug: Effective uid=5000, gid=5000, home=/svmail/04/quailmail.ca/other
Sep 14 18:10:34 ezm11-pco dovecot: lmtp(17044, other at quailmail.ca):
Debug: Namespace : type=private, prefix=INBOX., sep=., inbox=yes,
hidden=no, list=yes, subscriptions=yes
location=maildir:/svmail/04/quailmail.ca/other/Maildir
Sep 14 18:10:34 ezm11-pco dovecot: lmtp(17044, other at quailmail.ca):
Debug: maildir++: root=/svmail/04/quailmail.ca/other/Maildir, index=,
indexpvt=, control=, inbox=/svmail/04/quailmail.ca/other/Maildir, alt=
Sep 14 18:10:34 ezm11-pco dovecot: lmtp(17044, other at quailmail.ca):
Debug: Namespace : type=private, prefix=, sep=, inbox=no, hidden=yes,
list=no, subscriptions=no location=fail::LAYOUT=none
Sep 14 18:10:34 ezm11-pco dovecot: lmtp(17044, other at quailmail.ca):
Debug: none: root=, index=, indexpvt=, control=, inbox=, alt=
Sep 14 18:10:34 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug:
sieve: Pigeonhole version 0.4.16 (fed8554) initializing
Sep 14 18:10:34 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug:
sieve: include: sieve_global is not set; it is currently not possible to
include `:global' scripts.
Sep 14 18:10:34 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug:
8+waOpn5m1uUQgAAXc2cvg: sieve: file storage: Storage path
`/svmail/04/quailmail.ca/other/sieve' not found
Sep 14 18:10:34 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug:
8+waOpn5m1uUQgAAXc2cvg: sieve: file storage: Storage path
`/svmail/04/quailmail.ca/other/.dovecot.sieve' not found
Sep 14 18:10:34 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug:
8+waOpn5m1uUQgAAXc2cvg: sieve: storage: No default script location
configured
Sep 14 18:10:34 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug:
8+waOpn5m1uUQgAAXc2cvg: sieve: User has no personal script
Sep 14 18:10:34 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug:
8+waOpn5m1uUQgAAXc2cvg: sieve: No scripts to execute: reverting to
default delivery.
Sep 14 18:10:34 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug:
Mailbox <lmtp DATA>: Opened mail UID=1 because: copying
Sep 14 18:10:34 ezm11-pco dovecot: lmtp(other at quailmail.ca):
8+waOpn5m1uUQgAAXc2cvg:
msgid=<aeb7398b-0ce0-187b-9ac5-8ca76375edb5 at easydns.com>: saved mail to
INBOX
Sep 14 18:10:34 ezm11-pco postfix/lmtp[17043]: A3FC4207A5:
to=<other at quailmail.ca>, relay=smtp.easymail.ca[private/dovecot-lmtp],
delay=0.64, delays=0.29/0.01/0.01/0.34, dsn=2.0.0, status=sent (250
2.0.0 <other at quailmail.ca> 8+waOpn5m1uUQgAAXc2cvg Saved)
Sep 14 18:11:04 ezm11-pco dovecot: auth: Debug: master in:
USER#0112#011other at quailmail.ca#011service=quota-status
Sep 14 18:11:04 ezm11-pco dovecot: auth-worker(17035): Debug:
sql(other at quailmail.ca): SELECT
CONCAT('maildir:/',volume,'/',SUBSTRING_INDEX(email,'@',-1),'/',SUBSTRING_INDEX(email,'@',1),'/Maildir')
AS mail,
CONCAT('/',volume,'/',SUBSTRING_INDEX(email,'@',-1),'/',SUBSTRING_INDEX(email,'@',1))
AS home, 5000 AS uid, 5000 AS gid, concat('*:storage=', volume_limit
,'G') AS quota_rule from easymail_users where email =
'other at quailmail.ca' and banned = '0' and active = '1'
Sep 14 18:11:04 ezm11-pco dovecot: auth: Debug: userdb out:
USER#0112#011other at quailmail.ca#011mail=maildir:/svmail/04/quailmail.ca/other/Maildir#011home=/svmail/04/quailmail.ca/other#011uid=5000#011gid=5000#011quota_rule=*:storage=1G
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: auth USER input: other at quailmail.ca
mail=maildir:/svmail/04/quailmail.ca/other/Maildir
home=/svmail/04/quailmail.ca/other uid=5000 gid=5000 quota_rule=*:storage=1G
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Added userdb setting:
mail=maildir:/svmail/04/quailmail.ca/other/Maildir
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Added userdb setting: plugin/quota_rule=*:storage=1G
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Effective uid=5000, gid=5000, home=/svmail/04/quailmail.ca/other
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Quota root: name=User quota backend=count args=
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Quota rule: root=User quota mailbox=* bytes=1073741824 messages=0
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Quota warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 other at quailmail.ca
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Quota warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 other at quailmail.ca
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Quota warning: bytes=858993459 (80%) messages=0 reverse=no
command=quota-warning 80 other at quailmail.ca
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Quota grace: root=User quota bytes=107374182 (10%)
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Namespace : type=private, prefix=INBOX., sep=., inbox=yes,
hidden=no, list=yes, subscriptions=yes
location=maildir:/svmail/04/quailmail.ca/other/Maildir
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: maildir++: root=/svmail/04/quailmail.ca/other/Maildir, index=,
indexpvt=, control=, inbox=/svmail/04/quailmail.ca/other/Maildir, alt=
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Namespace : type=private, prefix=, sep=, inbox=no, hidden=yes,
list=no, subscriptions=no location=fail::LAYOUT=none
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: none: root=, index=, indexpvt=, control=, inbox=, alt=
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: Namespace INBOX.: Using permissions from
/svmail/04/quailmail.ca/other/Maildir: mode=0700 gid=default
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: quota: quota_over_flag check: STORAGE ret=1 value=847105
limit=1048576
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: quota: quota_over_flag check: MESSAGE ret=0 value=7578 limit=0
Sep 14 18:11:04 ezm11-pco dovecot: quota-status(other at quailmail.ca):
Debug: quota: quota_over_flag=0((null)) vs currently overquota=0
Sep 14 18:11:05 ezm11-pco amavis[1130]: (01130-01) ESMTP
[127.0.0.1]:10024
/var/lib/amavis/tmp/amavis-20180914T181105-01130-c1dnU_QP:
<ted at easydns.com> -> <other at quailmail.ca> SIZE=10997943 BODY=7BIT
Received: from smtp.easymail.ca ([127.0.0.1]) by localhost
(ezm11-pco.easydns.vpn [127.0.0.1]) (amavisd-new, port 10024) with ESMTP
for <other at quailmail.ca>; Fri, 14 Sep 2018 18:11:05 +0000 (UTC)
Sep 14 18:11:05 ezm11-pco amavis[1130]: (01130-01) Checking:
MAOKJ8YSvJXH [64.68.203.197] <ted at easydns.com> -> <other at quailmail.ca>
Sep 14 18:11:06 ezm11-pco amavis[1130]: (01130-01) spam-tag,
<ted at easydns.com> -> <other at quailmail.ca>, No, score=0 required=4
tests=[BODY_SINGLE_WORD=0.001, SPF_PASS=-0.001] autolearn=ham
autolearn_force=no
Sep 14 18:11:06 ezm11-pco amavis[1130]: (01130-01) MAOKJ8YSvJXH FWD from
<ted at easydns.com> -> <other at quailmail.ca>, BODY=7BIT 250 2.0.0 from
MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 526FA207A9
Sep 14 18:11:06 ezm11-pco dovecot: auth: Debug: master in:
USER#0112#011other at quailmail.ca#011service=lmtp
Sep 14 18:11:06 ezm11-pco dovecot: auth-worker(17035): Debug:
sql(other at quailmail.ca): SELECT
CONCAT('maildir:/',volume,'/',SUBSTRING_INDEX(email,'@',-1),'/',SUBSTRING_INDEX(email,'@',1),'/Maildir')
AS mail,
CONCAT('/',volume,'/',SUBSTRING_INDEX(email,'@',-1),'/',SUBSTRING_INDEX(email,'@',1))
AS home, 5000 AS uid, 5000 AS gid, concat('*:storage=', volume_limit
,'G') AS quota_rule from easymail_users where email =
'other at quailmail.ca' and banned = '0' and active = '1'
Sep 14 18:11:06 ezm11-pco amavis[1130]: (01130-01) Passed CLEAN
{RelayedInbound}, [64.68.203.197]:1101 [64.68.203.197] <ted at easydns.com>
-> <other at quailmail.ca>, Queue-ID: CD8CE2077F, Message-ID:
<0f892fdf-5e81-02bd-1985-240cb26501f9 at easydns.com>, mail_id:
MAOKJ8YSvJXH, Hits: 0, size: 10997943, queued_as: 526FA207A9, 1241 ms
Sep 14 18:11:06 ezm11-pco dovecot: auth: Debug: userdb out:
USER#0112#011other at quailmail.ca#011mail=maildir:/svmail/04/quailmail.ca/other/Maildir#011home=/svmail/04/quailmail.ca/other#011uid=5000#011gid=5000#011quota_rule=*:storage=1G
Sep 14 18:11:06 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug: auth
USER input: other at quailmail.ca
mail=maildir:/svmail/04/quailmail.ca/other/Maildir
home=/svmail/04/quailmail.ca/other uid=5000 gid=5000 quota_rule=*:storage=1G
Sep 14 18:11:06 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug:
Added userdb setting: mail=maildir:/svmail/04/quailmail.ca/other/Maildir
Sep 14 18:11:06 ezm11-pco dovecot: lmtp(other at quailmail.ca): Debug:
Added userdb setting: plugin/quota_rule=*:storage=1G
Sep 14 18:11:06 ezm11-pco postfix/smtp[17037]: CD8CE2077F:
to=<other at quailmail.ca>, relay=127.0.0.1[127.0.0.1]:10024, delay=1.8,
delays=0.55/0/0.01/1.2, dsn=2.0.0, status=sent (250 2.0.0 from
MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 526FA207A9)

Thank you
Ted
easyDNS Technologies

On 2018-09-19 12:55 PM, Aki Tuomi wrote:
>> On 19 September 2018 at 19:49 Ted <ted at easydns.com> wrote:
>>
>>
>> Hello,
>>
>> Most of the work was done with dovecot 2.2.27 but I just upgraded to
>> 2.3.2 and didn't see any change.  Some debug logs are below, is there
>> something specific I could search them for?
>>
> Can you maybe try delivery to an account which should trigger quota warning or overquota action with mail_debug=yes?
>
> Aki

More information about the dovecot mailing list