d--j / go-milter

Go library to write mail filters
BSD 2-Clause "Simplified" License
12 stars 3 forks source link

What's the best place to log final response? #13

Open iredmail opened 1 year ago

iredmail commented 1 year ago

I tried to log final response of processed message inAbort(), Cleanup(), but they both got called 2 or more times for one message.

So the question is, where should i log final response of processed message? and it should be called only once.

d--j commented 1 year ago

Cleanup() ist the right place. Abort() e.g. also gets called after the client of the MTA sessions issued a STARTTLS so not at the end of the transaction.

Cleanup() might in deed be called multiple times – but it is guranteed to be at least called once for each SMTP transaction. Since your milter backend is only valid for one transaction, just set a boolean


func (b *MyBackend) Cleanup() {
  if b.cleanupCalled {
    return
  }
  b.cleanupCalled = true
  // do cleanup
}
iredmail commented 1 year ago

Thanks for the suggestion. Is it better add a new method to be called ONCE after processed?

d--j commented 1 year ago

On second thought, Cleanup() is called at the end of the SMTP session (or when a SMFIC_QUIT_NC message is sent, or when the connection to the MTA fails). An SMTP session can have multiple messages.

So Cleanup() could log that the SMTP session has ended, but not that a single message has been processed.

The start and end of a message has to be figured out in the Milter backend. Have a look at https://github.com/d--j/go-milter/blob/main/mailfilter/backend.go to see how the mailfilter Backend does this.

Cleanup() is for cleaning up resources you may have opened for this SMTP transaction, e.g.:

https://github.com/d--j/go-milter/blob/f4e3ac5ed1980580d8ba4e17f78386abbc626327/mailfilter/transaction.go#L86-L97

iredmail commented 1 year ago

Can we add a new method which will be called ONCE after a single message has been processed?

For easy maintenance and troubleshooting, Milter server must log the final response and basic info of each message, so this method will be very neat and make milter development easier. :)

Maybe one more method for end of smtp transaction (and called just once)?

iredmail commented 1 year ago

Checked session.go, Cleanup() is called in 4 places:

  1. case wire.CodeQuitNewConn: https://github.com/d--j/go-milter/blob/115badd800c854f60252bd087533e0d12a5f4525/session.go#L308-L310
  2. case wire.CodeQuit: https://github.com/d--j/go-milter/blob/115badd800c854f60252bd087533e0d12a5f4525/session.go#L316-L317
  3. !resp.Continue(): https://github.com/d--j/go-milter/blob/115badd800c854f60252bd087533e0d12a5f4525/session.go#L393-L394
  4. m.backend != nil: https://github.com/d--j/go-milter/blob/115badd800c854f60252bd087533e0d12a5f4525/session.go#L329-L333

Seems none of them can precisely match each processed message. I suggest adding a new method to be called at the end of each processed message.

d--j commented 1 year ago

Sorry for beeing a little bit slow in understanding – can you explain why you need something other than EndOfMessage()?

https://github.com/d--j/go-milter/blob/30d4d62396d57db43116e28f8bb5c5b61ecf2478/server.go#L69-L75

In case the milter backend opts to reject the message before this callback, the milter backend already knows that the current message has ended, why should the serverSession need to tell the backend what the backend already told it?

iredmail commented 1 year ago

EndOfMessage is not applicable at all, for example:

There's no email message submitted at all, hence it doesn't go through EndOfMessage, so it doesn't trigger the logging.

d--j commented 1 year ago

Hello @iredmail

Please have a look at PR #17 – I introduced a new method ConnectionClosed that gets called when the the connection to the MTA was closed. Hopefully this might be useful for your logging purposes.