Skip to main content

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

SymptomUsually means
Nothing happens at allPostfix is not consulting the daemon, or the policy matches nothing
The rule fires on mail it should notA policy matching more broadly than you think, or several policies applying at once
Counters never moveThe module is off, or Track is not what you assumed
It worked, then stoppedA cache not restarted, a period boundary, or a database lock
Everything is deferredA 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_members row. The LEFT JOIN shows NULL for Source. It will never match.
  • @example.com in internal_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 '' from NULL where a plain select shows both as blank. A NULL can behave as a wildcard.
  • Disabled = 1 on 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

  1. postconf | grep check_policy_service - is Postfix consulting it at all?
  2. zmcbpolicydctl status - is the daemon running?
  3. zimbraCBPolicyd<Module>Enabled - is the module on?
  4. Log level to 4 and watch cbpolicyd.log while you test.
  5. Walk policies to policy_members to policy_groups, looking for the broken link.
  6. Read the tracking table to see what key is really being counted.
  7. zmcbpolicydctl restart after every change.

Steps 1 to 3 take under a minute between them and account for most cases.

The series