Loading ...
Sorry, an error occurred while loading the content.

postscreen log lines reporting warnings and fatal errors

Expand Messages
  • 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
    Message 1 of 9 , Jun 14, 2013
    View Source
    • 0 Attachment
      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
    • Wietse Venema
      ... 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,
      Message 2 of 9 , Jun 14, 2013
      View Source
      • 0 Attachment
        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
      • Robert Lopez
        ... 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
        Message 3 of 9 , Jun 14, 2013
        View Source
        • 0 Attachment
          On Fri, Jun 14, 2013 at 3:09 PM, Wietse Venema <wietse@...> 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
        • Wietse Venema
          ... 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
          Message 4 of 9 , Jun 14, 2013
          View Source
          • 0 Attachment
            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
          • Benny Pedersen
            ... locate postfix/postscreen ldd will show the problem why it fails under gentoo its ldd /usr/libexec/postfix/postscreen if its a break its
            Message 5 of 9 , Jun 14, 2013
            View Source
            • 0 Attachment
              wietse@... 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
            • 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
              Message 6 of 9 , Jun 17, 2013
              View Source
              • 0 Attachment
                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
              • Wietse Venema
                ... 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
                Message 7 of 9 , Jun 17, 2013
                View Source
                • 0 Attachment
                  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
                • Robert Lopez
                  ... 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
                  Message 8 of 9 , Jun 17, 2013
                  View Source
                  • 0 Attachment
                    On Mon, Jun 17, 2013 at 2:11 PM, Wietse Venema <wietse@...> 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
                  • 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
                    Message 9 of 9 , Jun 18, 2013
                    View Source
                    • 0 Attachment
                      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
                    Your message has been successfully submitted and would be delivered to recipients shortly.