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

Re: Postscreen: bad command startup -- throttling issues

Expand Messages
  • 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 1 of 11 , Feb 13, 2013
      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 2 of 11 , Feb 13, 2013
        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 3 of 11 , Feb 13, 2013
          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 4 of 11 , Feb 13, 2013
            > >> 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 5 of 11 , Feb 14, 2013
              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.