diff --git a/.travis.yml b/.travis.yml new file mode 100644 index 0000000..95f7b22 --- /dev/null +++ b/.travis.yml @@ -0,0 +1,24 @@ +language: go + +matrix: + include: + - go: 1.13.x + env: VET=1 GO111MODULE=on + - go: 1.13.x + env: RACE=1 GO111MODULE=on + - go: 1.13.x + env: RUN386=1 + - go: 1.12.x + env: GO111MODULE=on + - go: 1.11.x + env: GO111MODULE=on + - go: stable + +addons: + apt: + packages: + - libsystemd-dev + +env: + global: + GO111MODULE: on \ No newline at end of file diff --git a/main.go b/main.go index b3424d9..2eaa9fc 100644 --- a/main.go +++ b/main.go @@ -17,7 +17,7 @@ func main() { listenAddress = app.Flag("web.listen-address", "Address to listen on for web interface and telemetry.").Default(":9154").String() metricsPath = app.Flag("web.telemetry-path", "Path under which to expose metrics.").Default("/metrics").String() postfixShowqPath = app.Flag("postfix.showq_path", "Path at which Postfix places its showq socket.").Default("/var/spool/postfix/public/showq").String() - postfixLogfilePath = app.Flag("postfix.logfile_path", "Path where Postfix writes log entries. This file will be truncated by this exporter.").Default("/var/log/postfix_exporter_input.log").String() + postfixLogfilePath = app.Flag("postfix.logfile_path", "Path where Postfix writes log entries.").Default("/var/log/maillog").String() logUnsupportedLines = app.Flag("log.unsupported", "Log all unsupported lines.").Bool() systemdEnable bool systemdUnit, systemdSlice, systemdJournalPath string diff --git a/mock/HistogramVecMock.go b/mock/HistogramVecMock.go new file mode 100644 index 0000000..87204f8 --- /dev/null +++ b/mock/HistogramVecMock.go @@ -0,0 +1,46 @@ +package mock + +import "github.com/prometheus/client_golang/prometheus" + +type HistorgramVecMock struct { + mock HistogramMock +} + +func (m *HistorgramVecMock) Describe(chan<- *prometheus.Desc) { + panic("implement me") +} + +func (m *HistorgramVecMock) GetMetricWith(prometheus.Labels) (prometheus.Observer, error) { + panic("implement me") +} + +func (m *HistorgramVecMock) GetMetricWithLabelValues(lvs ...string) (prometheus.Observer, error) { + panic("implement me") +} + +func (m *HistorgramVecMock) With(prometheus.Labels) prometheus.Observer { + panic("implement me") +} + +func (m *HistorgramVecMock) WithLabelValues(...string) prometheus.Observer { + return m.mock +} + +func (m *HistorgramVecMock) CurryWith(prometheus.Labels) (prometheus.ObserverVec, error) { + panic("implement me") +} + +func (m *HistorgramVecMock) MustCurryWith(prometheus.Labels) prometheus.ObserverVec { + panic("implement me") +} + +func (m *HistorgramVecMock) Collect(chan<- prometheus.Metric) { + panic("implement me") +} +func (m *HistorgramVecMock) GetSum() float64 { + return *m.mock.sum +} + +func NewHistogramVecMock() *HistorgramVecMock { + return &HistorgramVecMock{mock: *NewHistogramMock()} +} diff --git a/mock/HistorgramMock.go b/mock/HistorgramMock.go new file mode 100644 index 0000000..48efeac --- /dev/null +++ b/mock/HistorgramMock.go @@ -0,0 +1,34 @@ +package mock + +import ( + "github.com/prometheus/client_golang/prometheus" + "github.com/prometheus/client_model/go" +) + +type HistogramMock struct { + sum *float64 +} + +func NewHistogramMock() *HistogramMock { + return &HistogramMock{sum: new(float64)} +} + +func (HistogramMock) Desc() *prometheus.Desc { + panic("implement me") +} + +func (HistogramMock) Write(*io_prometheus_client.Metric) error { + panic("implement me") +} + +func (HistogramMock) Describe(chan<- *prometheus.Desc) { + panic("implement me") +} + +func (HistogramMock) Collect(chan<- prometheus.Metric) { + panic("implement me") +} + +func (h HistogramMock) Observe(value float64) { + *h.sum += value +} diff --git a/postfix_exporter.go b/postfix_exporter.go index 4bbe70c..2e2ec22 100644 --- a/postfix_exporter.go +++ b/postfix_exporter.go @@ -94,12 +94,6 @@ func CollectShowqFromReader(file io.Reader, ch chan<- prometheus.Metric) error { // CollectTextualShowqFromReader parses Postfix's textual showq output. func CollectTextualShowqFromReader(file io.Reader, ch chan<- prometheus.Metric) error { - scanner := bufio.NewScanner(file) - scanner.Split(bufio.ScanLines) - - // Regular expression for matching postqueue's output. Example: - // "A07A81514 5156 Tue Feb 14 13:13:54 MAILER-DAEMON" - messageLine := regexp.MustCompile(`^[0-9A-F]+([\*!]?) +(\d+) (\w{3} \w{3} +\d+ +\d+:\d{2}:\d{2}) +`) // Histograms tracking the messages by size and age. sizeHistogram := prometheus.NewHistogramVec( @@ -119,34 +113,51 @@ func CollectTextualShowqFromReader(file io.Reader, ch chan<- prometheus.Metric) }, []string{"queue"}) + err := CollectTextualShowqFromScanner(sizeHistogram, ageHistogram, file) + + sizeHistogram.Collect(ch) + ageHistogram.Collect(ch) + return err +} + +func CollectTextualShowqFromScanner(sizeHistogram prometheus.ObserverVec, ageHistogram prometheus.ObserverVec, file io.Reader) error { + scanner := bufio.NewScanner(file) + scanner.Split(bufio.ScanLines) // Initialize all queue buckets to zero. for _, q := range []string{"active", "hold", "other"} { sizeHistogram.WithLabelValues(q) ageHistogram.WithLabelValues(q) } - now := time.Now() location, err := time.LoadLocation("Local") if err != nil { log.Println(err) } + // Regular expression for matching postqueue's output. Example: + // "A07A81514 5156 Tue Feb 14 13:13:54 MAILER-DAEMON" + messageLine := regexp.MustCompile(`^[0-9A-F]+([\*!]?) +(\d+) (\w{3} \w{3} +\d+ +\d+:\d{2}:\d{2}) +`) + for scanner.Scan() { - matches := messageLine.FindStringSubmatch(scanner.Text()) - if matches != nil { + text := scanner.Text() + matches := messageLine.FindStringSubmatch(text) + if matches == nil { continue } + queueMatch := matches[1] + sizeMatch := matches[2] + dateMatch := matches[3] // Derive the name of the message queue. queue := "other" - if matches[1] == "*" { + if queueMatch == "*" { queue = "active" - } else if matches[1] == "!" { + } else if queueMatch == "!" { queue = "hold" } // Parse the message size. - size, err := strconv.ParseFloat(matches[2], 64) + size, err := strconv.ParseFloat(sizeMatch, 64) if err != nil { return err } @@ -155,11 +166,11 @@ func CollectTextualShowqFromReader(file io.Reader, ch chan<- prometheus.Metric) // output contains no year number. Assume it // applies to the last year for which the // message date doesn't exceed time.Now(). - date, err := time.ParseInLocation("Mon Jan 2 15:04:05", - matches[3], location) + date, err := time.ParseInLocation("Mon Jan 2 15:04:05", dateMatch, location) if err != nil { return err } + now := time.Now() date = date.AddDate(now.Year(), 0, 0) if date.After(now) { date = date.AddDate(-1, 0, 0) @@ -168,9 +179,6 @@ func CollectTextualShowqFromReader(file io.Reader, ch chan<- prometheus.Metric) sizeHistogram.WithLabelValues(queue).Observe(size) ageHistogram.WithLabelValues(queue).Observe(now.Sub(date).Seconds()) } - - sizeHistogram.Collect(ch) - ageHistogram.Collect(ch) return scanner.Err() } @@ -339,10 +347,10 @@ func (e *PostfixExporter) CollectFromLogLine(line string) { } case "smtp": if smtpMatches := lmtpPipeSMTPLine.FindStringSubmatch(remainder); smtpMatches != nil { - addToHistogramVec(e.smtpDelays, smtpMatches[2], "before_queue_manager") - addToHistogramVec(e.smtpDelays, smtpMatches[3], "queue_manager") - addToHistogramVec(e.smtpDelays, smtpMatches[4], "connection_setup") - addToHistogramVec(e.smtpDelays, smtpMatches[5], "transmission") + addToHistogramVec(e.smtpDelays, smtpMatches[2], "before_queue_manager", "") + addToHistogramVec(e.smtpDelays, smtpMatches[3], "queue_manager", "") + addToHistogramVec(e.smtpDelays, smtpMatches[4], "connection_setup", "") + addToHistogramVec(e.smtpDelays, smtpMatches[5], "transmission", "") if smtpMatches := smtpStatusDeferredLine.FindStringSubmatch(remainder); smtpMatches != nil { e.smtpStatusDeferred.Inc() } @@ -365,7 +373,7 @@ func (e *PostfixExporter) CollectFromLogLine(line string) { } else if smtpdProcessesSASLMatches := smtpdProcessesSASLLine.FindStringSubmatch(remainder); smtpdProcessesSASLMatches != nil { e.smtpdProcesses.WithLabelValues(smtpdProcessesSASLMatches[1]).Inc() } else if strings.Contains(remainder, ": client=") { - e.smtpdProcesses.WithLabelValues(smtpdProcessesSASLMatches[1]).Inc() + e.smtpdProcesses.WithLabelValues("").Inc() } else if smtpdRejectsMatches := smtpdRejectsLine.FindStringSubmatch(remainder); smtpdRejectsMatches != nil { e.smtpdRejects.WithLabelValues(smtpdRejectsMatches[1]).Inc() } else if smtpdSASLAuthenticationFailuresLine.MatchString(remainder) { @@ -625,6 +633,8 @@ func (e *PostfixExporter) Describe(ch chan<- *prometheus.Desc) { e.smtpdTLSConnects.Describe(ch) ch <- e.smtpStatusDeferred.Desc() e.unsupportedLogEntries.Describe(ch) + e.smtpConnectionTimedOut.Describe(ch) + e.opendkimSignatureAdded.Describe(ch) } func (e *PostfixExporter) foreverCollectFromJournal(ctx context.Context) { diff --git a/postfix_exporter_test.go b/postfix_exporter_test.go index a56309d..d0d06f2 100644 --- a/postfix_exporter_test.go +++ b/postfix_exporter_test.go @@ -125,11 +125,12 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) { args: args{ line: []string{ "Oct 30 13:19:26 mailgw-out1 postfix/smtpd[27530]: EB4B2C19E2: client=xxx[1.2.3.4], sasl_method=PLAIN, sasl_username=user@domain", + "Feb 24 16:42:00 letterman postfix/smtpd[24906]: 1CF582025C: client=xxx[2.3.4.5]", }, removedCount: 0, saslFailedCount: 0, outgoingTLS: 0, - smtpdMessagesProcessed: 1, + smtpdMessagesProcessed: 2, }, fields: fields{ unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"process"}), @@ -152,6 +153,21 @@ func TestPostfixExporter_CollectFromLogline(t *testing.T) { smtpTLSConnects: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"Verified", "TLSv1.2", "ECDHE-RSA-AES256-GCM-SHA384", "256", "256"}), }, }, + { + name: "Testing delays", + args: args{ + line: []string{ + "Feb 24 16:18:40 letterman postfix/smtp[59649]: 5270320179: to=, relay=mail.telia.com[81.236.60.210]:25, delay=2017, delays=0.1/2017/0.03/0.05, dsn=2.0.0, status=sent (250 2.0.0 6FVIjIMwUJwU66FVIjAEB0 mail accepted for delivery)", + }, + removedCount: 0, + saslFailedCount: 0, + outgoingTLS: 0, + smtpdMessagesProcessed: 0, + }, + fields: fields{ + smtpDelays: prometheus.NewHistogramVec(prometheus.HistogramOpts{}, []string{"stage"}), + }, + }, } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { diff --git a/showq_test.go b/showq_test.go new file mode 100644 index 0000000..d2aad82 --- /dev/null +++ b/showq_test.go @@ -0,0 +1,45 @@ +package main + +import ( + "github.com/kumina/postfix_exporter/mock" + "github.com/stretchr/testify/assert" + "os" + "testing" +) + +func TestCollectShowqFromReader(t *testing.T) { + type args struct { + file string + } + tests := []struct { + name string + args args + wantErr bool + expectedTotalCount float64 + }{ + { + name: "basic test", + args: args{ + file: "testdata/showq.txt", + }, + wantErr: false, + expectedTotalCount: 118702, + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + file, err := os.Open(tt.args.file) + if err != nil { + t.Error(err) + } + + sizeHistogram := mock.NewHistogramVecMock() + ageHistogram := mock.NewHistogramVecMock() + if err := CollectTextualShowqFromScanner(sizeHistogram, ageHistogram, file); (err != nil) != tt.wantErr { + t.Errorf("CollectShowqFromReader() error = %v, wantErr %v", err, tt.wantErr) + } + assert.Equal(t, tt.expectedTotalCount, sizeHistogram.GetSum(), "Expected a lot more data.") + assert.Less(t, 0.0, ageHistogram.GetSum(), "Age not greater than 0") + }) + } +} diff --git a/testdata/showq.txt b/testdata/showq.txt new file mode 100644 index 0000000..bca2b27 --- /dev/null +++ b/testdata/showq.txt @@ -0,0 +1,80 @@ +-Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient------- +C420820802* 4387 Mon Feb 24 13:35:18 sender@example.com + recipient@lerum.se + +8D5D4205B9* 4033 Mon Feb 24 13:22:16 sender@example.com + recipient@lerum.se + +7465520414* 4043 Mon Feb 24 13:22:16 sender@example.com + recipient@lerum.se + +3E2F72070A* 5301 Mon Feb 24 13:35:39 sender@example.com + recipient@hotmail.se + +542032060A* 5828 Mon Feb 24 13:34:46 sender@example.com + recipient@skatteverket.se + +4B96A2037C* 9868 Mon Feb 24 13:32:03 sender@example.com + recipient@lerum.se + +E88EA20796* 5956 Mon Feb 24 13:34:55 sender@example.com + recipient@edu.halmstad.se + +8C9912052C* 4047 Mon Feb 24 13:22:16 sender@example.com + recipient@lerum.se + +70BDA2079B* 4404 Mon Feb 24 13:35:18 sender@example.com + recipient@lerum.se + +76E6A20536* 3875 Mon Feb 24 13:21:20 sender@example.com + recipient@lerum.se + +92C662062A* 3864 Mon Feb 24 13:21:20 sender@example.com + recipient@lerum.se + +BA9BC2071E* 4387 Mon Feb 24 13:35:18 sender@example.com + recipient@lerum.se + +9A67020670* 4393 Mon Feb 24 13:34:06 sender@example.com + recipient@lerum.se + +651AC20138* 3872 Mon Feb 24 13:23:17 sender@example.com + recipient@lerum.se + +4F16D20516* 4052 Mon Feb 24 13:24:38 sender@example.com + recipient@lerum.se + +C9C4A20501* 5099 Mon Feb 24 13:14:10 sender@example.com + recipient@haninge.se + +0572820D64 4098 Sat Feb 22 00:44:54 sender@example.com +(host mail.wekudata.com[37.208.0.7] said: 452 4.2.2 Quota exceeded (rehanna@stahlstierna.se) (in reply to RCPT TO command)) + recipient@stahlstierna.se + +0B2C320952 4173 Sat Feb 22 00:42:07 sender@example.com +(host alt1.gmail-smtp-in.l.google.com[108.177.97.26] said: 452-4.2.2 The email account that you tried to reach is over quota. Please direct 452-4.2.2 the recipient to 452 4.2.2 https://support.google.com/mail/?p=OverQuotaTemp q24si6538316pgt.498 - gsmtp (in reply to RCPT TO command)) + recipient@gmail.com + +0CC2B22124 10926 Fri Feb 21 13:31:58 sender@example.com +(host alt1.gmail-smtp-in.l.google.com[108.177.97.26] said: 452-4.2.2 The email account that you tried to reach is over quota. Please direct 452-4.2.2 the recipient to 452 4.2.2 https://support.google.com/mail/?p=OverQuotaTemp f10si11999094pgj.597 - gsmtp (in reply to RCPT TO command)) + recipient@gmail.com + +0C84020606 4898 Mon Feb 24 08:30:34 sender@example.com +(host alt1.gmail-smtp-in.l.google.com[108.177.97.26] said: 452-4.2.2 The email account that you tried to reach is over quota. Please direct 452-4.2.2 the recipient to 452 4.2.2 https://support.google.com/mail/?p=OverQuotaTemp 2si12536346pld.231 - gsmtp (in reply to RCPT TO command)) + recipient@gmail.com + +04EAA203C0 4133 Mon Feb 24 12:21:58 sender@example.com +(host alt1.gmail-smtp-in.l.google.com[108.177.97.26] said: 452-4.2.2 The email account that you tried to reach is over quota. Please direct 452-4.2.2 the recipient to 452 4.2.2 https://support.google.com/mail/?p=OverQuotaTemp i16si12220651pfq.60 - gsmtp (in reply to RCPT TO command)) + recipient@gmail.com + +00C33202B6 4823 Mon Feb 24 11:32:37 sender@example.com + (connect to gafe.se[151.252.30.111]:25: Connection refused) + recipient@gafe.se + +046E0218CA 4154 Mon Feb 24 00:13:12 sender@example.com +(host alt1.gmail-smtp-in.l.google.com[108.177.97.26] said: 452-4.2.2 The email account that you tried to reach is over quota. Please direct 452-4.2.2 the recipient to 452 4.2.2 https://support.google.com/mail/?p=OverQuotaTemp y1si11835269pgi.474 - gsmtp (in reply to RCPT TO command)) + recipient@gmail.com + +06373212DC 4088 Sat Feb 22 00:34:11 sender@example.com + (connect to smtp.falun.se[192.121.234.25]:25: Connection timed out) + recipient@utb.falun.se