Matus UHLAR - fantomas via Postfix-users:
> >Matus UHLAR - fantomas via Postfix-users:
> >> When processing logs I have noticed that some queue IDs get reported by
> >> smtpd when DATA phase starts, but when connection is lost, those IDs aren't
> >> reported as lost.
> >>
> >> Example:
> >>
> >> Sep 2 16:51:11 mail postfix/smtps/smtpd[3697]: connect from
> >> a.b.t-com.sk[178.41.x.y]
> >> Sep 2 16:51:11 mail postfix/smtps/smtpd[3697]: 4WyBXH6Dp7z6C7g:
> >> client=a.b.t-com.sk[178.41.x.y], sasl_method=LOGIN, sasl_username=redacted1
> >> Sep 2 16:51:11 mail postfwd2/policy[7072]: [RULES] rule=23,
> >> id=GLOBAL-RATE-02, queue=4WyBXH6Dp7z6C7g, client=a.b.t-com.sk[178.41.x.y],
> >> user=redacted1, sender=<redact...@example.com>,
> >> recipient=<redact...@example.com>, helo=<redacted3>, proto=ESMTP,
> >> state=DATA, rate=rate/D/0.00s, delay=0.01s,
> >> hits=GLOBAL-RATE-01;GLOBAL-RATE-02, action=WARN GLOBAL rate limit of C
> >> messages in 1 hour exceeded [D hits]
> >> Sep 2 16:51:11 mail postfix/smtps/smtpd[3697]: 4WyBXH6Dp7z6C7g: warn:
> >> DATA from a.b.t-com.sk[178.41.x.y]: GLOBAL rate limit of C messages in 1
> >> hour exceeded [D hits]; from=<redact...@example.com>
> >> to=<redact...@example.com> proto=ESMTP helo=<redacted3>
> >> Sep 2 16:51:15 mail postfix/smtps/smtpd[3697]: lost connection after DATA
> >> (6 bytes) from a.b.t-com.sk[178.41.x.y]
> >>
> >>
> >> Could the last message "lost connection" report the queue id, so log parser
> >> would drop that queue id?
>
> On 04.11.24 11:55, Wietse Venema via Postfix-users wrote:
> >No, but I do have a different suggestion.
> >
> >The queue ID is generated by the cleanup server. That server could
> >log that a transaction is aborted. That would also signal an aborted
> >transaction from non-SMTP sources such as the pickup daemon, or
> >when smtpd process aborts in the middle of a transaction after some
> >fatal or panic error condition.
>
> This is good idea as well (maybe even better) but knowinf the queue ID in
> the "lost connection" log makes it easier to debug problem with failing
> connections.
>
> I guess you don't want to change format of existing log messages.
I guess that designing a change requires a bigger picture than
just the immediate 'problem' at hand.
The "lost connection' error is logged in one of several code paths
that lead to an unexpected end of an SMTP session.
1 - Shared code paths in smtpd for lost connection, timeout, too
many errors. This is good.
2 - Distinct logging code paths in smtpd for the above errors after
DATA, after BDAT, or after end-of-message. Each code path needs
to be updated to log the queue ID. This is a potential code
maintenance problem when new code paths are needed.
3 - Shared logging code path in smtpd for all disconnects (after
error or no error). This will not be logged if smtpd fails, but
that may be OK.
4 - Shared logging code path in cleanup for all unfinished message
transactions. This will be logged even if smtpd fails, and also
covers non-smtpd email streams.
5 - Shared logging code paths in smtpd or cleanup for all unfinished
message transactions. The smtpd says 'I will log unfinished
message transactions' so that cleanup will not log them. This
will not be logged if smtpd fails, but that may be OK.
Coming back to the original problem, if the idea is to log unfinished
message transactions, then I think that that should not be limited
to just the 'lost connection' case.
I proposed to log the queue ID in [4]. If we log the queue ID in
[3] instead, then that won't log non-smtpd unfinished message
transactions, but that may be OK. Doing [5] is a little clumsy but
may doable.
If the problem is to make logfile analysis more robust, then I think
that all unfinished message transactions should be logged, or at last
those handled by smtpd.
Wietse
_______________________________________________
Postfix-users mailing list -- postfix-users@postfix.org
To unsubscribe send an email to postfix-users-le...@postfix.org
