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

Re: Postscreen: bad command startup -- throttling issues

Expand Messages
  • Wietse Venema
    ... You show only WARNING messages. postscreen logs an ERROR mesage before exiting with status 1. Are you using a syslog configuration that logs ERRORS and
    Message 1 of 11 , Feb 12, 2013
    • 0 Attachment
      LDB:
      > On 02/12/2013 08:35 AM, Wietse Venema wrote:
      > > egrep '(warning|error|fatal|panic):' /some/log/file | more
      >
      > Thank you for the response. I apologize for the delay.
      >
      > The log entries you requested are as follows and since then the postfix service
      > has been restarted many times:

      You show only WARNING messages.

      postscreen logs an ERROR mesage before exiting with status 1.

      Are you using a syslog configuration that logs ERRORS and WARNINGS
      to different files?

      Wietse
    • LDB
      ... My /var/log/mail.err file is empty. I am not seeing any other postscreen messages in any of the mail or mail.{info,err,warn} logs. Thanks, LDB
      Message 2 of 11 , Feb 13, 2013
      • 0 Attachment
        On Feb 12, 2013, at 5:05 PM, Wietse Venema <wietse@...> wrote:

        > LDB:
        >> On 02/12/2013 08:35 AM, Wietse Venema wrote:
        >>> egrep '(warning|error|fatal|panic):' /some/log/file | more
        >>
        >> Thank you for the response. I apologize for the delay.
        >>
        >> The log entries you requested are as follows and since then the postfix service
        >> has been restarted many times:
        >
        > You show only WARNING messages.
        >
        > postscreen logs an ERROR mesage before exiting with status 1.
        >
        > Are you using a syslog configuration that logs ERRORS and WARNINGS
        > to different files?
        >
        > Wietse

        My /var/log/mail.err file is empty. I am not seeing any other postscreen messages in any of the mail or mail.{info,err,warn} logs.

        Thanks,

        LDB
      • LDB
        ... I increased the debugging output in master.cf using -D -vvvvv . eb 13 21:23:14 server postfix/postfix-script[364]: stopping the Postfix mail system Feb 13
        Message 3 of 11 , Feb 13, 2013
        • 0 Attachment
          On 2/13/13 8:24 AM, LDB wrote:
          >
          >
          > On Feb 12, 2013, at 5:05 PM, Wietse Venema <wietse@...> wrote:
          >
          >> LDB:
          >>> On 02/12/2013 08:35 AM, Wietse Venema wrote:
          >>>> egrep '(warning|error|fatal|panic):' /some/log/file | more
          >>>
          >>> Thank you for the response. I apologize for the delay.
          >>>
          >>> The log entries you requested are as follows and since then the postfix service
          >>> has been restarted many times:
          >>
          >> You show only WARNING messages.
          >>
          >> postscreen logs an ERROR mesage before exiting with status 1.
          >>
          >> Are you using a syslog configuration that logs ERRORS and WARNINGS
          >> to different files?
          >>
          >> Wietse
          >
          > My /var/log/mail.err file is empty. I am not seeing any other postscreen messages in any of the mail or mail.{info,err,warn} logs.
          >
          > Thanks,
          >
          > LDB
          >

          I increased the debugging output in master.cf using "-D -vvvvv".


          eb 13 21:23:14 server postfix/postfix-script[364]: stopping the Postfix
          mail system
          Feb 13 21:23:14 server postfix/master[29847]: terminating on signal 15
          Feb 13 21:23:14 server postfix/postfix-script[451]: starting the Postfix
          mail system
          Feb 13 21:23:14 server postfix/master[452]: daemon started -- version
          2.8.11, configuration /etc/postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          syslog_facility = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: mail
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const mail
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          syslog_facility = mail
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          inet_protocols = ipv4
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: ipv4
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const ipv4
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          multi_instance_directories = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse:
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          multi_instance_directories =
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          multi_instance_group = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse:
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          multi_instance_group =
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          multi_instance_name = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse:
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          multi_instance_name =
          Feb 13 21:23:46 server postfix/postscreen[476]: name_mask: ipv4
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: myhostname
          = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: mydomain =
          example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: key.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          key.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update: myhostname
          = key.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: mydomain =
          example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: mail_name =
          (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: Postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const Postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update: mail_name =
          Postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: syslog_name
          = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse:
          ${multi_instance_name:postfix}${multi_instance_name?$multi_instance_name}
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          multi_instance_name =
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          multi_instance_name =
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: expand
          ${multi_instance_name:postfix}${multi_instance_name?$multi_instance_name} ->
          postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update: syslog_name
          = postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: mail_owner
          = postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          setgid_group = maildrop
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: maildrop
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const maildrop
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          mydestination = $myhostname, localhost.$mydomain, localhost, $mydomain,
          mail.$mydomain
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: $myhostname,
          localhost.$mydomain, localhost, $mydomain, mail.$mydomain
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: myhostname
          = key.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: key.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: mydomain =
          example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: mydomain =
          example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: mydomain =
          example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: expand
          $myhostname, localhost.$mydomain, localhost, $mydomain, mail.$mydomain
          -> key.example.net, localhost.example.net, localhost, example.net,
          mail.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: myorigin =
          $myhostname
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: $myhostname
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: myhostname
          = key.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: key.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: expand
          $myhostname -> key.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: relayhost =
          (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse:
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update: relayhost =
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          daemon_directory = /usr/lib/postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: /usr/lib/postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          /usr/lib/postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          data_directory = /var/lib/postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: /var/lib/postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          /var/lib/postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          command_directory = /usr/sbin
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: /usr/sbin
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const /usr/sbin
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          queue_directory = /var/spool/postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse:
          /var/spool/postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          /var/spool/postfix
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          process_id_directory = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: pid
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const pid
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          process_id_directory = pid
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          inet_interfaces = $myhostname
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: $myhostname
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: myhostname
          = key.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: key.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: expand
          $myhostname -> key.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          proxy_interfaces = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse:
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          proxy_interfaces =
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          double_bounce_sender = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: double-bounce
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          double-bounce
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          double_bounce_sender = double-bounce
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          default_privs = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: nobody
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const nobody
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          default_privs = nobody
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          alias_database = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: hash:/etc/aliases
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          hash:/etc/aliases
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          alias_database = hash:/etc/aliases
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          mail_release_date = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: 20120520
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const 20120520
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          mail_release_date = 20120520
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          mail_version = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: 2.8.11
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const 2.8.11
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          mail_version = 2.8.11
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          default_database_type = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: hash
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const hash
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          default_database_type = hash
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          hash_queue_names = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: deferred, defer
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          deferred, defer
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          hash_queue_names = deferred, defer
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          recipient_delimiter = +
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: +
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const +
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          relay_domains = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: $mydestination
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          mydestination = $myhostname, localhost.$mydomain, localhost, $mydomain,
          mail.$mydomain
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: $myhostname,
          localhost.$mydomain, localhost, $mydomain, mail.$mydomain
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: myhostname
          = key.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: key.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: mydomain =
          example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: mydomain =
          example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: mydomain =
          example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: expand
          $mydestination -> key.example.net, localhost.example.net, localhost,
          example.net, mail.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          relay_domains = key.example.net, localhost.example.net, localhost,
          example.net, mail.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          fast_flush_domains = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: $relay_domains
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          relay_domains = key.example.net, localhost.example.net, localhost,
          example.net, mail.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse:
          key.example.net, localhost.example.net, localhost, example.net,
          mail.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: expand
          $relay_domains -> key.example.net, localhost.example.net, localhost,
          example.net, mail.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          fast_flush_domains = key.example.net, localhost.example.net, localhost,
          example.net, mail.example.net
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          export_environment = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: TZ
          MAIL_CONFIG LANG
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const TZ
          MAIL_CONFIG LANG
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          export_environment = TZ MAIL_CONFIG LANG
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          import_environment = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: MAIL_CONFIG
          MAIL_DEBUG MAIL_LOGTAG TZ XAUTHORITY DISPLAY LANG=C
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          MAIL_CONFIG MAIL_DEBUG MAIL_LOGTAG TZ XAUTHORITY DISPLAY LANG=C
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          import_environment = MAIL_CONFIG MAIL_DEBUG MAIL_LOGTAG TZ XAUTHORITY
          DISPLAY LANG=C
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          mynetworks_style = subnet
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: subnet
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const subnet
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          debug_peer_list = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse:
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          debug_peer_list =
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          default_verp_delimiters = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: +=
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const +=
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          default_verp_delimiters = +=
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          verp_delimiter_filter = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: -=+
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const -=+
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          verp_delimiter_filter = -=+
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          parent_domain_matches_subdomains = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse:
          debug_peer_list,fast_flush_domains,mynetworks,permit_mx_backup_networks,qmqpd_authorized_clients,relay_domains,smtpd_access_maps
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          debug_peer_list,fast_flush_domains,mynetworks,permit_mx_backup_networks,qmqpd_authorized_clients,relay_domains,smtpd_access_maps
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          parent_domain_matches_subdomains =
          debug_peer_list,fast_flush_domains,mynetworks,permit_mx_backup_networks,qmqpd_authorized_clients,relay_domains,smtpd_access_maps
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          alternate_config_directories = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse:
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          alternate_config_directories =
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          bounce_service_name = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: bounce
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const bounce
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          bounce_service_name = bounce
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          cleanup_service_name = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: cleanup
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const cleanup
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          cleanup_service_name = cleanup
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          defer_service_name = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: defer
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const defer
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          defer_service_name = defer
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          pickup_service_name = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: pickup
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const pickup
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          pickup_service_name = pickup
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          queue_service_name = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: qmgr
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const qmgr
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          queue_service_name = qmgr
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          rewrite_service_name = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: rewrite
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const rewrite
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          rewrite_service_name = rewrite
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          showq_service_name = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: showq
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const showq
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          showq_service_name = showq
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          error_service_name = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: error
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const error
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          error_service_name = error
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          flush_service_name = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: flush
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const flush
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          flush_service_name = flush
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          address_verify_service_name = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: verify
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const verify
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          address_verify_service_name = verify
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          trace_service_name = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: trace
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const trace
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          trace_service_name = trace
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          proxymap_service_name = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: proxymap
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const proxymap
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          proxymap_service_name = proxymap
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          proxywrite_service_name = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: proxywrite
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const proxywrite
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          proxywrite_service_name = proxywrite
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          internal_mail_filter_classes = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse:
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          internal_mail_filter_classes =
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          multi_instance_wrapper = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse:
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          multi_instance_wrapper =
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: max_use =
          (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update: max_use = 100
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup: dont_remove
          = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update: dont_remove = 0
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          line_length_limit = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          line_length_limit = 2048
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          message_size_limit = 0
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: 0
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const 0
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          hash_queue_depth = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          hash_queue_depth = 1
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          fork_attempts = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          fork_attempts = 5
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          deliver_lock_attempts = (notfound)
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_update:
          deliver_lock_attempts = 20
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          debug_peer_level = 2
          Feb 13 21:23:46 server postfix/postscreen[476]: mac_parse: 2
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_eval: const 2
          Feb 13 21:23:46 server postfix/postscreen[476]: dict_lookup:
          fault_injection_code = (notfound)
          .
          .
          .
          .
          .
          .
          .
          .
          $daemon_directory/$process_name $process_id & sleep 5 ->
          PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin? ddd
          /usr/lib/postfix/postscreen 476 & sleep 5
          Feb 13 21:23:46 server postfix/postscreen[476]: running:
          PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin? ddd
          /usr/lib/postfix/postscreen 476 & sleep 5
          Feb 13 21:23:51 server postfix/postscreen[476]: match_string: mynetworks
          ~? debug_peer_list
          Feb 13 21:23:51 server postfix/postscreen[476]: match_string: mynetworks
          ~? fast_flush_domains
          Feb 13 21:23:51 server postfix/postscreen[476]: match_string: mynetworks
          ~? mynetworks
          Feb 13 21:23:51 server postfix/postscreen[476]: dict_open: calling hash
          open routine
          Feb 13 21:23:51 server postfix/postscreen[476]: Compiled against
          Berkeley DB: 4.8.30?
          Feb 13 21:23:51 server postfix/postscreen[476]: Run-time linked against
          Berkeley DB: 4.8.30?
          Feb 13 21:23:52 server postfix/master[452]: warning: process
          /usr/lib/postfix/postscreen pid 476 exit status 1
          Feb 13 21:23:52 server postfix/master[452]: warning:
          /usr/lib/postfix/postscreen: bad command startup -- throttling
        • Wietse Venema
          ... I did not ask you to do that. postscreen logs the error message and you just need to learn where to find it. Adding more logging just makes the information
          Message 4 of 11 , Feb 13, 2013
          • 0 Attachment
            LDB:
            > >> You show only WARNING messages.
            > >>
            > >> postscreen logs an ERROR mesage before exiting with status 1.
            > >>
            > >> Are you using a syslog configuration that logs ERRORS and WARNINGS
            > >> to different files?
            > >>
            > >> Wietse
            > >
            > > My /var/log/mail.err file is empty. I am not seeing any other postscreen messages in any of the mail or mail.{info,err,warn} logs.
            >
            > I increased the debugging output in master.cf using "-D -vvvvv".

            I did not ask you to do that. postscreen logs the error message
            and you just need to learn where to find it. Adding more logging
            just makes the information harder to find.

            Start with /etc/syslog.conf and examine EVERY FILE listed there.

            Wietse
          • LDB
            ... I agree and I understood. Although, here is the impetus behind my change to produce more verbose logs. Postfix is seemingly logging to the correct
            Message 5 of 11 , Feb 13, 2013
            • 0 Attachment
              On Feb 13, 2013, at 3:14 PM, Wietse Venema <wietse@...> wrote:

              > LDB:
              >>>> You show only WARNING messages.
              >>>>
              >>>> postscreen logs an ERROR mesage before exiting with status 1.
              >>>>
              >>>> Are you using a syslog configuration that logs ERRORS and WARNINGS
              >>>> to different files?
              >>>>
              >>>> Wietse
              >>>
              >>> My /var/log/mail.err file is empty. I am not seeing any other postscreen messages in any of the mail or mail.{info,err,warn} logs.
              >>
              >> I increased the debugging output in master.cf using "-D -vvvvv".
              >
              > I did not ask you to do that. postscreen logs the error message
              > and you just need to learn where to find it. Adding more logging
              > just makes the information harder to find.
              >
              > Start with /etc/syslog.conf and examine EVERY FILE listed there.
              >
              > Wietse

              I agree and I understood. Although, here is the impetus behind my change to produce more verbose logs.


              Postfix is seemingly logging to the correct facility:

              server:/var/log # postconf -d | grep syslog
              syslog_facility = mail
              syslog_name = ${multi_instance_name:postfix}${multi_instance_name?$multi_instance_name}



              Syslog is seemingly configured properly, as well:

              server:/var/log # grep mail /etc/rsyslog.conf
              # email-messages
              mail.* -/var/log/mail
              mail.info -/var/log/mail.info
              mail.warning -/var/log/mail.warn
              mail.err /var/log/mail.err
              *.*;mail.none;news.none -/var/log/messages



              But yet, /var/log/mail.err, remains empty.

              Once again, I am refraining from changing much of the defaults in Postfix or within the OS.

              Thank you,

              LDB
            • Wietse Venema
              ... I asked you to examine EVERY FILE listed there. Apparently, you don t understand plain English. Maybe someone else has more patience. I am done with this
              Message 6 of 11 , Feb 13, 2013
              • 0 Attachment
                > >> I increased the debugging output in master.cf using "-D -vvvvv".
                > >
                > > I did not ask you to do that. postscreen logs the error message
                > > and you just need to learn where to find it. Adding more logging
                > > just makes the information harder to find.
                > >
                > > Start with /etc/syslog.conf and examine EVERY FILE listed there.

                > server:/var/log # grep mail /etc/rsyslog.conf

                I asked you to examine EVERY FILE listed there. Apparently, you
                don't understand plain English.

                Maybe someone else has more patience. I am done with this thread.

                Wietse
              • Reindl Harald
                ... and what is in the others? cat /var/log/mail* would have been the minimum i expected as reply and a look in /var/log/messages is also not wrong
                Message 7 of 11 , Feb 14, 2013
                • 0 Attachment
                  Am 13.02.2013 22:14, schrieb LDB:
                  > Syslog is seemingly configured properly, as well:
                  >
                  > server:/var/log # grep mail /etc/rsyslog.conf
                  > # email-messages
                  > mail.* -/var/log/mail
                  > mail.info -/var/log/mail.info
                  > mail.warning -/var/log/mail.warn
                  > mail.err /var/log/mail.err
                  > *.*;mail.none;news.none -/var/log/messages
                  >
                  > But yet, /var/log/mail.err, remains empty

                  and what is in the others?

                  "cat /var/log/mail*" would have been the minimum i expected as
                  reply and a look in /var/log/messages is also not wrong
                Your message has been successfully submitted and would be delivered to recipients shortly.