Add metric by status for all message processed by smtp

This commit is contained in:
Thomas Paradis 2021-04-07 15:21:26 +02:00
parent b050cdff02
commit 3abd6f4572
2 changed files with 47 additions and 3 deletions

View File

@ -56,6 +56,8 @@ type PostfixExporter struct {
smtpDelays *prometheus.HistogramVec smtpDelays *prometheus.HistogramVec
smtpTLSConnects *prometheus.CounterVec smtpTLSConnects *prometheus.CounterVec
smtpConnectionTimedOut prometheus.Counter smtpConnectionTimedOut prometheus.Counter
smtpProcesses *prometheus.CounterVec
// should be the same as smtpProcesses{status=deferred}, kept for compatibility, but this doesn't work !
smtpDeferreds prometheus.Counter smtpDeferreds prometheus.Counter
smtpdConnects prometheus.Counter smtpdConnects prometheus.Counter
smtpdDisconnects prometheus.Counter smtpdDisconnects prometheus.Counter
@ -66,6 +68,7 @@ type PostfixExporter struct {
smtpdSASLAuthenticationFailures prometheus.Counter smtpdSASLAuthenticationFailures prometheus.Counter
smtpdTLSConnects *prometheus.CounterVec smtpdTLSConnects *prometheus.CounterVec
unsupportedLogEntries *prometheus.CounterVec unsupportedLogEntries *prometheus.CounterVec
// same as smtpProcesses{status=deferred}, kept for compatibility
smtpStatusDeferred prometheus.Counter smtpStatusDeferred prometheus.Counter
opendkimSignatureAdded *prometheus.CounterVec opendkimSignatureAdded *prometheus.CounterVec
} }
@ -289,7 +292,7 @@ var (
logLine = regexp.MustCompile(` ?(postfix|opendkim)(/(\w+))?\[\d+\]: (.*)`) logLine = regexp.MustCompile(` ?(postfix|opendkim)(/(\w+))?\[\d+\]: (.*)`)
lmtpPipeSMTPLine = regexp.MustCompile(`, relay=(\S+), .*, delays=([0-9\.]+)/([0-9\.]+)/([0-9\.]+)/([0-9\.]+), `) lmtpPipeSMTPLine = regexp.MustCompile(`, relay=(\S+), .*, delays=([0-9\.]+)/([0-9\.]+)/([0-9\.]+)/([0-9\.]+), `)
qmgrInsertLine = regexp.MustCompile(`:.*, size=(\d+), nrcpt=(\d+) `) qmgrInsertLine = regexp.MustCompile(`:.*, size=(\d+), nrcpt=(\d+) `)
smtpStatusDeferredLine = regexp.MustCompile(`, status=deferred`) smtpStatusLine = regexp.MustCompile(`, status=(\w+) `)
smtpTLSLine = regexp.MustCompile(`^(\S+) TLS connection established to \S+: (\S+) with cipher (\S+) \((\d+)/(\d+) bits\)`) smtpTLSLine = regexp.MustCompile(`^(\S+) TLS connection established to \S+: (\S+) with cipher (\S+) \((\d+)/(\d+) bits\)`)
smtpConnectionTimedOut = regexp.MustCompile(`^connect\s+to\s+(.*)\[(.*)\]:(\d+):\s+(Connection timed out)$`) smtpConnectionTimedOut = regexp.MustCompile(`^connect\s+to\s+(.*)\[(.*)\]:(\d+):\s+(Connection timed out)$`)
smtpdFCrDNSErrorsLine = regexp.MustCompile(`^warning: hostname \S+ does not resolve to address `) smtpdFCrDNSErrorsLine = regexp.MustCompile(`^warning: hostname \S+ does not resolve to address `)
@ -359,8 +362,11 @@ func (e *PostfixExporter) CollectFromLogLine(line string) {
addToHistogramVec(e.smtpDelays, smtpMatches[3], "queue_manager", "") addToHistogramVec(e.smtpDelays, smtpMatches[3], "queue_manager", "")
addToHistogramVec(e.smtpDelays, smtpMatches[4], "connection_setup", "") addToHistogramVec(e.smtpDelays, smtpMatches[4], "connection_setup", "")
addToHistogramVec(e.smtpDelays, smtpMatches[5], "transmission", "") addToHistogramVec(e.smtpDelays, smtpMatches[5], "transmission", "")
if smtpMatches := smtpStatusDeferredLine.FindStringSubmatch(remainder); smtpMatches != nil { if smtpStatusMatches := smtpStatusLine.FindStringSubmatch(remainder); smtpStatusMatches != nil {
e.smtpStatusDeferred.Inc() e.smtpProcesses.WithLabelValues(smtpStatusMatches[1]).Inc()
if smtpStatusMatches[1] == "deferred" {
e.smtpStatusDeferred.Inc()
}
} }
} else if smtpTLSMatches := smtpTLSLine.FindStringSubmatch(remainder); smtpTLSMatches != nil { } else if smtpTLSMatches := smtpTLSLine.FindStringSubmatch(remainder); smtpTLSMatches != nil {
e.smtpTLSConnects.WithLabelValues(smtpTLSMatches[1:]...).Inc() e.smtpTLSConnects.WithLabelValues(smtpTLSMatches[1:]...).Inc()
@ -504,6 +510,13 @@ func NewPostfixExporter(showqPath string, logSrc LogSource, logUnsupportedLines
Name: "smtp_deferred_messages_total", Name: "smtp_deferred_messages_total",
Help: "Total number of messages that have been deferred on SMTP.", Help: "Total number of messages that have been deferred on SMTP.",
}), }),
smtpProcesses: prometheus.NewCounterVec(
prometheus.CounterOpts{
Namespace: "postfix",
Name: "smtp_messages_processed_total",
Help: "Total number of messages that have been processed by the smtp process.",
},
[]string{"status"}),
smtpConnectionTimedOut: prometheus.NewCounter(prometheus.CounterOpts{ smtpConnectionTimedOut: prometheus.NewCounter(prometheus.CounterOpts{
Namespace: "postfix", Namespace: "postfix",
Name: "smtp_connection_timed_out_total", Name: "smtp_connection_timed_out_total",
@ -598,6 +611,7 @@ func (e *PostfixExporter) Describe(ch chan<- *prometheus.Desc) {
e.smtpDelays.Describe(ch) e.smtpDelays.Describe(ch)
e.smtpTLSConnects.Describe(ch) e.smtpTLSConnects.Describe(ch)
ch <- e.smtpDeferreds.Desc() ch <- e.smtpDeferreds.Desc()
e.smtpProcesses.Describe(ch)
ch <- e.smtpdConnects.Desc() ch <- e.smtpdConnects.Desc()
ch <- e.smtpdDisconnects.Desc() ch <- e.smtpdDisconnects.Desc()
ch <- e.smtpdFCrDNSErrors.Desc() ch <- e.smtpdFCrDNSErrors.Desc()
@ -673,6 +687,7 @@ func (e *PostfixExporter) Collect(ch chan<- prometheus.Metric) {
e.smtpDelays.Collect(ch) e.smtpDelays.Collect(ch)
e.smtpTLSConnects.Collect(ch) e.smtpTLSConnects.Collect(ch)
ch <- e.smtpDeferreds ch <- e.smtpDeferreds
e.smtpProcesses.Collect(ch)
ch <- e.smtpdConnects ch <- e.smtpdConnects
ch <- e.smtpdDisconnects ch <- e.smtpdDisconnects
ch <- e.smtpdFCrDNSErrors ch <- e.smtpdFCrDNSErrors

View File

@ -23,6 +23,8 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
smtpDelays *prometheus.HistogramVec smtpDelays *prometheus.HistogramVec
smtpTLSConnects *prometheus.CounterVec smtpTLSConnects *prometheus.CounterVec
smtpDeferreds prometheus.Counter smtpDeferreds prometheus.Counter
smtpStatusDeferred prometheus.Counter
smtpProcesses *prometheus.CounterVec
smtpdConnects prometheus.Counter smtpdConnects prometheus.Counter
smtpdDisconnects prometheus.Counter smtpdDisconnects prometheus.Counter
smtpdFCrDNSErrors prometheus.Counter smtpdFCrDNSErrors prometheus.Counter
@ -39,6 +41,7 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
saslFailedCount int saslFailedCount int
outgoingTLS int outgoingTLS int
smtpdMessagesProcessed int smtpdMessagesProcessed int
smtpMessagesProcessed int
} }
tests := []struct { tests := []struct {
name string name string
@ -117,6 +120,7 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
fields: fields{ fields: fields{
smtpdSASLAuthenticationFailures: prometheus.NewCounter(prometheus.CounterOpts{}), smtpdSASLAuthenticationFailures: prometheus.NewCounter(prometheus.CounterOpts{}),
unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"process"}), unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"process"}),
smtpProcesses: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"status"}),
}, },
}, },
{ {
@ -146,10 +150,12 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
removedCount: 0, removedCount: 0,
saslFailedCount: 0, saslFailedCount: 0,
outgoingTLS: 2, outgoingTLS: 2,
smtpdMessagesProcessed: 0,
}, },
fields: fields{ fields: fields{
unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"process"}), unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"process"}),
smtpTLSConnects: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"Verified", "TLSv1.2", "ECDHE-RSA-AES256-GCM-SHA384", "256", "256"}), smtpTLSConnects: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"Verified", "TLSv1.2", "ECDHE-RSA-AES256-GCM-SHA384", "256", "256"}),
smtpProcesses: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"status"}),
}, },
}, },
{ {
@ -162,9 +168,29 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
saslFailedCount: 0, saslFailedCount: 0,
outgoingTLS: 0, outgoingTLS: 0,
smtpdMessagesProcessed: 0, smtpdMessagesProcessed: 0,
smtpMessagesProcessed: 1,
}, },
fields: fields{ fields: fields{
smtpDelays: prometheus.NewHistogramVec(prometheus.HistogramOpts{}, []string{"stage"}), smtpDelays: prometheus.NewHistogramVec(prometheus.HistogramOpts{}, []string{"stage"}),
smtpProcesses: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"status"}),
},
},
{
name: "Testing different smtp statuses",
args: args{
line: []string{
"Dec 29 02:54:09 mail postfix/smtp[7648]: 732BB407C3: host mail.domain.com[1.1.1.1] said: 451 DT:SPM 163 mx13,P8CowECpNVM_oEVaenoEAQ--.23796S3 1514512449, please try again 15min later (in reply to end of DATA command)",
"Dec 29 02:54:12 mail postfix/smtp[7648]: 732BB407C3: to=<redacted@domain.com>, relay=mail.domain.com[1.1.1.1]:25, delay=6.2, delays=0.1/0/5.2/0.87, dsn=4.0.0, status=deferred (host mail.domain.com[1.1.1.1] said: 451 DT:SPM 163 mx40,WsCowAAnEhlCoEVa5GjcAA--.20089S3 1514512452, please try again 15min later (in reply to end of DATA command))",
"Dec 29 03:03:48 mail postfix/smtp[8492]: 732BB407C3: to=<redacted@domain.com>, relay=mail.domain.com[1.1.1.1]:25, delay=582, delays=563/16/1.7/0.81, dsn=5.0.0, status=bounced (host mail.domain.com[1.1.1.1] said: 554 DT:SPM 163 mx9,O8CowEDJVFKCokVaRhz+AA--.26016S3 1514513028,please see http://mail.domain.com/help/help_spam.htm?ip= (in reply to end of DATA command))",
"Dec 29 03:03:48 mail postfix/bounce[9321]: 732BB407C3: sender non-delivery notification: 5DE184083C",
},
smtpMessagesProcessed: 2,
},
fields: fields{
unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"process"}),
smtpDelays: prometheus.NewHistogramVec(prometheus.HistogramOpts{}, []string{"stage"}),
smtpStatusDeferred: prometheus.NewCounter(prometheus.CounterOpts{}),
smtpProcesses: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"status"}),
}, },
}, },
} }
@ -184,6 +210,8 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
smtpDelays: tt.fields.smtpDelays, smtpDelays: tt.fields.smtpDelays,
smtpTLSConnects: tt.fields.smtpTLSConnects, smtpTLSConnects: tt.fields.smtpTLSConnects,
smtpDeferreds: tt.fields.smtpDeferreds, smtpDeferreds: tt.fields.smtpDeferreds,
smtpStatusDeferred: tt.fields.smtpStatusDeferred,
smtpProcesses: tt.fields.smtpProcesses,
smtpdConnects: tt.fields.smtpdConnects, smtpdConnects: tt.fields.smtpdConnects,
smtpdDisconnects: tt.fields.smtpdDisconnects, smtpdDisconnects: tt.fields.smtpdDisconnects,
smtpdFCrDNSErrors: tt.fields.smtpdFCrDNSErrors, smtpdFCrDNSErrors: tt.fields.smtpdFCrDNSErrors,
@ -202,6 +230,7 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
assertCounterEquals(t, e.smtpdSASLAuthenticationFailures, tt.args.saslFailedCount, "Wrong number of Sasl counter counted") assertCounterEquals(t, e.smtpdSASLAuthenticationFailures, tt.args.saslFailedCount, "Wrong number of Sasl counter counted")
assertCounterEquals(t, e.smtpTLSConnects, tt.args.outgoingTLS, "Wrong number of TLS connections counted") assertCounterEquals(t, e.smtpTLSConnects, tt.args.outgoingTLS, "Wrong number of TLS connections counted")
assertCounterEquals(t, e.smtpdProcesses, tt.args.smtpdMessagesProcessed, "Wrong number of smtpd messages processed") assertCounterEquals(t, e.smtpdProcesses, tt.args.smtpdMessagesProcessed, "Wrong number of smtpd messages processed")
assertCounterEquals(t, e.smtpProcesses, tt.args.smtpMessagesProcessed, "Wrong number of smtp messages processed")
}) })
} }
} }