connection: add MAIL and RCPT to results

[msimerson]

• stores all sender and recipient attempts in results_store
• move rcpt incrementing into rcpt_incr, which also saves to results

replaces 10 of these:

this.transaction.rcpt_count[action]++;
this.rcpt_count[action]++;

with 10 of this:

this.rcpt_incr('accept');  // or 'reject' or 'tempfail'

This change drains some impetus for #945

[smfreegard]

Sorry - I don't like this.

If you're scraping logs or using something like Splunk (probably Logstash too), then having a log format that is the same for every instance of that log line is desirable and this changes it completely depending on conditions.

Quite often I do things like this:

$ grep ' recipient ' /var/log/maillog | grep -Po 'code=\S+' | sort | uniq -c | sort -rn
   7359 code=DENY
   4682 code=OK
   1027 code=CONT
    303 code=DENYSOFT
     42 code=DENYSOFTDISCONNECT

That becomes impossible after these changes.

I also don't like it logging under [mail_from] and [rcpt_to] .vs. [core]. Currently you can grep your logs for only core output easily and discard the plugin output and this change will break any existing parsers. It's also clear where the output is coming from.

You're also not quoting strings so; msg=MX without an A record is going to be far harder to capture than msg="MX without an A record" e.g. via msg="([^"]+)"

You appear to have found a bug somewhere as 1027 code=CONT should be impossible on my install and indeed looking at the logs; somehow the code returned by core was CONT when in actual fact the plugin returned OK - I'm looking in to why now.

Logging changes should be treated like API changes and things that fundamentally change the format should only be done on a major version bump, documented and warned about accordingly.

Adding a new disposition=[accepted|tempfailed[+drop]|rejected[+drop]] field on the end of the existing sender, recipient and message log lines would be a fine compromise though to make it clearer for those that don't understand what the code=constant means whilst retaining the existing format and functionality.

[msimerson]

My main concern is getting the data into ResultStore so that it ends up in Elasticsearch. Perhaps another solution is to leave the existing lognotice lines in place and turn off the emit: true options to result_store.

[smfreegard]

As long as the logging remains as it is and we still have the existing counters; then I've got no problem at all with adding this stuff to ResultStore as it seems like a pretty sensible thing to do.

I've found the cause of the code=CONT being logged incorrectly; it's because hook_rcpt returned OK at which point the log output is generated by rcpt_ok_respond() instead, so in this case if hook_rcpt_ok returns CONT; it should actually be logged as OK instead.

[msimerson]

Is removing the empty msg="" strings okay?

[smfreegard]

No - sorry.

[msimerson]

Log message affecting changes have been removed.