postfix-users April 2011 archive
Main Archive Page > Month Archives  > postfix-users archives
postfix-users: Re: minor postscreen cleanup logging issue

Re: minor postscreen cleanup logging issue

From: Wietse Venema <wietse_at_nospam>
Date: Mon Apr 11 2011 - 23:22:22 GMT
To: Postfix users <postfix-users@postfix.org>

Peter Schultze:
> Hello,
>
> using postfix 2.8.2 under Solaris 10 with
> postscreen_cache_map = dbm:$data_directory/verify_cache
>
> it appears that cache cleanup logging gives erratic numbers of retained entries,
> ranging between 1875 and as high as 727916:
>
> Apr 3 11:32:25 postfix/postscreen[760]: [ID 197553 mail.info] cache /var/lib/postfix/verify_cache full cleanup: retained=1875 dropped=59 entries
> Apr 3 23:32:58 postfix/postscreen[760]: [ID 197553 mail.info] cache /var/lib/postfix/verify_cache full cleanup: retained=468417 dropped=693 entries
> Apr 4 11:33:13 postfix/postscreen[760]: [ID 197553 mail.info] cache /var/lib/postfix/verify_cache full cleanup: retained=238015 dropped=1087 entries
> Apr 4 23:33:43 postfix/postscreen[760]: [ID 197553 mail.info] cache /var/lib/postfix/verify_cache full cleanup: retained=404255 dropped=207 entries
> Apr 5 11:34:08 postfix/postscreen[760]: [ID 197553 mail.info] cache /var/lib/postfix/verify_cache full cleanup: retained=357344 dropped=1094 entries
> Apr 5 23:34:09 postfix/postscreen[760]: [ID 197553 mail.info] cache /var/lib/postfix/verify_cache full cleanup: retained=10043 dropped=278 entries
> Apr 6 11:34:24 postfix/postscreen[760]: [ID 197553 mail.info] cache /var/lib/postfix/verify_cache full cleanup: retained=235581 dropped=1393 entries
> Apr 6 23:34:52 postfix/postscreen[760]: [ID 197553 mail.info] cache /var/lib/postfix/verify_cache full cleanup: retained=389771 dropped=839 entries
> Apr 7 11:35:41 postfix/postscreen[760]: [ID 197553 mail.info] cache /var/lib/postfix/verify_cache full cleanup: retained=668060 dropped=546 entries
> Apr 7 23:36:23 postfix/postscreen[760]: [ID 197553 mail.info] cache /var/lib/postfix/verify_cache full cleanup: retained=569135 dropped=903 entries
> Apr 8 11:36:41 postfix/postscreen[760]: [ID 197553 mail.info] cache /var/lib/postfix/verify_cache full cleanup: retained=259013 dropped=1148 entries
> Apr 8 23:36:59 postfix/postscreen[760]: [ID 197553 mail.info] cache /var/lib/postfix/verify_cache full cleanup: retained=252607 dropped=832 entries
> Apr 9 11:37:08 postfix/postscreen[760]: [ID 197553 mail.info] cache /var/lib/postfix/verify_cache full cleanup: retained=117216 dropped=677 entries
> Apr 9 23:38:02 postfix/postscreen[760]: [ID 197553 mail.info] cache /var/lib/postfix/verify_cache full cleanup: retained=727916 dropped=492 entries
>
>
> The actual number of cache entries on this system is around 25000:
>
> # postmap -s /var/lib/postfix/verify_cache | wc -l
> 24436
>
> Otherwise postscreen is working well, so if this is a bug it would only be minor.
>

The cache manager (dict_cache.c) uses the same first/next iterator
as "postmap -s".

The difference is that "postmap -s" makes a continuous pass, while
cache manager cleanup is interleaved with routine database lookup
and updates. I suspect that the DBM iterator does not handle this
usage pattern and just thrashes around in the database.

A more serious problem is that DBM tables can only have a limited
number of entries in the same hash bucket, after that, all updates
fail with a hard error (this is a known problem with NIS databases).

For all these reasons the default cache database type is btree not
dbm. It has a more robust iterator, and it does not die when you
have many entries in the database.

You change the default at your own risk.

        Wietse