postscreen log lines reporting warnings and fatal errors

classic Classic list List threaded Threaded
9 messages Options
Reply | Threaded
Open this post in threaded view
|

postscreen log lines reporting warnings and fatal errors

Robert Lopez
wrt: mail_version = 2.10.0


I am trying to understand the cause/causes of these log lines:

1) postfix/postscreen[####]: fatal: error [-30986] seeking
/var/lib/postfix/postscreen_cache.db: Success

2) postfix/master[4070]: warning: process
/usr/libexec/postfix/postscreen pid 4366 exit status 1

3) postfix/master[4070]: warning: /usr/libexec/postfix/postscreen: bad
command startup -- throttling

As in the context of these log lines:

Jun 14 12:40:47 mg08 postfix/postscreen[4366]: CONNECT from
[92.56.112.84]:1297 to [198.133.182.99]:25
Jun 14 12:40:47 mg08 postfix/postscreen[4366]: fatal: error [-30986]
seeking /var/lib/postfix/postscreen_cache.db: Success
Jun 14 12:40:47 mg08 postfix/dnsblog[4328]: addr 92.56.112.84 listed
by domain bl.spamcop.net as 127.0.0.2
Jun 14 12:40:47 mg08 postfix/dnsblog[4327]: addr 92.56.112.84 listed
by domain b.barracudacentral.org as 127.0.0.2
Jun 14 12:40:47 mg08 postfix/dnsblog[4329]: addr 92.56.112.84 listed
by domain dnsbl.sorbs.net as 127.0.0.6
Jun 14 12:40:48 mg08 postfix/master[4070]: warning: process
/usr/libexec/postfix/postscreen pid 4366 exit status 1
Jun 14 12:40:51 mg08 postfix/postscreen[4367]: CONNECT from
[5.46.134.65]:30669 to [198.133.182.99]:25
Jun 14 12:40:51 mg08 postfix/postscreen[4367]: fatal: error [-30986]
seeking /var/lib/postfix/postscreen_cache.db: Success
Jun 14 12:40:51 mg08 postfix/dnsblog[4330]: addr 5.46.134.65 listed by
domain b.barracudacentral.org as 127.0.0.2
Jun 14 12:40:52 mg08 postfix/master[4070]: warning: process
/usr/libexec/postfix/postscreen pid 4367 exit status 1
Jun 14 12:40:55 mg08 postfix/postscreen[4368]: CONNECT from
[216.211.163.156]:36611 to [198.133.182.99]:25
Jun 14 12:40:55 mg08 postfix/postscreen[4368]: fatal: error [-30986]
seeking /var/lib/postfix/postscreen_cache.db: Success
Jun 14 12:40:56 mg08 postfix/master[4070]: warning: process
/usr/libexec/postfix/postscreen pid 4368 exit status 1
Jun 14 12:40:56 mg08 postfix/postscreen[4369]: CONNECT from
[190.254.19.122]:18185 to [198.133.182.99]:25
Jun 14 12:40:56 mg08 postfix/postscreen[4369]: fatal: error reading
/var/lib/postfix/postscreen_cache.db: Unknown error
18446744073709520630
Jun 14 12:40:57 mg08 postfix/master[4070]: warning: process
/usr/libexec/postfix/postscreen pid 4369 exit status 1
Jun 14 12:40:57 mg08 postfix/master[4070]: warning:
/usr/libexec/postfix/postscreen: bad command startup -- throttling


The #1 line is confusing in having both the words "fatal" and
"Success". It seems I have seen that discussed in the group before,
(before I installed 2.10.0) but Google is not helping me find the discussion.

All these lines seem to be related to the cases of others who
have reported such errors associated to multiple postscreen processes.

In so far as I understand I do not think I have multiple postscreen processes.
I do recognize that I have 4 ethernet interfaces. eth0 which faces toward the
Internet. eth1 that faces toward CNM internal network. eth2 which is dedicated
to an interface to a filer system (not used by email). lo loopback.
Because I have no code in master.cf to address these interfaces, I think I
am not running multiple postscreen processes.

Here are the uncommented lines of the master.cf:

[root@mg08 log]# cat /etc/postfix/master.cf | grep -v "^#"
smtp      inet  n       -       -       -       1       postscreen
smtpd     pass  -       -       -       -       -       smtpd
dnsblog   unix  -       -       -       -       0       dnsblog
pickup    fifo  n       -       -       60      1       pickup
cleanup   unix  n       -       -       -       0       cleanup
qmgr      fifo  n       -       n       300     1       qmgr
rewrite   unix  -       -       -       -       -       trivial-rewrite
bounce    unix  -       -       -       -       0       bounce
defer     unix  -       -       -       -       0       bounce
trace     unix  -       -       -       -       0       bounce
verify    unix  -       -       -       -       1       verify
flush     unix  n       -       -       1000?   0       flush
proxymap  unix  -       -       n       -       -       proxymap
proxywrite unix -       -       n       -       1       proxymap
smtp      unix  -       -       -       -       -       smtp
relay     unix  -       -       -       -       -       smtp
showq     unix  n       -       -       -       -       showq
error     unix  -       -       -       -       -       error
retry     unix  -       -       -       -       -       error
discard   unix  -       -       -       -       -       discard
local     unix  -       n       n       -       -       local
virtual   unix  -       n       n       -       -       virtual
lmtp      unix  -       -       -       -       -       lmtp
anvil     unix  -       -       -       -       1       anvil
scache    unix  -       -       -       -       1       scache
maildrop  unix  -       n       n       -       -       pipe
  flags=DRhu user=vmail argv=/usr/bin/maildrop -d ${recipient}
uucp      unix  -       n       n       -       -       pipe
  flags=Fqhu user=uucp argv=uux -r -n -z -a$sender - $nexthop!rmail ($recipient)
ifmail    unix  -       n       n       -       -       pipe
  flags=F user=ftn argv=/usr/lib/ifmail/ifmail -r $nexthop ($recipient)
bsmtp     unix  -       n       n       -       -       pipe
  flags=Fq. user=bsmtp argv=/usr/lib/bsmtp/bsmtp -t$nexthop -f$sender $recipient
scalemail-backend unix    -    n    n    -    2    pipe
  flags=R user=scalemail argv=/usr/lib/scalemail/bin/scalemail-store
${nexthop} ${user} ${extension}
mailman   unix  -       n       n       -       -       pipe
  flags=FR user=list argv=/usr/lib/mailman/bin/postfix-to-mailman.py
  ${nexthop} ${user}

Aside Note: In the above, from uucp on down, I do not think I need ay of that
but I have hesitated to comment it out as it all exists in
/var/spool/postfix/private/.

Here is postconf -n output:

[root@mg08 log]# postconf -n
alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
append_dot_mydomain = yes
berkeley_db_read_buffer_size = 262144
biff = no
bounce_size_limit = 1
config_directory = /etc/postfix
default_process_limit = 400
header_checks = regexp:/etc/postfix/header_checks
inet_interfaces = $myhostname, localhost
inet_protocols = ipv4
mailbox_size_limit = 0
masquerade_domains = $mydomain, cnm.edu, nmvc.org, nmvirtualcollege.org
max_use = 100
message_size_limit = 26214400
mydestination = $myhostname, $mydomain, localhost.localdomain
mydomain = cnm.edu
mynetworks = 198.133.178.0/23, 198.133.182.0/24, 198.133.181.0/24,
198.133.180.0/24, 172.16.0.0/12, 192.168.0.0/16, 10.0.0.0/8,
127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128
notify_classes = resource, software
postscreen_access_list = permit_mynetworks,
cidr:/etc/postfix/postscreen_access.cidr
postscreen_dnsbl_action = enforce
postscreen_dnsbl_reply_map = texthash:/etc/postfix/dnsbl_reply
postscreen_dnsbl_sites = zen.spamhaus.net*2 b.barracudacentral.org*1
dnsbl.sorbs.net*1 bl.spamcop.net*1
postscreen_dnsbl_threshold = 2
readme_directory = no
recipient_delimiter = +
relay_domains =
relayhost =
smtp_host_lookup = dns, native
smtpd_banner = cnm.edu ESMTP
smtpd_client_restrictions = reject_unauth_pipelining
check_client_access hash:/etc/postfix/whitelist check_client_access
cidr:/etc/postfix/cidr-ip check_client_access hash:/etc/postfix/access
permit_mynetworks reject_rbl_client [key].zen.dq.spamhaus.net
reject_rbl_client b.barracudacentral.org reject_rbl_client
bl.spamcop.net reject_rbl_client dnsbl.sorbs.net
smtpd_helo_required = yes
smtpd_helo_restrictions = permit_mynetworks check_helo_access
hash:/etc/postfix/helo-ip reject_invalid_helo_hostname
reject_non_fqdn_helo_hostname
smtpd_recipient_restrictions = permit_mynetworks
reject_unknown_recipient_domain reject_unlisted_recipient
reject_non_fqdn_recipient reject_unknown_recipient_domain
smtpd_relay_restrictions = permit_mynetworks reject_unauth_destination
smtpd_sender_restrictions = check_sender_access
hash:/etc/postfix/whitelist check_sender_access
hash:/etc/postfix/greylist check_sender_access
hash:/etc/postfix/access permit_mynetworks reject_non_fqdn_sender
reject_unknown_sender_domain
smtpd_use_tls = no
virtual_alias_maps = hash:/etc/postfix/virtualaliases

Is there a configuration change I must make to eliminate the three
types of concerning lines?


--
Robert Lopez
Unix Systems Administrator
Central New Mexico Community College (CNM)
525 Buena Vista SE
Albuquerque, New Mexico 87106
Reply | Threaded
Open this post in threaded view
|

Re: postscreen log lines reporting warnings and fatal errors

Wietse Venema
Robert Lopez:
> I am trying to understand the cause/causes of these log lines:
>
> 1) postfix/postscreen[####]: fatal: error [-30986] seeking
> /var/lib/postfix/postscreen_cache.db: Success

Your Berkeley DB is screwed up.

Code fragment from src/util/dict_db.c:

    /*
     * Database lookup.
     */
    status =
        dict_db->cursor->c_get(dict_db->cursor, &db_key, &db_value, db_function);
    if (status != 0 && status != DB_NOTFOUND)
        msg_fatal("error [%d] seeking %s: %m", status, dict_db->dict.name);

Did you build Postfix yourself or is this a package?

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: postscreen log lines reporting warnings and fatal errors

Robert Lopez
On Fri, Jun 14, 2013 at 3:09 PM, Wietse Venema <[hidden email]> wrote:

> Robert Lopez:
>> I am trying to understand the cause/causes of these log lines:
>>
>> 1) postfix/postscreen[####]: fatal: error [-30986] seeking
>> /var/lib/postfix/postscreen_cache.db: Success
>
> Your Berkeley DB is screwed up.
>
> Code fragment from src/util/dict_db.c:
>
>     /*
>      * Database lookup.
>      */
>     status =
>         dict_db->cursor->c_get(dict_db->cursor, &db_key, &db_value, db_function);
>     if (status != 0 && status != DB_NOTFOUND)
>         msg_fatal("error [%d] seeking %s: %m", status, dict_db->dict.name);
>
> Did you build Postfix yourself or is this a package?
>
>         Wietse

It was built from postfix-2.10.0.tar.gz, from Porcupine.


--
Robert Lopez
Unix Systems Administrator
Central New Mexico Community College (CNM)
525 Buena Vista SE
Albuquerque, New Mexico 87106
Reply | Threaded
Open this post in threaded view
|

Re: postscreen log lines reporting warnings and fatal errors

Wietse Venema
Robert Lopez:
> 1) postfix/postscreen[####]: fatal: error [-30986] seeking
> /var/lib/postfix/postscreen_cache.db: Success

Wietse:

> Your Berkeley DB is screwed up.
>
> Code fragment from src/util/dict_db.c:
>
>     status =
>         dict_db->cursor->c_get(dict_db->cursor, &db_key, &db_value, db_function);
>     if (status != 0 && status != DB_NOTFOUND)
>         msg_fatal("error [%d] seeking %s: %m", status, dict_db->dict.name);
>
> Did you build Postfix yourself or is this a package?

Robert Lopez:
> It was built from postfix-2.10.0.tar.gz, from Porcupine.

Then, you made a mistake. Most likely you have multiple copies of
Berkeley DB on the same system and now have Berkeley DB DLL hell.

My advice is to avoid installing multiple Berkeley DB copies, and
to use the Berkeley DB that comes with the operating system.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: postscreen log lines reporting warnings and fatal errors

Benny Pedersen-2
[hidden email] skrev den 2013-06-15 02:36:

> My advice is to avoid installing multiple Berkeley DB copies, and
> to use the Berkeley DB that comes with the operating system.

locate postfix/postscreen
ldd <result-path>

will show the problem why it fails

under gentoo its "ldd /usr/libexec/postfix/postscreen"

if its a break its fixed by issueing revdep-rebuild

--
senders that put my email into body content will deliver it to my own
trashcan, so if you like to get reply, dont do it
Reply | Threaded
Open this post in threaded view
|

Fwd: postscreen log lines reporting warnings and fatal errors

Robert Lopez
It would not surprise me in the least to find out I did something wrong.   :-}

I know I did "yum install db4-devel" as part of packages I believed
were prerequisites to installing Postfix.
My recall is that I was missing a /usr/include file when test building
a Postfix and I did a "yum provides" that lead me to the decision to
install db4-devel.

I am not convinced there are two copied of Berkeley DB installed.

Does this look like two Berkeley DB copies? ...

[root@mg08 ~]# locate postfix/postscreen
/etc/postfix/postscreen_access.cidr
/usr/libexec/postfix/postscreen
/var/lib/postfix/postscreen_cache.db
/var/www/postfix/postscreen.8.html
[root@mg08 ~]# ldd /usr/libexec/postfix/postscreen
    linux-vdso.so.1 =>  (0x00007fff31fff000)
    libpcre.so.0 => /lib64/libpcre.so.0 (0x00007fcc8fc38000)
    libdb-4.7.so => /lib64/libdb-4.7.so (0x00007fcc8f8c4000)
    libnsl.so.1 => /lib64/libnsl.so.1 (0x00007fcc8f6aa000)
    libresolv.so.2 => /lib64/libresolv.so.2 (0x00007fcc8f490000)
    libc.so.6 => /lib64/libc.so.6 (0x00007fcc8f0fd000)
    libpthread.so.0 => /lib64/libpthread.so.0 (0x00007fcc8eedf000)
    /lib64/ld-linux-x86-64.so.2 (0x00007fcc8fe6d000)
[root@mg08 ~]# locate libdb
/lib64/libdb-4.7.so
/lib64/libdbus-1.so.3
/lib64/libdbus-1.so.3.4.0
/usr/lib64/libdb-4.7.so
/usr/lib64/libdb.so
/usr/lib64/libdb_cxx-4.7.so
/usr/lib64/libdb_cxx.so
/usr/lib64/libdbus-glib-1.so.2
/usr/lib64/libdbus-glib-1.so.2.1.0
/usr/share/doc/rsyslog-5.8.10/omlibdbi.html
[root@mg08 ~]# locate include/db
/usr/include/db.h
/usr/include/db4
/usr/include/db_185.h
/usr/include/db_cxx.h
/usr/include/db4/db.h
/usr/include/db4/db_185.h
/usr/include/db4/db_cxx.h
/usr/local/src/postfix-2.10.0/include/db_common.h


This is an install on a VM instance of Red Hat Enterprise Linux Server
release 6.4 (Santiago), Linux mg08 2.6.32-358.6.1.el6.x86_64 #1 SMP
Fri Mar 29 16:51:51 EDT 2013 x86_64 x86_64 x86_64 GNU/Linux.


--
Robert Lopez
Unix Systems Administrator
Central New Mexico Community College (CNM)
525 Buena Vista SE
Albuquerque, New Mexico 87106
Reply | Threaded
Open this post in threaded view
|

Re: Fwd: postscreen log lines reporting warnings and fatal errors

Wietse Venema
Robert Lopez:
> It would not surprise me in the least to find out I did something wrong.   :-}
>
> I know I did "yum install db4-devel" as part of packages I believed
> were prerequisites to installing Postfix.
> My recall is that I was missing a /usr/include file when test building
> a Postfix and I did a "yum provides" that lead me to the decision to
> install db4-devel.

I suggest that you install a compiled version of Postfix, and that
you use a simpler program to become familiar with the process of
building your own binaries.

Running ldd(1) on Postfix will not show if some library has its own
dependency on a DIFFERENT Berkeley DB version.  While Postfix will
report library mis-matches if it can, other libraries may not, and
just thrash your memory.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Fwd: postscreen log lines reporting warnings and fatal errors

Robert Lopez
On Mon, Jun 17, 2013 at 2:11 PM, Wietse Venema <[hidden email]> wrote:

> I suggest that you install a compiled version of Postfix, and that
> you use a simpler program to become familiar with the process of
> building your own binaries.

There existed a project goal to install a postfix with postscreen.
The goal was set because one night a botnet had crashed two production
mail gateways which were both coming up on retirement dates.
The crashing had never been seen before (or since for that matter).

There exists another goal of moving all college RHEL4 and RHEL 5
physical servers to RHEL 6 on VM as they reach retirement.

The currently available Redhat yum package (binary) for RHEL 6 is postfix 2.6.6.

The ftp.wl0.org site has no package for RHEL 6.
It does have a 2.9 package for RHEL 5.

A development build of a VM using RHEL 5 and 2.9 from ftp.wl0.org was built.
Another development build of a VM using RHEL 6 and 2.10.0 from source was built.
A team of people examined both development servers and did not detect
the problem.

The postfix 2.10.0 compiled build on RHEL 6 was selected because it
satisfied both goals.

Another VM instance was built in a test environment using the exact
same scripts (except for IP and hostname; read from include file).
It was tested by another team for a few weeks and the current problem
was not detected.

A production server was built using all the same build scripts that
built the previous servers.
Only under real production load did the problem become apparent and
only after over two weeks of production use.

Wietse, Thank you. At this point I must take your advice to my team
and management to discuss our options.

--
Robert Lopez
Unix Systems Administrator
Central New Mexico Community College (CNM)
525 Buena Vista SE
Albuquerque, New Mexico 87106
Reply | Threaded
Open this post in threaded view
|

Re: Fwd: postscreen log lines reporting warnings and fatal errors

Robert Lopez
After looking at past logs an seeing the errors only began after the
email gateway had been running for a few weeks, I deleted the
/var/lib/postfix/postscreen_cache.db.
Restarting postfix now has a happy postscreen+bdb again.


--
Robert Lopez
Unix Systems Administrator
Central New Mexico Community College (CNM)
525 Buena Vista SE
Albuquerque, New Mexico 87106