Wietse Venema wrote:
>
> Many people don't need the "log queue file deletion" record, so
> what about making the logging configurable.
>
> A lot of the Postfix logging is distributed over different processes
> so as to make trouble shooting possible. smtpd logs connection info
> so you have some clue of what happens even when no mail transaction
> is completed; cleanup logs the message ID rather than leaving that
> up to the qmgr, because a lot of time may pass before the qmgr gets
> around to open the queue file; qmgr logs queueID and sender, so
> you know it is not stuck; a delivery agent logs successful/failed
> delivery itself rather than leaving that up to the qmgr, because
> the qmgr process may no longer be around by that time.
>
> It is possible to compress all this information into fewer records,
> but that requires a stateful logging process thet flushes the buffer
> when a message life ends or when certain checkpoints are passed.
> I'm not sure the solution's complexity is worth the effort.

That's should not be so difficult as described above. In my original
post I demonstrated how logs might looks like with current architecture.
What is needed is a more strong definition of "message lifetime" (may
be "solved" by e.g. adding even more lines like "qid: start" and
"qid: finished") and moving some info between lines (qmgr's sender
into delivery agent's line). This is all quite trivial changes and
will allow very simple manipulations (esp. useful for grep-like
quick-find).

> It is extremely unlikely that the frst implementation of a program
> is the right one, and Postfix is not an exception.
>
> The Postfix logging is still first-generation code that needs to
> be replaced by more configurable mechanisms. Changing it from one
> hard-coded logging format to another hard-coded logging format is
> only a waste of time, in my opinion.

Configurable logs may be needed only to preserve compatibility. If
postfix will log enouth and more-or-less easily parseable it will be
sufficient. At the end, configurable log will break "standard"
log-analisys tools or make them too complex.

Current "log issues" are due to absense of a strong "log rules" IMHO
(this is normal -- noone can define *all* aspects of a program before
writing implementation). Current log format, while somewhat "ad-hoc"
in every log line, is already almost good. It is not difficult to
define those rules and to follow them within current infrastructure.
There is no need to *redefine* logging or to reduce number of logged
lines. What I thought about is to rearrange logging -- only minor
rearrangements will be sufficient. Moreover, in some situations this
will help to reduce number of log lines.

Here is a summary (not all aspects may be touched):

o Start of a message lifetime. Should be easily findable:

 cleanup: QID: proto=ESMTP from=<from> client=<client> helo=<helo>
 cleanup: QID: proto=internal from=<double-bounce>
 cleanup: QID: proto=pickup from=<from> uid=<uid>
 cleanup: QID: proto=forward from=<from> expanded-from=<orig-dest>

 (or corresponding "injectors" or "receivers" -- smtpd, pickup, ...).
 Currently, only smtpd (and qmqpd) and pickup lines are here. Note
 additional helo= argument.

o more accurate rejects. Should include all information so that it
 is easy to find and collect stats:

 smtpd: QID: reject: \
  client=<cli> helo=<helo> from=<from> rcpt=<rcpt> rule=check_client_access \
  stage=RCPT msg=554 Client host rejected: ...

 Note the differences: presence of QID, presence of complete information in
 easily parseable format, and the message sent to client is at the end.
 Obviously, if a message was rejected at CONNECT or HELO stage, none of
 rcpt/from or even QID should be there.

 The same is for content-based rejects. All info about message context:

 cleanup: QID: reject: \
   uid=<uid> from=<from> rcpt=<rcpt> \
   header=<X-Mailer: Mail Bomber> msg=Message Content Rejected

 (an example for pickup submission). Alternatively, using the same
 multi-attr protocol, from pickup itself:

  pickup: QID: reject:
   uid=<uid> from=<from> rcpt=<rcpt> \
   header=...

 This is questionable if content-rejects should be logged with every
 recipient -- will be too many lines in log if the message will be
 repeated for every rcpt, but logging only one recipient is obviously
 incorrect (either all or none or one if single).

o End of message lifetime for rejected messages:

 smtpd: QID: cancelled: no valid rcpts, too many errors, timeout exceeded,
  disconnect and the like.

o qmgr lines may be the same. It should be sufficient to have:

  qmgr: QID: nrcpt=xxx

o for all delivery agents -- log from and size in addition to rcpt and status
  (move or add qmgr info):

  smtp: QID: from=<from> size=size to=<to> delay=delay status=sent (...)

o log all deletion of a queue file (end of message lifetime):

  qmgr: QID: done, delay=xxx

o some log lines (like smtpd's "client connect/disconnect" lines, qmgr's
  start-of-delivery lines, may be cleanup's (resent-)message-id lines)
  may be made at level DEBUG, not INFO so it is easy to turn them off
  if needed.

---
The above is only a brief view.  In addition, it may be helpful to have
an ability to filter only a few lines with a regexp and got a complete
info.  For example (and this is covered by the above), grepping for
" reject: " will give all rejects with *complete* info (missing for
content-checks currently), grepping for " cancelled: " will give all
unsuccesseful attempts to construct a message, grepping for something
like " (start|done) " will show average message lifetimes, for "proto=internal" --
internal bounces (to be distinguishable from double-bounces) and so on.
This is a yet-to-be defined things, but an overall structure should
be clean already.
What I want currently is to discuss and define the rules.  Note that
all the above is very easy fits into current postfix structure -- very
minor changes will be required to implement this.
Regards,
 Michael.
-
To unsubscribe, send mail to majordomopostfix.org with content
(not subject): unsubscribe postfix-users

• Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]