Merge pull request #75 from paradis/master

Add some new metrics when parsing postfix logs
This commit is contained in:
Bart Vercoulen 2022-10-13 18:53:41 +02:00 committed by GitHub
commit a6f58e9b2b
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 183 additions and 22 deletions

View File

@ -53,9 +53,12 @@ type PostfixExporter struct {
qmgrInsertsNrcpt prometheus.Histogram qmgrInsertsNrcpt prometheus.Histogram
qmgrInsertsSize prometheus.Histogram qmgrInsertsSize prometheus.Histogram
qmgrRemoves prometheus.Counter qmgrRemoves prometheus.Counter
qmgrExpires prometheus.Counter
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,8 +69,11 @@ 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
bounceNonDelivery prometheus.Counter
virtualDelivered prometheus.Counter
} }
// A LogSource is an interface to read log lines. // A LogSource is an interface to read log lines.
@ -286,10 +292,11 @@ func CollectShowqFromSocket(path string, ch chan<- prometheus.Metric) error {
// Patterns for parsing log messages. // Patterns for parsing log messages.
var ( var (
logLine = regexp.MustCompile(` ?(postfix|opendkim)(/(\w+))?\[\d+\]: (.*)`) logLine = regexp.MustCompile(` ?(postfix|opendkim)(/(\w+))?\[\d+\]: ((?:(warning|error|fatal|panic): )?.*)`)
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`) qmgrExpiredLine = regexp.MustCompile(`:.*, status=(expired|force-expired), returned to sender`)
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 `)
@ -299,6 +306,7 @@ var (
smtpdSASLAuthenticationFailuresLine = regexp.MustCompile(`^warning: \S+: SASL \S+ authentication failed: `) smtpdSASLAuthenticationFailuresLine = regexp.MustCompile(`^warning: \S+: SASL \S+ authentication failed: `)
smtpdTLSLine = regexp.MustCompile(`^(\S+) TLS connection established from \S+: (\S+) with cipher (\S+) \((\d+)/(\d+) bits\)`) smtpdTLSLine = regexp.MustCompile(`^(\S+) TLS connection established from \S+: (\S+) with cipher (\S+) \((\d+)/(\d+) bits\)`)
opendkimSignatureAdded = regexp.MustCompile(`^[\w\d]+: DKIM-Signature field added \(s=(\w+), d=(.*)\)$`) opendkimSignatureAdded = regexp.MustCompile(`^[\w\d]+: DKIM-Signature field added \(s=(\w+), d=(.*)\)$`)
bounceNonDeliveryLine = regexp.MustCompile(`: sender non-delivery notification: `)
) )
// CollectFromLogline collects metrict from a Postfix log line. // CollectFromLogline collects metrict from a Postfix log line.
@ -308,10 +316,11 @@ func (e *PostfixExporter) CollectFromLogLine(line string) {
if logMatches == nil { if logMatches == nil {
// Unknown log entry format. // Unknown log entry format.
e.addToUnsupportedLine(line, "") e.addToUnsupportedLine(line, "", "")
return return
} }
process := logMatches[1] process := logMatches[1]
level := logMatches[5]
remainder := logMatches[4] remainder := logMatches[4]
switch process { switch process {
case "postfix": case "postfix":
@ -324,7 +333,7 @@ func (e *PostfixExporter) CollectFromLogLine(line string) {
} else if strings.Contains(remainder, ": reject: ") { } else if strings.Contains(remainder, ": reject: ") {
e.cleanupRejects.Inc() e.cleanupRejects.Inc()
} else { } else {
e.addToUnsupportedLine(line, subprocess) e.addToUnsupportedLine(line, subprocess, level)
} }
case "lmtp": case "lmtp":
if lmtpMatches := lmtpPipeSMTPLine.FindStringSubmatch(remainder); lmtpMatches != nil { if lmtpMatches := lmtpPipeSMTPLine.FindStringSubmatch(remainder); lmtpMatches != nil {
@ -333,7 +342,7 @@ func (e *PostfixExporter) CollectFromLogLine(line string) {
addToHistogramVec(e.lmtpDelays, lmtpMatches[4], "LMTP sdelay", "connection_setup") addToHistogramVec(e.lmtpDelays, lmtpMatches[4], "LMTP sdelay", "connection_setup")
addToHistogramVec(e.lmtpDelays, lmtpMatches[5], "LMTP xdelay", "transmission") addToHistogramVec(e.lmtpDelays, lmtpMatches[5], "LMTP xdelay", "transmission")
} else { } else {
e.addToUnsupportedLine(line, subprocess) e.addToUnsupportedLine(line, subprocess, level)
} }
case "pipe": case "pipe":
if pipeMatches := lmtpPipeSMTPLine.FindStringSubmatch(remainder); pipeMatches != nil { if pipeMatches := lmtpPipeSMTPLine.FindStringSubmatch(remainder); pipeMatches != nil {
@ -342,7 +351,7 @@ func (e *PostfixExporter) CollectFromLogLine(line string) {
addToHistogramVec(e.pipeDelays, pipeMatches[4], "PIPE sdelay", pipeMatches[1], "connection_setup") addToHistogramVec(e.pipeDelays, pipeMatches[4], "PIPE sdelay", pipeMatches[1], "connection_setup")
addToHistogramVec(e.pipeDelays, pipeMatches[5], "PIPE xdelay", pipeMatches[1], "transmission") addToHistogramVec(e.pipeDelays, pipeMatches[5], "PIPE xdelay", pipeMatches[1], "transmission")
} else { } else {
e.addToUnsupportedLine(line, subprocess) e.addToUnsupportedLine(line, subprocess, level)
} }
case "qmgr": case "qmgr":
if qmgrInsertMatches := qmgrInsertLine.FindStringSubmatch(remainder); qmgrInsertMatches != nil { if qmgrInsertMatches := qmgrInsertLine.FindStringSubmatch(remainder); qmgrInsertMatches != nil {
@ -350,8 +359,10 @@ func (e *PostfixExporter) CollectFromLogLine(line string) {
addToHistogram(e.qmgrInsertsNrcpt, qmgrInsertMatches[2], "QMGR nrcpt") addToHistogram(e.qmgrInsertsNrcpt, qmgrInsertMatches[2], "QMGR nrcpt")
} else if strings.HasSuffix(remainder, ": removed") { } else if strings.HasSuffix(remainder, ": removed") {
e.qmgrRemoves.Inc() e.qmgrRemoves.Inc()
} else if qmgrExpired := qmgrExpiredLine.FindStringSubmatch(remainder); qmgrExpired != nil {
e.qmgrExpires.Inc()
} else { } else {
e.addToUnsupportedLine(line, subprocess) e.addToUnsupportedLine(line, subprocess, level)
} }
case "smtp": case "smtp":
if smtpMatches := lmtpPipeSMTPLine.FindStringSubmatch(remainder); smtpMatches != nil { if smtpMatches := lmtpPipeSMTPLine.FindStringSubmatch(remainder); smtpMatches != nil {
@ -359,15 +370,18 @@ 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.smtpProcesses.WithLabelValues(smtpStatusMatches[1]).Inc()
if smtpStatusMatches[1] == "deferred" {
e.smtpStatusDeferred.Inc() 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()
} else if smtpMatches := smtpConnectionTimedOut.FindStringSubmatch(remainder); smtpMatches != nil { } else if smtpMatches := smtpConnectionTimedOut.FindStringSubmatch(remainder); smtpMatches != nil {
e.smtpConnectionTimedOut.Inc() e.smtpConnectionTimedOut.Inc()
} else { } else {
e.addToUnsupportedLine(line, subprocess) e.addToUnsupportedLine(line, subprocess, level)
} }
case "smtpd": case "smtpd":
if strings.HasPrefix(remainder, "connect from ") { if strings.HasPrefix(remainder, "connect from ") {
@ -389,28 +403,40 @@ func (e *PostfixExporter) CollectFromLogLine(line string) {
} else if smtpdTLSMatches := smtpdTLSLine.FindStringSubmatch(remainder); smtpdTLSMatches != nil { } else if smtpdTLSMatches := smtpdTLSLine.FindStringSubmatch(remainder); smtpdTLSMatches != nil {
e.smtpdTLSConnects.WithLabelValues(smtpdTLSMatches[1:]...).Inc() e.smtpdTLSConnects.WithLabelValues(smtpdTLSMatches[1:]...).Inc()
} else { } else {
e.addToUnsupportedLine(line, subprocess) e.addToUnsupportedLine(line, subprocess, level)
}
case "bounce":
if bounceMatches := bounceNonDeliveryLine.FindStringSubmatch(remainder); bounceMatches != nil {
e.bounceNonDelivery.Inc()
} else {
e.addToUnsupportedLine(line, process, level)
}
case "virtual":
if strings.HasSuffix(remainder, ", status=sent (delivered to maildir)") {
e.virtualDelivered.Inc()
} else {
e.addToUnsupportedLine(line, process, level)
} }
default: default:
e.addToUnsupportedLine(line, subprocess) e.addToUnsupportedLine(line, subprocess, level)
} }
case "opendkim": case "opendkim":
if opendkimMatches := opendkimSignatureAdded.FindStringSubmatch(remainder); opendkimMatches != nil { if opendkimMatches := opendkimSignatureAdded.FindStringSubmatch(remainder); opendkimMatches != nil {
e.opendkimSignatureAdded.WithLabelValues(opendkimMatches[1], opendkimMatches[2]).Inc() e.opendkimSignatureAdded.WithLabelValues(opendkimMatches[1], opendkimMatches[2]).Inc()
} else { } else {
e.addToUnsupportedLine(line, process) e.addToUnsupportedLine(line, process, level)
} }
default: default:
// Unknown log entry format. // Unknown log entry format.
e.addToUnsupportedLine(line, "") e.addToUnsupportedLine(line, process, level)
} }
} }
func (e *PostfixExporter) addToUnsupportedLine(line string, subprocess string) { func (e *PostfixExporter) addToUnsupportedLine(line string, subprocess string, level string) {
if e.logUnsupportedLines { if e.logUnsupportedLines {
log.Printf("Unsupported Line: %v", line) log.Printf("Unsupported Line: %v", line)
} }
e.unsupportedLogEntries.WithLabelValues(subprocess).Inc() e.unsupportedLogEntries.WithLabelValues(subprocess, level).Inc()
} }
func addToHistogram(h prometheus.Histogram, value, fieldName string) { func addToHistogram(h prometheus.Histogram, value, fieldName string) {
@ -484,6 +510,11 @@ func NewPostfixExporter(showqPath string, logSrc LogSource, logUnsupportedLines
Name: "qmgr_messages_removed_total", Name: "qmgr_messages_removed_total",
Help: "Total number of messages removed from mail queues.", Help: "Total number of messages removed from mail queues.",
}), }),
qmgrExpires: prometheus.NewCounter(prometheus.CounterOpts{
Namespace: "postfix",
Name: "qmgr_messages_expired_total",
Help: "Total number of messages expired from mail queues.",
}),
smtpDelays: prometheus.NewHistogramVec( smtpDelays: prometheus.NewHistogramVec(
prometheus.HistogramOpts{ prometheus.HistogramOpts{
Namespace: "postfix", Namespace: "postfix",
@ -504,6 +535,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",
@ -563,7 +601,7 @@ func NewPostfixExporter(showqPath string, logSrc LogSource, logUnsupportedLines
Name: "unsupported_log_entries_total", Name: "unsupported_log_entries_total",
Help: "Log entries that could not be processed.", Help: "Log entries that could not be processed.",
}, },
[]string{"service"}), []string{"service", "level"}),
smtpStatusDeferred: prometheus.NewCounter(prometheus.CounterOpts{ smtpStatusDeferred: prometheus.NewCounter(prometheus.CounterOpts{
Namespace: "postfix", Namespace: "postfix",
Name: "smtp_status_deferred", Name: "smtp_status_deferred",
@ -577,6 +615,16 @@ func NewPostfixExporter(showqPath string, logSrc LogSource, logUnsupportedLines
}, },
[]string{"subject", "domain"}, []string{"subject", "domain"},
), ),
bounceNonDelivery: prometheus.NewCounter(prometheus.CounterOpts{
Namespace: "postfix",
Name: "bounce_non_delivery_notification_total",
Help: "Total number of non delivery notification sent by bounce.",
}),
virtualDelivered: prometheus.NewCounter(prometheus.CounterOpts{
Namespace: "postfix",
Name: "virtual_delivered_total",
Help: "Total number of mail delivered to a virtual mailbox.",
}),
}, nil }, nil
} }
@ -595,9 +643,11 @@ func (e *PostfixExporter) Describe(ch chan<- *prometheus.Desc) {
ch <- e.qmgrInsertsNrcpt.Desc() ch <- e.qmgrInsertsNrcpt.Desc()
ch <- e.qmgrInsertsSize.Desc() ch <- e.qmgrInsertsSize.Desc()
ch <- e.qmgrRemoves.Desc() ch <- e.qmgrRemoves.Desc()
ch <- e.qmgrExpires.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()
@ -610,6 +660,8 @@ func (e *PostfixExporter) Describe(ch chan<- *prometheus.Desc) {
e.unsupportedLogEntries.Describe(ch) e.unsupportedLogEntries.Describe(ch)
e.smtpConnectionTimedOut.Describe(ch) e.smtpConnectionTimedOut.Describe(ch)
e.opendkimSignatureAdded.Describe(ch) e.opendkimSignatureAdded.Describe(ch)
ch <- e.bounceNonDelivery.Desc()
ch <- e.virtualDelivered.Desc()
} }
func (e *PostfixExporter) StartMetricCollection(ctx context.Context) { func (e *PostfixExporter) StartMetricCollection(ctx context.Context) {
@ -670,9 +722,11 @@ func (e *PostfixExporter) Collect(ch chan<- prometheus.Metric) {
ch <- e.qmgrInsertsNrcpt ch <- e.qmgrInsertsNrcpt
ch <- e.qmgrInsertsSize ch <- e.qmgrInsertsSize
ch <- e.qmgrRemoves ch <- e.qmgrRemoves
ch <- e.qmgrExpires
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
@ -685,4 +739,6 @@ func (e *PostfixExporter) Collect(ch chan<- prometheus.Metric) {
e.unsupportedLogEntries.Collect(ch) e.unsupportedLogEntries.Collect(ch)
ch <- e.smtpConnectionTimedOut ch <- e.smtpConnectionTimedOut
e.opendkimSignatureAdded.Collect(ch) e.opendkimSignatureAdded.Collect(ch)
ch <- e.bounceNonDelivery
ch <- e.virtualDelivered
} }

View File

@ -20,9 +20,12 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
qmgrInsertsNrcpt prometheus.Histogram qmgrInsertsNrcpt prometheus.Histogram
qmgrInsertsSize prometheus.Histogram qmgrInsertsSize prometheus.Histogram
qmgrRemoves prometheus.Counter qmgrRemoves prometheus.Counter
qmgrExpires prometheus.Counter
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
@ -31,14 +34,21 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
smtpdRejects *prometheus.CounterVec smtpdRejects *prometheus.CounterVec
smtpdSASLAuthenticationFailures prometheus.Counter smtpdSASLAuthenticationFailures prometheus.Counter
smtpdTLSConnects *prometheus.CounterVec smtpdTLSConnects *prometheus.CounterVec
bounceNonDelivery prometheus.Counter
virtualDelivered prometheus.Counter
unsupportedLogEntries *prometheus.CounterVec unsupportedLogEntries *prometheus.CounterVec
} }
type args struct { type args struct {
line []string line []string
removedCount int removedCount int
expiredCount int
saslFailedCount int saslFailedCount int
outgoingTLS int outgoingTLS int
smtpdMessagesProcessed int smtpdMessagesProcessed int
smtpMessagesProcessed int
bounceNonDelivery int
virtualDelivered int
unsupportedLogEntries []string
} }
tests := []struct { tests := []struct {
name string name string
@ -56,7 +66,7 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
}, },
fields: fields{ fields: fields{
qmgrRemoves: prometheus.NewCounter(prometheus.CounterOpts{}), qmgrRemoves: prometheus.NewCounter(prometheus.CounterOpts{}),
unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"process"}), unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"service", "level"}),
}, },
}, },
{ {
@ -100,7 +110,20 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
}, },
fields: fields{ fields: fields{
qmgrRemoves: prometheus.NewCounter(prometheus.CounterOpts{}), qmgrRemoves: prometheus.NewCounter(prometheus.CounterOpts{}),
unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"process"}), unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"service", "level"}),
},
},
{
name: "qmgr expired",
args: args{
line: []string{
"Apr 10 14:50:16 mail postfix/qmgr[3663]: BACE842E72: from=<noreply@domain.com>, status=expired, returned to sender",
"Apr 10 14:50:16 mail postfix/qmgr[3663]: BACE842E73: from=<noreply@domain.com>, status=force-expired, returned to sender",
},
expiredCount: 2,
},
fields: fields{
qmgrExpires: prometheus.NewCounter(prometheus.CounterOpts{}),
}, },
}, },
{ {
@ -116,7 +139,8 @@ 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{"service", "level"}),
smtpProcesses: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"status"}),
}, },
}, },
{ {
@ -132,7 +156,7 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
smtpdMessagesProcessed: 2, smtpdMessagesProcessed: 2,
}, },
fields: fields{ fields: fields{
unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"process"}), unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"service", "level"}),
smtpdProcesses: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"sasl_method"}), smtpdProcesses: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"sasl_method"}),
}, },
}, },
@ -146,10 +170,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{"service", "level"}),
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 +188,62 @@ 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,
bounceNonDelivery: 1,
},
fields: fields{
unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"service", "level"}),
smtpDelays: prometheus.NewHistogramVec(prometheus.HistogramOpts{}, []string{"stage"}),
smtpStatusDeferred: prometheus.NewCounter(prometheus.CounterOpts{}),
smtpProcesses: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"status"}),
bounceNonDelivery: prometheus.NewCounter(prometheus.CounterOpts{}),
},
},
{
name: "Testing virtual delivered",
args: args{
line: []string{
"Apr 7 15:35:20 123-mail postfix/virtual[20235]: 199041033BE: to=<me@domain.fr>, relay=virtual, delay=0.08, delays=0.08/0/0/0, dsn=2.0.0, status=sent (delivered to maildir)",
},
virtualDelivered: 1,
},
fields: fields{
virtualDelivered: prometheus.NewCounter(prometheus.CounterOpts{}),
},
},
{
name: "Testing levels of unsupported entries",
args: args{
line: []string{
"Feb 14 19:05:25 123-mail postfix/smtpd[1517]: table hash:/etc/postfix/virtual_mailbox_maps(0,lock|fold_fix) has changed -- restarting",
"Mar 16 12:28:02 123-mail postfix/smtpd[16268]: fatal: file /etc/postfix/main.cf: parameter default_privs: unknown user name value: nobody",
"Mar 16 23:30:44 123-mail postfix/qmgr[29980]: warning: please avoid flushing the whole queue when you have",
"Mar 16 23:30:44 123-mail postfix/qmgr[29980]: warning: lots of deferred mail, that is bad for performance",
},
unsupportedLogEntries: []string{
`label:<name:"level" value:"" > label:<name:"service" value:"smtpd" > counter:<value:1 > `,
`label:<name:"level" value:"fatal" > label:<name:"service" value:"smtpd" > counter:<value:1 > `,
`label:<name:"level" value:"warning" > label:<name:"service" value:"qmgr" > counter:<value:2 > `,
},
},
fields: fields{
unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"service", "level"}),
}, },
}, },
} }
@ -181,9 +260,12 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
qmgrInsertsNrcpt: tt.fields.qmgrInsertsNrcpt, qmgrInsertsNrcpt: tt.fields.qmgrInsertsNrcpt,
qmgrInsertsSize: tt.fields.qmgrInsertsSize, qmgrInsertsSize: tt.fields.qmgrInsertsSize,
qmgrRemoves: tt.fields.qmgrRemoves, qmgrRemoves: tt.fields.qmgrRemoves,
qmgrExpires: tt.fields.qmgrExpires,
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,
@ -192,6 +274,8 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
smtpdRejects: tt.fields.smtpdRejects, smtpdRejects: tt.fields.smtpdRejects,
smtpdSASLAuthenticationFailures: tt.fields.smtpdSASLAuthenticationFailures, smtpdSASLAuthenticationFailures: tt.fields.smtpdSASLAuthenticationFailures,
smtpdTLSConnects: tt.fields.smtpdTLSConnects, smtpdTLSConnects: tt.fields.smtpdTLSConnects,
bounceNonDelivery: tt.fields.bounceNonDelivery,
virtualDelivered: tt.fields.virtualDelivered,
unsupportedLogEntries: tt.fields.unsupportedLogEntries, unsupportedLogEntries: tt.fields.unsupportedLogEntries,
logUnsupportedLines: true, logUnsupportedLines: true,
} }
@ -199,9 +283,14 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) {
e.CollectFromLogLine(line) e.CollectFromLogLine(line)
} }
assertCounterEquals(t, e.qmgrRemoves, tt.args.removedCount, "Wrong number of lines counted") assertCounterEquals(t, e.qmgrRemoves, tt.args.removedCount, "Wrong number of lines counted")
assertCounterEquals(t, e.qmgrExpires, tt.args.expiredCount, "Wrong number of qmgr expired lines counted")
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")
assertCounterEquals(t, e.bounceNonDelivery, tt.args.bounceNonDelivery, "Wrong number of non delivery notifications")
assertCounterEquals(t, e.virtualDelivered, tt.args.virtualDelivered, "Wrong number of delivered mails")
assertVecMetricsEquals(t, e.unsupportedLogEntries, tt.args.unsupportedLogEntries, "Wrong number of unsupportedLogEntries")
}) })
} }
} }
@ -241,3 +330,19 @@ func assertCounterEquals(t *testing.T, counter prometheus.Collector, expected in
} }
} }
} }
func assertVecMetricsEquals(t *testing.T, counter *prometheus.CounterVec, expected []string, message string) {
if expected != nil {
metricsChan := make(chan prometheus.Metric)
go func() {
counter.Collect(metricsChan)
close(metricsChan)
}()
var res []string
for metric := range metricsChan {
metricDto := io_prometheus_client.Metric{}
metric.Write(&metricDto)
res = append(res, metricDto.String())
}
assert.Equal(t, expected, res, message)
}
}