'X-Envelope-From' missing in 2.7.0 ?

[Mark Martinec]

Amedeo,

Actually, the envelope sender address is also reflected in the
main log entry. So what was the amavisd log line corresponding
to the problem message - was it a 'Blocked ... <> -> ...'
or a 'Blocked ... <MAILER-DAEMON> -> ...' ?

> I can try, but first I need to find a better way to capture it
> without "log-level5-debug" all traffic for weeks! :)
> .. stay tuned ;-)

The 2.8.0-pre* brings just such a feature - assuming the trouble can
be detected some time before the end of processing of a message. It may
be an overkill for your purpose, but is perhaps worth considering.
Release notes say (slightly rephrased from the last -pre):


NEW FEATURES

- as a debugging aid it is now possible that a late event triggers full
  logging of earlier events that occurred during processing of a current
  mail message. This is implemented by writing all log events to a temporary
  file regardless of their log level and of the current $log_level setting.
  A later event can cause the captured temporary log to be copied to a
  regular log. Each child process keeps its own temporary log file open
  all the time, the file is rewound and truncated after each mail message
  processing and reused for the next capture, so its size rarely exceeds
  about 50 kB.

  Maintaining a temporary capture log is enabled by setting a configuration
  variable $enable_log_capture to true:
    $enable_log_capture = 1;

  Enabling a log capture costs a little bit of resources as amavisd needs
  to assemble and format all log messages regardless of their log level, not
  benefiting from early pruning of log entries not reaching the $log_level.
  Nevertheless the small overhead is quite acceptable when troubleshooting
  some rarely occurring problem and keeping $log_level permanently at the
  max is not acceptable due to sheer volume of debug logging.

  The captured log is read from a temporary file and copied to a regular
  log as log level 1 entries (i.e. at LOG_INFO syslog priority) if a
  dynamic variable $enable_log_capture_dump is true by the end of mail
  message processing. A chunk of captured log entries is preceded/ended
  by a log line:
    CAPTURED DEBUG LOG DUMP BEGINS
    CAPTURED DEBUG LOG DUMP ENDS
  and each such log entry has a prepended timestamp (hours, minutes,
  seconds with milliseconds) of a capture time.

  The $enable_log_capture_dump variable can be turned on directly
  by some debugging patch code, but is more conveniently loaded by
  activating a policy bank, e.g.:

  $policy_bank{'SLOW'} = {
    enable_log_capture_dump => 1,
  };

  $policy_bank{'GOTCHA'} = {
    enable_log_capture_dump => 1,
  };

  which can be loaded for example by a custom hook, e.g.:

  sub after_send {
    my($self,$conn,$msginfo) = @_;
    if (Time::HiRes::time - $msginfo->rx_time > 5.5) {
      Amavis::load_policy_bank('SLOW', $msginfo);
    }
    # or perhaps:
    if ($msginfo->sender =~ /some-regexp/) {
      Amavis::load_policy_bank('GOTCHA', $msginfo);
    }
  }

  Btw, the only purpose of having two different policy banks in the example
  is to be able to see at a glance in the log which one was activated.



Mark