Troubleshooting cbpolicyd on Zimbra
cbpolicyd fails quietly. A policy whose group is empty matches nothing and says nothing. A daemon Postfix never consults looks exactly like a rule that does not apply. At the default log level you will not be told which policies matched or why. This is the order to check things in, from the cheapest test to the most thorough.
The last article in the series that starts with cbpolicyd on Zimbra: An Introduction.
Narrow it down first
| Symptom | Usually means |
|---|---|
| Nothing happens at all | Postfix is not consulting the daemon, or the policy matches nothing |
| The rule fires on mail it should not | A policy matching more broadly than you think, or several policies applying at once |
| Counters never move | The module is off, or Track is not what you assumed |
| It worked, then stopped | A cache not restarted, a period boundary, or a database lock |
| Everything is deferred | A limit of 0, or a NULL that means inherit rather than off |
Step 1: is Postfix even asking?
This rules out more than anything else, and it takes three seconds.
postconf | grep check_policy_service
You need check_policy_service inet:localhost:10031 in smtpd_recipient_restrictions, and
normally in smtpd_end_of_data_restrictions as well. If it is missing, nothing in the
database can possibly have any effect.
zmcbpolicydctl status
ss -lnt | grep 10031
You can also ask the daemon directly, without sending mail:
printf 'request=smtpd_access_policy\nprotocol_state=RCPT\nprotocol_name=SMTP\nsender=user@example.com\nrecipient=other@example.com\nclient_address=127.0.0.1\n\n' | nc 127.0.0.1 10031
An action= line back proves the socket works. It may not give a meaningful verdict without
more attributes, so treat it as a connectivity test.
Step 2: turn the logging up
At the default level of 3 you see almost nothing about decisions:
zmprov ms $(zmhostname) zimbraCBPolicydLogLevel 4
zmmtactl restart
tail -f /opt/zimbra/log/cbpolicyd.log
Put it back to 3 afterwards. Level 4 is noisy on a busy server.
Step 3: is the module enabled?
Only quotas is on by default. Everything else needs its attribute set and an MTA restart:
for a in Quotas AccessControl Greylisting CheckSPF CheckHelo Accounting Amavis; do
printf '%-16s %s\n' "$a" "$(zmprov gcf zimbraCBPolicyd${a}Enabled)"
done
A rule for a disabled module sits in the database looking perfectly correct and does nothing.
Step 4: can the policy match anything?
This is the most common cause by a wide margin. Walk the chain from the module row up to the group members, because a break anywhere means silence.
-- what is attached to which policy, in evaluation order
SELECT p.Priority, p.ID, p.Name AS Policy, p.Disabled AS PolDisabled,
m.Source, m.Destination
FROM policies p
LEFT JOIN policy_members m ON m.PolicyID = p.ID
ORDER BY p.Priority, p.ID;
-- what the groups actually contain
SELECT g.ID, g.Name, quote(m.Member) AS Member, m.Disabled
FROM policy_groups g
LEFT JOIN policy_group_members m ON m.PolicyGroupID = g.ID
ORDER BY g.ID;
Things to look for:
- A policy with no
policy_membersrow. TheLEFT JOINshowsNULLforSource. It will never match. @example.comininternal_domains. The shipped placeholders. If your real domains are not there, the three direction policies match nothing real.- An empty or NULL member.
quote()distinguishes''fromNULLwhere a plain select shows both as blank. A NULL can behave as a wildcard. Disabled = 1on the policy, the member or the module row.
Step 5: is it counting what you think?
For quotas and accounting, the tracking tables tell you exactly what key cbpolicyd decided
to use. That is usually the fastest way to find a wrong Track string.
SELECT q.Name, t.TrackKey, t.Counter,
datetime(t.LastUpdate, 'unixepoch') AS LastUpdate
FROM quotas_tracking t
JOIN quotas_limits l ON l.ID = t.QuotasLimitsID
JOIN quotas q ON q.ID = l.QuotasID
ORDER BY t.LastUpdate DESC LIMIT 20;
No rows at all means the policy never matched, so go back to step 4. Rows with an
unexpected TrackKey mean the Track string is not what you intended - Sender:@domain
pools a whole domain into one bucket, while Sender:user@domain gives each person their
own.
The failure modes worth knowing
Policies are cached. Every change to the database needs a restart before it takes effect:
zmcbpolicydctl restart
More rules "not working" come from skipping this than from anything wrong with the SQL.
Counting happens per recipient. Postfix consults the policy service at RCPT stage, so
one message to five recipients can add five to a MessageCount counter. If your limits
trip sooner than the message volume suggests, this is why.
Every matching policy applies. cbpolicyd does not stop at the first match. It collects
all of them in priority order and the modules work through them. A quota on Default and
another on Default Outbound both count the same outbound message.
Lower priority numbers run first. The upstream documentation is blunt about the
confusion: "'Higher priority' in everyday language can be ambiguous. In PolicyD, lower
numeric values are evaluated first." A broad REJECT at priority 5 beats the OK at 10
that was meant to exempt something from it.
NULL means inherit, not off. In greylisting, checkspf, checkhelo and the amavis
module, a NULL column takes its value from a lower-priority policy rather than disabling
the check. To switch something off, write 0.
Units differ between modules. quotas_limits.CounterLimit with
MessageCumulativeSize is in bytes. accounting.MessageCumulativeSizeLimit is in
kilobytes. A thousand-fold error in either direction looks like a limit that never
fires or one that always does.
Writing to amavis_rules does nothing on a stock Zimbra, because amavis is not
configured to read from that database. See cbpolicyd and Amavis.
When the database is the problem
SQLite allows one writer at a time. cbpolicyd is reading from that file on every single
transaction Postfix handles, so a long write from your sqlite3 session can block it:
database is locked
If you see that in cbpolicyd.log, or your sqlite3 session hangs, something is holding a
write. Keep interactive sessions short, do bulk work in a transaction rather than as
hundreds of separate statements, and run VACUUM outside busy hours.
The tracking tables grow and nothing prunes them. On a busy server they are worth watching:
SELECT 'quotas_tracking', COUNT(*) FROM quotas_tracking
UNION ALL SELECT 'accounting_tracking', COUNT(*) FROM accounting_tracking
UNION ALL SELECT 'greylisting_tracking', COUNT(*) FROM greylisting_tracking
UNION ALL SELECT 'checkhelo_tracking', COUNT(*) FROM checkhelo_tracking;
Prune what you do not need, then reclaim the space:
DELETE FROM accounting_tracking
WHERE LastUpdate < strftime('%s', 'now', '-1 year');
sqlite3 /opt/zimbra/data/cbpolicyd/db/cbpolicyd.sqlitedb 'VACUUM;'
Starting over
When a database has been experimented on past the point of understanding it, the fastest
fix is often to rebuild. Stop the service, move the file aside, and let zmconfigd create
a fresh one:
zmcbpolicydctl stop
mv /opt/zimbra/data/cbpolicyd/db/cbpolicyd.sqlitedb \
/opt/zimbra/data/cbpolicyd/db/cbpolicyd.sqlitedb.old-$(date +%F)
zmcbpolicydctl start
You lose all policies and all tracking history, so take a copy rather than deleting, and
keep your working rules in a .sql file you can replay. Scripting your configuration is
worth doing for its own sake: it is the only version history this daemon will ever have.
A worked order
postconf | grep check_policy_service- is Postfix consulting it at all?zmcbpolicydctl status- is the daemon running?zimbraCBPolicyd<Module>Enabled- is the module on?- Log level to
4and watchcbpolicyd.logwhile you test. - Walk policies to policy_members to policy_groups, looking for the broken link.
- Read the tracking table to see what key is really being counted.
zmcbpolicydctl restartafter every change.
Steps 1 to 3 take under a minute between them and account for most cases.