diff --git a/.dockerignore b/.dockerignore new file mode 100644 index 0000000..b528b7d --- /dev/null +++ b/.dockerignore @@ -0,0 +1,4 @@ +# Created by .ignore support plugin (hsz.mobi) +.idea/ +*.iml +.git/ \ No newline at end of file diff --git a/.gitignore b/.gitignore index 8c0f4ef..7dd92f4 100644 --- a/.gitignore +++ b/.gitignore @@ -1 +1,12 @@ +# Editor files +*~ +.idea/ + +# Test binary, build with `go test -c` +*.test + +# Binaries postfix_exporter + +*.iml +vendor/ diff --git a/.travis.yml b/.travis.yml new file mode 100644 index 0000000..d6c3fc2 --- /dev/null +++ b/.travis.yml @@ -0,0 +1,42 @@ +language: go + +matrix: + include: + - go: 1.16.x + env: VET=1 GO111MODULE=on + - go: 1.16.x + env: RACE=1 GO111MODULE=on + - go: 1.16.x + env: RUN386=1 + - go: 1.15.x + env: VET=1 GO111MODULE=on + - go: 1.15.x + env: RACE=1 GO111MODULE=on + - go: 1.15.x + env: RUN386=1 + - go: 1.14.x + env: VET=1 GO111MODULE=on + - go: 1.14.x + env: RACE=1 GO111MODULE=on + - go: 1.14.x + env: RUN386=1 + - 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 diff --git a/CHANGELOG.md b/CHANGELOG.md new file mode 100644 index 0000000..cad552e --- /dev/null +++ b/CHANGELOG.md @@ -0,0 +1,15 @@ +## 0.1.3 / 2021-05-02 + +* [BUGFIX] Fix default for mail log path (/var/log/mail.log) + +## 0.1.2 / 2018-05-04 + +* [ENHANCEMENT] Build tag for systemd + +## 0.1.1 / 2018-04-19 + +* [BUGFIX] Non-updating metrics from systemd-journal fix + +## 0.1.0 / 2018-02-23 + +* [ENHANCEMENT] Initial release, add changelog diff --git a/Dockerfile b/Dockerfile new file mode 100644 index 0000000..a3327d8 --- /dev/null +++ b/Dockerfile @@ -0,0 +1,24 @@ +FROM golang:1.16 AS builder +WORKDIR /src + +# avoid downloading the dependencies on succesive builds +RUN apt-get update -qq && apt-get install -qqy \ + build-essential \ + libsystemd-dev + +COPY go.mod go.sum ./ +RUN go mod download +RUN go mod verify + +COPY . . + +# Force the go compiler to use modules +ENV GO111MODULE=on +RUN go test +RUN go build -o /bin/postfix_exporter + +FROM debian:latest +EXPOSE 9154 +WORKDIR / +COPY --from=builder /bin/postfix_exporter /bin/ +ENTRYPOINT ["/bin/postfix_exporter"] diff --git a/README.md b/README.md index 129403b..931ad0b 100644 --- a/README.md +++ b/README.md @@ -1,20 +1,61 @@ # Prometheus Postfix exporter -This repository provides code for a Prometheus metrics exporter -for [the Postfix mail server](http://www.postfix.org/). This exporter -provides histogram metrics for the size and age of messages stored in +Prometheus metrics exporter for [the Postfix mail server](http://www.postfix.org/). +This exporter provides histogram metrics for the size and age of messages stored in the mail queue. It extracts these metrics from Postfix by connecting to -a UNIX socket under `/var/spool`. +a UNIX socket under `/var/spool`. It also counts events by parsing Postfix's +log entries, using regular expression matching. The log entries are retrieved from +the systemd journal, the Docker logs, or from a log file. -In addition to that, it counts events by parsing Postfix's log file, -using regular expression matching. It truncates the log file when -processed, so that the next iteration doesn't interpret the same lines -twice. It makes sense to configure your syslogger to multiplex log -entries to a second file: +## Options + +These options can be used when starting the `postfix_exporter` + +| Flag | Description | Default | +|--------------------------|------------------------------------------------------|-----------------------------------| +| `--web.listen-address` | Address to listen on for web interface and telemetry | `9154` | +| `--web.telemetry-path` | Path under which to expose metrics | `/metrics` | +| `--postfix.showq_path` | Path at which Postfix places its showq socket | `/var/spool/postfix/public/showq` | +| `--postfix.logfile_path` | Path where Postfix writes log entries | `/var/log/mail.log` | +| `--log.unsupported` | Log all unsupported lines | `false` | +| `--docker.enable` | Read from the Docker logs instead of a file | `false` | +| `--docker.container.id` | The container to read Docker logs from | `postfix` | +| `--systemd.enable` | Read from the systemd journal instead of file | `false` | +| `--systemd.unit` | Name of the Postfix systemd unit | `postfix.service` | +| `--systemd.slice` | Name of the Postfix systemd slice. | `""` | +| `--systemd.journal_path` | Path to the systemd journal | `""` | + +## Events from Docker + +Postfix servers running in a [Docker](https://www.docker.com/) +container can be monitored using the `--docker.enable` flag. The +default container ID is `postfix`, but can be customized with the +`--docker.container.id` flag. + +The default is to connect to the local Docker, but this can be +customized using [the `DOCKER_HOST` and +similar](https://pkg.go.dev/github.com/docker/docker/client?tab=doc#NewEnvClient) +environment variables. + +## Events from log file + +The log file is tailed when processed. Rotating the log files while the exporter +is running is OK. The path to the log file is specified with the +`--postfix.logfile_path` flag. + +## Events from systemd + +Retrieval from the systemd journal is enabled with the `--systemd.enable` flag. +This overrides the log file setting. +It is possible to specify the unit (with `--systemd.unit`) or slice (with `--systemd.slice`). +Additionally, it is possible to read the journal from a directory with the `--systemd.journal_path` flag. + +## Build options + +Default the exporter is build with systemd journal functionality (but it is disabled at default). +Because the systemd headers are required for building with systemd, there is +an option to build the exporter without systemd. Use the build tag `nosystemd`. ``` -mail.* -/var/log/postfix_exporter_input.log +go build -tags nosystemd ``` - -Please refer to this utility's `main()` function for a list of supported -command line flags. diff --git a/build_static.sh b/build_static.sh index 3c4851d..b3233a7 100755 --- a/build_static.sh +++ b/build_static.sh @@ -1,17 +1,15 @@ #!/bin/sh -docker run -i -v `pwd`:/postfix_exporter alpine:edge /bin/sh << 'EOF' +docker run -i -v `pwd`:/postfix_exporter golang:1.16 /bin/sh << 'EOF' set -ex # Install prerequisites for the build process. -apk update -apk add ca-certificates git go libc-dev -update-ca-certificates +apt-get update -q +apt-get install -yq libsystemd-dev -# Build the postfix_exporter. cd /postfix_exporter -export GOPATH=/gopath + go get -d ./... -go build --ldflags '-extldflags "-static"' +go build -a -tags static_all strip postfix_exporter EOF diff --git a/go.mod b/go.mod new file mode 100644 index 0000000..261c013 --- /dev/null +++ b/go.mod @@ -0,0 +1,18 @@ +module github.com/kumina/postfix_exporter + +go 1.16 + +require ( + github.com/Microsoft/go-winio v0.5.0 // indirect + github.com/alecthomas/kingpin v2.2.6+incompatible + github.com/coreos/go-systemd/v22 v22.0.0 + github.com/docker/distribution v2.7.1+incompatible // indirect + github.com/docker/docker v1.13.1 + github.com/docker/go-connections v0.4.0 // indirect + github.com/docker/go-units v0.4.0 // indirect + github.com/nxadm/tail v1.4.8 + github.com/opencontainers/go-digest v1.0.0 // indirect + github.com/prometheus/client_golang v1.4.1 + github.com/prometheus/client_model v0.2.0 + github.com/stretchr/testify v1.4.0 +) diff --git a/go.sum b/go.sum new file mode 100644 index 0000000..17fc388 --- /dev/null +++ b/go.sum @@ -0,0 +1,127 @@ +github.com/Microsoft/go-winio v0.5.0 h1:Elr9Wn+sGKPlkaBvwu4mTrxtmOp3F3yV9qhaHbXGjwU= +github.com/Microsoft/go-winio v0.5.0/go.mod h1:JPGBdM1cNvN/6ISo+n8V5iA4v8pBzdOpzfwIujj1a84= +github.com/alecthomas/kingpin v2.2.6+incompatible h1:5svnBTFgJjZvGKyYBtMB0+m5wvrbUHiqye8wRJMlnYI= +github.com/alecthomas/kingpin v2.2.6+incompatible/go.mod h1:59OFYbFVLKQKq+mqrL6Rw5bR0c3ACQaawgXx0QYndlE= +github.com/alecthomas/template v0.0.0-20160405071501-a0175ee3bccc/go.mod h1:LOuyumcjzFXgccqObfd/Ljyb9UuFJ6TxHnclSeseNhc= +github.com/alecthomas/template v0.0.0-20190718012654-fb15b899a751 h1:JYp7IbQjafoB+tBA3gMyHYHrpOtNuDiK/uB5uXxq5wM= +github.com/alecthomas/template v0.0.0-20190718012654-fb15b899a751/go.mod h1:LOuyumcjzFXgccqObfd/Ljyb9UuFJ6TxHnclSeseNhc= +github.com/alecthomas/units v0.0.0-20151022065526-2efee857e7cf/go.mod h1:ybxpYRFXyAe+OPACYpWeL0wqObRcbAqCMya13uyzqw0= +github.com/alecthomas/units v0.0.0-20190717042225-c3de453c63f4 h1:Hs82Z41s6SdL1CELW+XaDYmOH4hkBN4/N9og/AsOv7E= +github.com/alecthomas/units v0.0.0-20190717042225-c3de453c63f4/go.mod h1:ybxpYRFXyAe+OPACYpWeL0wqObRcbAqCMya13uyzqw0= +github.com/beorn7/perks v0.0.0-20180321164747-3a771d992973/go.mod h1:Dwedo/Wpr24TaqPxmxbtue+5NUziq4I4S80YR8gNf3Q= +github.com/beorn7/perks v1.0.0/go.mod h1:KWe93zE9D1o94FZ5RNwFwVgaQK1VOXiVxmqh+CedLV8= +github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM= +github.com/beorn7/perks v1.0.1/go.mod h1:G2ZrVWU2WbWT9wwq4/hrbKbnv/1ERSJQ0ibhJ6rlkpw= +github.com/cespare/xxhash/v2 v2.1.1 h1:6MnRN8NT7+YBpUIWxHtefFZOKTAPgGjpQSxqLNn0+qY= +github.com/cespare/xxhash/v2 v2.1.1/go.mod h1:VGX0DQ3Q6kWi7AoAeZDth3/j3BFtOZR5XLFGgcrjCOs= +github.com/coreos/go-systemd/v22 v22.0.0 h1:XJIw/+VlJ+87J+doOxznsAWIdmWuViOVhkQamW5YV28= +github.com/coreos/go-systemd/v22 v22.0.0/go.mod h1:xO0FLkIi5MaZafQlIrOotqXZ90ih+1atmu1JpKERPPk= +github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= +github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/docker/distribution v2.7.1+incompatible h1:a5mlkVzth6W5A4fOsS3D2EO5BUmsJpcB+cRlLU7cSug= +github.com/docker/distribution v2.7.1+incompatible/go.mod h1:J2gT2udsDAN96Uj4KfcMRqY0/ypR+oyYUYmja8H+y+w= +github.com/docker/docker v1.13.1 h1:IkZjBSIc8hBjLpqeAbeE5mca5mNgeatLHBy3GO78BWo= +github.com/docker/docker v1.13.1/go.mod h1:eEKB0N0r5NX/I1kEveEz05bcu8tLC/8azJZsviup8Sk= +github.com/docker/go-connections v0.4.0 h1:El9xVISelRB7BuFusrZozjnkIM5YnzCViNKohAFqRJQ= +github.com/docker/go-connections v0.4.0/go.mod h1:Gbd7IOopHjR8Iph03tsViu4nIes5XhDvyHbTtUxmeec= +github.com/docker/go-units v0.4.0 h1:3uh0PgVws3nIA0Q+MwDC8yjEPf9zjRfZZWXZYDct3Tw= +github.com/docker/go-units v0.4.0/go.mod h1:fgPhTUdO+D/Jk86RDLlptpiXQzgHJF7gydDDbaIK4Dk= +github.com/fsnotify/fsnotify v1.4.9 h1:hsms1Qyu0jgnwNXIxa+/V/PDsU6CfLf6CNO8H7IWoS4= +github.com/fsnotify/fsnotify v1.4.9/go.mod h1:znqG4EE+3YCdAaPaxE2ZRY/06pZUdp0tY4IgpuI1SZQ= +github.com/go-kit/kit v0.8.0/go.mod h1:xBxKIO96dXMWWy0MnWVtmwkA9/13aqxPnvrjFYMA2as= +github.com/go-kit/kit v0.9.0/go.mod h1:xBxKIO96dXMWWy0MnWVtmwkA9/13aqxPnvrjFYMA2as= +github.com/go-logfmt/logfmt v0.3.0/go.mod h1:Qt1PoO58o5twSAckw1HlFXLmHsOX5/0LbT9GBnD5lWE= +github.com/go-logfmt/logfmt v0.4.0/go.mod h1:3RMwSq7FuexP4Kalkev3ejPJsZTpXXBr9+V4qmtdjCk= +github.com/go-stack/stack v1.8.0/go.mod h1:v0f6uXyyMGvRgIKkXu+yp6POWl0qKG85gN/melR3HDY= +github.com/godbus/dbus/v5 v5.0.3/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA= +github.com/gogo/protobuf v1.1.1/go.mod h1:r8qH/GZQm5c6nD/R0oafs1akxWv10x8SbQlK7atdtwQ= +github.com/golang/protobuf v1.2.0/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U= +github.com/golang/protobuf v1.3.1/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U= +github.com/golang/protobuf v1.3.2 h1:6nsPYzhq5kReh6QImI3k5qWzO4PEbvbIW2cwSfR/6xs= +github.com/golang/protobuf v1.3.2/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U= +github.com/google/go-cmp v0.3.1/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMywk6iLU= +github.com/google/go-cmp v0.4.0 h1:xsAVV57WRhGj6kEIi8ReJzQlHHqcBYCElAvkovg3B/4= +github.com/google/go-cmp v0.4.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= +github.com/google/gofuzz v1.0.0/go.mod h1:dBl0BpW6vV/+mYPU4Po3pmUjxk6FQPldtuIdl/M65Eg= +github.com/json-iterator/go v1.1.6/go.mod h1:+SdeFBvtyEkXs7REEP0seUULqWtbJapLOCVDaaPEHmU= +github.com/json-iterator/go v1.1.9/go.mod h1:KdQUCv79m/52Kvf8AW2vK1V8akMuk1QjK/uOdHXbAo4= +github.com/julienschmidt/httprouter v1.2.0/go.mod h1:SYymIcj16QtmaHHD7aYtjjsJG7VTCxuUUipMqKk8s4w= +github.com/konsorten/go-windows-terminal-sequences v1.0.1/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ= +github.com/kr/logfmt v0.0.0-20140226030751-b84e30acd515/go.mod h1:+0opPa2QZZtGFBFZlji/RkVcI2GknAs/DXo4wKdlNEc= +github.com/kr/pretty v0.1.0 h1:L/CwN0zerZDmRFUapSPitk6f+Q3+0za1rQkzVuMiMFI= +github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo= +github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= +github.com/kr/text v0.1.0 h1:45sCR5RtlFHMR4UwH9sdQ5TC8v0qDQCHnXt+kaKSTVE= +github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI= +github.com/matttproud/golang_protobuf_extensions v1.0.1 h1:4hp9jkHxhMHkqkrB3Ix0jegS5sx/RkqARlsWZ6pIwiU= +github.com/matttproud/golang_protobuf_extensions v1.0.1/go.mod h1:D8He9yQNgCq6Z5Ld7szi9bcBfOoFv/3dc6xSMkL2PC0= +github.com/modern-go/concurrent v0.0.0-20180228061459-e0a39a4cb421/go.mod h1:6dJC0mAP4ikYIbvyc7fijjWJddQyLn8Ig3JB5CqoB9Q= +github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd/go.mod h1:6dJC0mAP4ikYIbvyc7fijjWJddQyLn8Ig3JB5CqoB9Q= +github.com/modern-go/reflect2 v0.0.0-20180701023420-4b7aa43c6742/go.mod h1:bx2lNnkwVCuqBIxFjflWJWanXIb3RllmbCylyMrvgv0= +github.com/modern-go/reflect2 v1.0.1/go.mod h1:bx2lNnkwVCuqBIxFjflWJWanXIb3RllmbCylyMrvgv0= +github.com/mwitkow/go-conntrack v0.0.0-20161129095857-cc309e4a2223/go.mod h1:qRWi+5nqEBWmkhHvq77mSJWrCKwh8bxhgT7d/eI7P4U= +github.com/nxadm/tail v1.4.8 h1:nPr65rt6Y5JFSKQO7qToXr7pePgD6Gwiw05lkbyAQTE= +github.com/nxadm/tail v1.4.8/go.mod h1:+ncqLTQzXmGhMZNUePPaPqPvBxHAIsmXswZKocGu+AU= +github.com/opencontainers/go-digest v1.0.0 h1:apOUWs51W5PlhuyGyz9FCeeBIOUDA/6nW8Oi/yOhh5U= +github.com/opencontainers/go-digest v1.0.0/go.mod h1:0JzlMkj0TRzQZfJkVvzbP0HBR3IKzErnv2BNG4W4MAM= +github.com/pkg/errors v0.8.0/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= +github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= +github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4= +github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= +github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= +github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/prometheus/client_golang v0.9.1/go.mod h1:7SWBe2y4D6OKWSNQJUaRYU/AaXPKyh/dDVn+NZz0KFw= +github.com/prometheus/client_golang v1.0.0/go.mod h1:db9x61etRT2tGnBNRi70OPL5FsnadC4Ky3P0J6CfImo= +github.com/prometheus/client_golang v1.4.1 h1:FFSuS004yOQEtDdTq+TAOLP5xUq63KqAFYyOi8zA+Y8= +github.com/prometheus/client_golang v1.4.1/go.mod h1:e9GMxYsXl05ICDXkRhurwBS4Q3OK1iX/F2sw+iXX5zU= +github.com/prometheus/client_model v0.0.0-20180712105110-5c3871d89910/go.mod h1:MbSGuTsp3dbXC40dX6PRTWyKYBIrTGTE9sqQNg2J8bo= +github.com/prometheus/client_model v0.0.0-20190129233127-fd36f4220a90/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA= +github.com/prometheus/client_model v0.2.0 h1:uq5h0d+GuxiXLJLNABMgp2qUWDPiLvgCzz2dUR+/W/M= +github.com/prometheus/client_model v0.2.0/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA= +github.com/prometheus/common v0.4.1/go.mod h1:TNfzLD0ON7rHzMJeJkieUDPYmFC7Snx/y86RQel1bk4= +github.com/prometheus/common v0.9.1 h1:KOMtN28tlbam3/7ZKEYKHhKoJZYYj3gMH4uc62x7X7U= +github.com/prometheus/common v0.9.1/go.mod h1:yhUN8i9wzaXS3w1O07YhxHEBxD+W35wd8bs7vj7HSQ4= +github.com/prometheus/procfs v0.0.0-20181005140218-185b4288413d/go.mod h1:c3At6R/oaqEKCNdg8wHV1ftS6bRYblBhIjjI8uT2IGk= +github.com/prometheus/procfs v0.0.2/go.mod h1:TjEm7ze935MbeOT/UhFTIMYKhuLP4wbCsTZCD3I8kEA= +github.com/prometheus/procfs v0.0.8 h1:+fpWZdT24pJBiqJdAwYBjPSk+5YmQzYNPYzQsdzLkt8= +github.com/prometheus/procfs v0.0.8/go.mod h1:7Qr8sr6344vo1JqZ6HhLceV9o3AJ1Ff+GxbHq6oeK9A= +github.com/sirupsen/logrus v1.2.0/go.mod h1:LxeOpSwHxABJmUn/MG1IvRgCAasNZTLOkJPxbbu5VWo= +github.com/sirupsen/logrus v1.4.2/go.mod h1:tLMulIdttU9McNUspp0xgXVQah82FyeX6MwdIuYE2rE= +github.com/sirupsen/logrus v1.7.0/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0= +github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/objx v0.1.1/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= +github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= +github.com/stretchr/testify v1.4.0 h1:2E4SXV/wtOkTonXsotYi4li6zVWxYlZuYNCXe9XRJyk= +github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4= +golang.org/x/crypto v0.0.0-20180904163835-0709b304e793/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= +golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= +golang.org/x/net v0.0.0-20181114220301-adae6a3d119a/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= +golang.org/x/net v0.0.0-20190613194153-d28f0bde5980 h1:dfGZHvZk057jK2MCeWus/TowKpJ8y4AmooUzdBSR9GU= +golang.org/x/net v0.0.0-20190613194153-d28f0bde5980/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s= +golang.org/x/sync v0.0.0-20181108010431-42b317875d0f/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sync v0.0.0-20181221193216-37e7f081c4d4/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sync v0.0.0-20190911185100-cd5d95a43a6e/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sys v0.0.0-20180905080454-ebe1bf3edb33/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= +golang.org/x/sys v0.0.0-20181116152217-5ac8a444bdc5/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= +golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= +golang.org/x/sys v0.0.0-20190422165155-953cdadca894/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20191005200804-aed5e4c7ecf9/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20191026070338-33540a1f6037/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20200122134326-e047566fdf82/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210124154548-22da62e12c0c h1:VwygUrnw9jn88c4u8GD3rZQbqrP/tgas88tPUbBxQrk= +golang.org/x/sys v0.0.0-20210124154548-22da62e12c0c/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= +golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= +gopkg.in/alecthomas/kingpin.v2 v2.2.6/go.mod h1:FMv+mEhP44yOT+4EoQTLFTRgOQ1FBLkstjWtayDeSgw= +gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15 h1:YR8cESwS4TdDjEe65xsg0ogRM/Nc3DYOhEAlW+xobZo= +gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/tomb.v1 v1.0.0-20141024135613-dd632973f1e7 h1:uRGJdciOHaEIrze2W8Q3AKkepLTh2hOroT7a+7czfdQ= +gopkg.in/tomb.v1 v1.0.0-20141024135613-dd632973f1e7/go.mod h1:dt/ZhP58zS4L8KSrWDmTeBkI65Dw0HsyUHuEVlX15mw= +gopkg.in/yaml.v2 v2.2.1/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= +gopkg.in/yaml.v2 v2.2.2/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= +gopkg.in/yaml.v2 v2.2.4/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= +gopkg.in/yaml.v2 v2.2.5 h1:ymVxjfMaHvXD8RqPRmzHHsB3VvucivSkIAvJFDI5O3c= +gopkg.in/yaml.v2 v2.2.5/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= diff --git a/logsource.go b/logsource.go new file mode 100644 index 0000000..492d2e2 --- /dev/null +++ b/logsource.go @@ -0,0 +1,64 @@ +package main + +import ( + "context" + "fmt" + "io" + + "github.com/alecthomas/kingpin" +) + +// A LogSourceFactory provides a repository of log sources that can be +// instantiated from command line flags. +type LogSourceFactory interface { + // Init adds the factory's struct fields as flags in the + // application. + Init(*kingpin.Application) + + // New attempts to create a new log source. This is called after + // flags have been parsed. Returning `nil, nil`, means the user + // didn't want this log source. + New(context.Context) (LogSourceCloser, error) +} + +type LogSourceCloser interface { + io.Closer + LogSource +} + +var logSourceFactories []LogSourceFactory + +// RegisterLogSourceFactory can be called from module `init` functions +// to register factories. +func RegisterLogSourceFactory(lsf LogSourceFactory) { + logSourceFactories = append(logSourceFactories, lsf) +} + +// InitLogSourceFactories runs Init on all factories. The +// initialization order is arbitrary, except `fileLogSourceFactory` is +// always last (the fallback). The file log source must be last since +// it's enabled by default. +func InitLogSourceFactories(app *kingpin.Application) { + RegisterLogSourceFactory(&fileLogSourceFactory{}) + + for _, f := range logSourceFactories { + f.Init(app) + } +} + +// NewLogSourceFromFactories iterates through the factories and +// attempts to instantiate a log source. The first factory to return +// success wins. +func NewLogSourceFromFactories(ctx context.Context) (LogSourceCloser, error) { + for _, f := range logSourceFactories { + src, err := f.New(ctx) + if err != nil { + return nil, err + } + if src != nil { + return src, nil + } + } + + return nil, fmt.Errorf("no log source configured") +} diff --git a/logsource_docker.go b/logsource_docker.go new file mode 100644 index 0000000..fa182a7 --- /dev/null +++ b/logsource_docker.go @@ -0,0 +1,96 @@ +// +build !nodocker + +package main + +import ( + "bufio" + "context" + "io" + "log" + "strings" + + "github.com/alecthomas/kingpin" + "github.com/docker/docker/api/types" + "github.com/docker/docker/client" +) + +// A DockerLogSource reads log records from the given Docker +// journal. +type DockerLogSource struct { + client DockerClient + containerID string + reader *bufio.Reader +} + +// A DockerClient is the client interface that client.Client +// provides. See https://pkg.go.dev/github.com/docker/docker/client +type DockerClient interface { + io.Closer + ContainerLogs(context.Context, string, types.ContainerLogsOptions) (io.ReadCloser, error) +} + +// NewDockerLogSource returns a log source for reading Docker logs. +func NewDockerLogSource(ctx context.Context, c DockerClient, containerID string) (*DockerLogSource, error) { + r, err := c.ContainerLogs(ctx, containerID, types.ContainerLogsOptions{ + ShowStdout: true, + ShowStderr: true, + Follow: true, + Tail: "0", + }) + if err != nil { + return nil, err + } + + logSrc := &DockerLogSource{ + client: c, + containerID: containerID, + reader: bufio.NewReader(r), + } + + return logSrc, nil +} + +func (s *DockerLogSource) Close() error { + return s.client.Close() +} + +func (s *DockerLogSource) Path() string { + return "docker:" + s.containerID +} + +func (s *DockerLogSource) Read(ctx context.Context) (string, error) { + line, err := s.reader.ReadString('\n') + if err != nil { + return "", err + } + return strings.TrimSpace(line), nil +} + +// A dockerLogSourceFactory is a factory that can create +// DockerLogSources from command line flags. +type dockerLogSourceFactory struct { + enable bool + containerID string +} + +func (f *dockerLogSourceFactory) Init(app *kingpin.Application) { + app.Flag("docker.enable", "Read from Docker logs. Environment variable DOCKER_HOST can be used to change the address. See https://pkg.go.dev/github.com/docker/docker/client?tab=doc#NewEnvClient for more information.").Default("false").BoolVar(&f.enable) + app.Flag("docker.container.id", "ID/name of the Postfix Docker container.").Default("postfix").StringVar(&f.containerID) +} + +func (f *dockerLogSourceFactory) New(ctx context.Context) (LogSourceCloser, error) { + if !f.enable { + return nil, nil + } + + log.Println("Reading log events from Docker") + c, err := client.NewEnvClient() + if err != nil { + return nil, err + } + return NewDockerLogSource(ctx, c, f.containerID) +} + +func init() { + RegisterLogSourceFactory(&dockerLogSourceFactory{}) +} diff --git a/logsource_docker_test.go b/logsource_docker_test.go new file mode 100644 index 0000000..74231c2 --- /dev/null +++ b/logsource_docker_test.go @@ -0,0 +1,79 @@ +// +build !nodocker + +package main + +import ( + "context" + "io" + "io/ioutil" + "strings" + "testing" + + "github.com/docker/docker/api/types" + "github.com/stretchr/testify/assert" +) + +func TestNewDockerLogSource(t *testing.T) { + ctx := context.Background() + c := &fakeDockerClient{} + src, err := NewDockerLogSource(ctx, c, "acontainer") + if err != nil { + t.Fatalf("NewDockerLogSource failed: %v", err) + } + + assert.Equal(t, []string{"acontainer"}, c.containerLogsCalls, "A call to ContainerLogs should be made.") + + if err := src.Close(); err != nil { + t.Fatalf("Close failed: %v", err) + } + + assert.Equal(t, 1, c.closeCalls, "A call to Close should be made.") +} + +func TestDockerLogSource_Path(t *testing.T) { + ctx := context.Background() + c := &fakeDockerClient{} + src, err := NewDockerLogSource(ctx, c, "acontainer") + if err != nil { + t.Fatalf("NewDockerLogSource failed: %v", err) + } + defer src.Close() + + assert.Equal(t, "docker:acontainer", src.Path(), "Path should be set by New.") +} + +func TestDockerLogSource_Read(t *testing.T) { + ctx := context.Background() + + c := &fakeDockerClient{ + logsReader: ioutil.NopCloser(strings.NewReader("Feb 13 23:31:30 ahost anid[123]: aline\n")), + } + src, err := NewDockerLogSource(ctx, c, "acontainer") + if err != nil { + t.Fatalf("NewDockerLogSource failed: %v", err) + } + defer src.Close() + + s, err := src.Read(ctx) + if err != nil { + t.Fatalf("Read failed: %v", err) + } + assert.Equal(t, "Feb 13 23:31:30 ahost anid[123]: aline", s, "Read should get data from the journal entry.") +} + +type fakeDockerClient struct { + logsReader io.ReadCloser + + containerLogsCalls []string + closeCalls int +} + +func (c *fakeDockerClient) ContainerLogs(ctx context.Context, containerID string, opts types.ContainerLogsOptions) (io.ReadCloser, error) { + c.containerLogsCalls = append(c.containerLogsCalls, containerID) + return c.logsReader, nil +} + +func (c *fakeDockerClient) Close() error { + c.closeCalls++ + return nil +} diff --git a/logsource_file.go b/logsource_file.go new file mode 100644 index 0000000..afcfa68 --- /dev/null +++ b/logsource_file.go @@ -0,0 +1,78 @@ +package main + +import ( + "context" + "io" + "log" + + "github.com/alecthomas/kingpin" + "github.com/nxadm/tail" +) + +// A FileLogSource can read lines from a file. +type FileLogSource struct { + tailer *tail.Tail +} + +// NewFileLogSource creates a new log source, tailing the given file. +func NewFileLogSource(path string) (*FileLogSource, error) { + tailer, err := tail.TailFile(path, tail.Config{ + ReOpen: true, // reopen the file if it's rotated + MustExist: true, // fail immediately if the file is missing or has incorrect permissions + Follow: true, // run in follow mode + Location: &tail.SeekInfo{Whence: io.SeekEnd}, // seek to end of file + Logger: tail.DiscardingLogger, + }) + if err != nil { + return nil, err + } + return &FileLogSource{tailer}, nil +} + +func (s *FileLogSource) Close() error { + defer s.tailer.Cleanup() + go func() { + // Stop() waits for the tailer goroutine to shut down, but it + // can be blocking on sending on the Lines channel... + for range s.tailer.Lines { + } + }() + return s.tailer.Stop() +} + +func (s *FileLogSource) Path() string { + return s.tailer.Filename +} + +func (s *FileLogSource) Read(ctx context.Context) (string, error) { + select { + case line, ok := <-s.tailer.Lines: + if !ok { + return "", io.EOF + } + return line.Text, nil + case <-ctx.Done(): + return "", ctx.Err() + } +} + +// A fileLogSourceFactory is a factory than can create log sources +// from command line flags. +// +// Because this factory is enabled by default, it must always be +// registered last. +type fileLogSourceFactory struct { + path string +} + +func (f *fileLogSourceFactory) Init(app *kingpin.Application) { + app.Flag("postfix.logfile_path", "Path where Postfix writes log entries.").Default("/var/log/mail.log").StringVar(&f.path) +} + +func (f *fileLogSourceFactory) New(ctx context.Context) (LogSourceCloser, error) { + if f.path == "" { + return nil, nil + } + log.Printf("Reading log events from %s", f.path) + return NewFileLogSource(f.path) +} diff --git a/logsource_file_test.go b/logsource_file_test.go new file mode 100644 index 0000000..673be04 --- /dev/null +++ b/logsource_file_test.go @@ -0,0 +1,87 @@ +package main + +import ( + "context" + "fmt" + "io/ioutil" + "os" + "sync" + "testing" + "time" + + "github.com/stretchr/testify/assert" +) + +func TestFileLogSource_Path(t *testing.T) { + path, close, err := setupFakeLogFile() + if err != nil { + t.Fatalf("setupFakeTailer failed: %v", err) + } + defer close() + + src, err := NewFileLogSource(path) + if err != nil { + t.Fatalf("NewFileLogSource failed: %v", err) + } + defer src.Close() + + assert.Equal(t, path, src.Path(), "Path should be set by New.") +} + +func TestFileLogSource_Read(t *testing.T) { + ctx := context.Background() + + path, close, err := setupFakeLogFile() + if err != nil { + t.Fatalf("setupFakeTailer failed: %v", err) + } + defer close() + + src, err := NewFileLogSource(path) + if err != nil { + t.Fatalf("NewFileLogSource failed: %v", err) + } + defer src.Close() + + s, err := src.Read(ctx) + if err != nil { + t.Fatalf("Read failed: %v", err) + } + assert.Equal(t, "Feb 13 23:31:30 ahost anid[123]: aline", s, "Read should get data from the journal entry.") +} + +func setupFakeLogFile() (string, func(), error) { + f, err := ioutil.TempFile("", "filelogsource") + if err != nil { + return "", nil, err + } + + ctx, cancel := context.WithCancel(context.Background()) + var wg sync.WaitGroup + + wg.Add(1) + go func() { + defer wg.Done() + defer os.Remove(f.Name()) + defer f.Close() + + for { + // The tailer seeks to the end and then does a + // follow. Keep writing lines so we know it wakes up and + // returns lines. + fmt.Fprintln(f, "Feb 13 23:31:30 ahost anid[123]: aline") + + select { + case <-time.After(10 * time.Millisecond): + // continue + case <-ctx.Done(): + return + } + } + }() + + return f.Name(), func() { + cancel() + wg.Wait() + }, nil +} diff --git a/logsource_systemd.go b/logsource_systemd.go new file mode 100644 index 0000000..60f5cb6 --- /dev/null +++ b/logsource_systemd.go @@ -0,0 +1,143 @@ +// +build !nosystemd,linux + +package main + +import ( + "context" + "fmt" + "io" + "log" + "time" + + "github.com/alecthomas/kingpin" + "github.com/coreos/go-systemd/v22/sdjournal" +) + +// timeNow is a test fake injection point. +var timeNow = time.Now + +// A SystemdLogSource reads log records from the given Systemd +// journal. +type SystemdLogSource struct { + journal SystemdJournal + path string +} + +// A SystemdJournal is the journal interface that sdjournal.Journal +// provides. See https://pkg.go.dev/github.com/coreos/go-systemd/sdjournal?tab=doc +type SystemdJournal interface { + io.Closer + AddMatch(match string) error + GetEntry() (*sdjournal.JournalEntry, error) + Next() (uint64, error) + SeekRealtimeUsec(usec uint64) error + Wait(timeout time.Duration) int +} + +// NewSystemdLogSource returns a log source for reading Systemd +// journal entries. `unit` and `slice` provide filtering if non-empty +// (with `slice` taking precedence). +func NewSystemdLogSource(j SystemdJournal, path, unit, slice string) (*SystemdLogSource, error) { + logSrc := &SystemdLogSource{journal: j, path: path} + + var err error + if slice != "" { + err = logSrc.journal.AddMatch("_SYSTEMD_SLICE=" + slice) + } else if unit != "" { + err = logSrc.journal.AddMatch("_SYSTEMD_UNIT=" + unit) + } + if err != nil { + logSrc.journal.Close() + return nil, err + } + + // Start at end of journal + if err := logSrc.journal.SeekRealtimeUsec(uint64(timeNow().UnixNano() / 1000)); err != nil { + logSrc.journal.Close() + return nil, err + } + + if r := logSrc.journal.Wait(1 * time.Second); r < 0 { + logSrc.journal.Close() + return nil, err + } + + return logSrc, nil +} + +func (s *SystemdLogSource) Close() error { + return s.journal.Close() +} + +func (s *SystemdLogSource) Path() string { + return s.path +} + +func (s *SystemdLogSource) Read(ctx context.Context) (string, error) { + c, err := s.journal.Next() + if err != nil { + return "", err + } + if c == 0 { + return "", io.EOF + } + + e, err := s.journal.GetEntry() + if err != nil { + return "", err + } + ts := time.Unix(0, int64(e.RealtimeTimestamp)*int64(time.Microsecond)) + + return fmt.Sprintf( + "%s %s %s[%s]: %s", + ts.Format(time.Stamp), + e.Fields["_HOSTNAME"], + e.Fields["SYSLOG_IDENTIFIER"], + e.Fields["_PID"], + e.Fields["MESSAGE"], + ), nil +} + +// A systemdLogSourceFactory is a factory that can create +// SystemdLogSources from command line flags. +type systemdLogSourceFactory struct { + enable bool + unit, slice, path string +} + +func (f *systemdLogSourceFactory) Init(app *kingpin.Application) { + app.Flag("systemd.enable", "Read from the systemd journal instead of log").Default("false").BoolVar(&f.enable) + app.Flag("systemd.unit", "Name of the Postfix systemd unit.").Default("postfix.service").StringVar(&f.unit) + app.Flag("systemd.slice", "Name of the Postfix systemd slice. Overrides the systemd unit.").Default("").StringVar(&f.slice) + app.Flag("systemd.journal_path", "Path to the systemd journal").Default("").StringVar(&f.path) +} + +func (f *systemdLogSourceFactory) New(ctx context.Context) (LogSourceCloser, error) { + if !f.enable { + return nil, nil + } + + log.Println("Reading log events from systemd") + j, path, err := newSystemdJournal(f.path) + if err != nil { + return nil, err + } + return NewSystemdLogSource(j, path, f.unit, f.slice) +} + +// newSystemdJournal creates a journal handle. It returns the handle +// and a string representation of it. If `path` is empty, it connects +// to the local journald. +func newSystemdJournal(path string) (*sdjournal.Journal, string, error) { + if path != "" { + j, err := sdjournal.NewJournalFromDir(path) + return j, path, err + } + + j, err := sdjournal.NewJournal() + return j, "journald", err +} + +func init() { + RegisterLogSourceFactory(&systemdLogSourceFactory{}) +} diff --git a/logsource_systemd_test.go b/logsource_systemd_test.go new file mode 100644 index 0000000..a1f9c4a --- /dev/null +++ b/logsource_systemd_test.go @@ -0,0 +1,150 @@ +// +build !nosystemd,linux + +package main + +import ( + "context" + "io" + "os" + "testing" + "time" + + "github.com/coreos/go-systemd/v22/sdjournal" + "github.com/stretchr/testify/assert" +) + +func TestNewSystemdLogSource(t *testing.T) { + j := &fakeSystemdJournal{} + src, err := NewSystemdLogSource(j, "apath", "aunit", "aslice") + if err != nil { + t.Fatalf("NewSystemdLogSource failed: %v", err) + } + + assert.Equal(t, []string{"_SYSTEMD_SLICE=aslice"}, j.addMatchCalls, "A match should be added for slice.") + assert.Equal(t, []uint64{1234567890000000}, j.seekRealtimeUsecCalls, "A call to SeekRealtimeUsec should be made.") + assert.Equal(t, []time.Duration{1 * time.Second}, j.waitCalls, "A call to Wait should be made.") + + if err := src.Close(); err != nil { + t.Fatalf("Close failed: %v", err) + } + + assert.Equal(t, 1, j.closeCalls, "A call to Close should be made.") +} + +func TestSystemdLogSource_Path(t *testing.T) { + j := &fakeSystemdJournal{} + src, err := NewSystemdLogSource(j, "apath", "aunit", "aslice") + if err != nil { + t.Fatalf("NewSystemdLogSource failed: %v", err) + } + defer src.Close() + + assert.Equal(t, "apath", src.Path(), "Path should be set by New.") +} + +func TestSystemdLogSource_Read(t *testing.T) { + ctx := context.Background() + + j := &fakeSystemdJournal{ + getEntryValues: []sdjournal.JournalEntry{ + { + Fields: map[string]string{ + "_HOSTNAME": "ahost", + "SYSLOG_IDENTIFIER": "anid", + "_PID": "123", + "MESSAGE": "aline", + }, + RealtimeTimestamp: 1234567890000000, + }, + }, + nextValues: []uint64{1}, + } + src, err := NewSystemdLogSource(j, "apath", "aunit", "aslice") + if err != nil { + t.Fatalf("NewSystemdLogSource failed: %v", err) + } + defer src.Close() + + s, err := src.Read(ctx) + if err != nil { + t.Fatalf("Read failed: %v", err) + } + assert.Equal(t, "Feb 13 23:31:30 ahost anid[123]: aline", s, "Read should get data from the journal entry.") +} + +func TestSystemdLogSource_ReadEOF(t *testing.T) { + ctx := context.Background() + + j := &fakeSystemdJournal{ + nextValues: []uint64{0}, + } + src, err := NewSystemdLogSource(j, "apath", "aunit", "aslice") + if err != nil { + t.Fatalf("NewSystemdLogSource failed: %v", err) + } + defer src.Close() + + _, err = src.Read(ctx) + assert.Equal(t, io.EOF, err, "Should interpret Next 0 as EOF.") +} + +func TestMain(m *testing.M) { + // We compare Unix timestamps to date strings, so make it deterministic. + os.Setenv("TZ", "UTC") + timeNow = func() time.Time { return time.Date(2009, 2, 13, 23, 31, 30, 0, time.UTC) } + defer func() { + timeNow = time.Now + }() + + os.Exit(m.Run()) +} + +type fakeSystemdJournal struct { + getEntryValues []sdjournal.JournalEntry + getEntryError error + nextValues []uint64 + nextError error + + addMatchCalls []string + closeCalls int + seekRealtimeUsecCalls []uint64 + waitCalls []time.Duration +} + +func (j *fakeSystemdJournal) AddMatch(match string) error { + j.addMatchCalls = append(j.addMatchCalls, match) + return nil +} + +func (j *fakeSystemdJournal) Close() error { + j.closeCalls++ + return nil +} + +func (j *fakeSystemdJournal) GetEntry() (*sdjournal.JournalEntry, error) { + if len(j.getEntryValues) == 0 { + return nil, j.getEntryError + } + e := j.getEntryValues[0] + j.getEntryValues = j.getEntryValues[1:] + return &e, nil +} + +func (j *fakeSystemdJournal) Next() (uint64, error) { + if len(j.nextValues) == 0 { + return 0, j.nextError + } + v := j.nextValues[0] + j.nextValues = j.nextValues[1:] + return v, nil +} + +func (j *fakeSystemdJournal) SeekRealtimeUsec(usec uint64) error { + j.seekRealtimeUsecCalls = append(j.seekRealtimeUsecCalls, usec) + return nil +} + +func (j *fakeSystemdJournal) Wait(timeout time.Duration) int { + j.waitCalls = append(j.waitCalls, timeout) + return 0 +} diff --git a/main.go b/main.go new file mode 100644 index 0000000..c92d7d5 --- /dev/null +++ b/main.go @@ -0,0 +1,62 @@ +package main + +import ( + "context" + "log" + "net/http" + "os" + + "github.com/alecthomas/kingpin" + "github.com/prometheus/client_golang/prometheus" + "github.com/prometheus/client_golang/prometheus/promhttp" +) + +func main() { + var ( + ctx = context.Background() + app = kingpin.New("postfix_exporter", "Prometheus metrics exporter for postfix") + 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() + logUnsupportedLines = app.Flag("log.unsupported", "Log all unsupported lines.").Bool() + ) + + InitLogSourceFactories(app) + kingpin.MustParse(app.Parse(os.Args[1:])) + + logSrc, err := NewLogSourceFromFactories(ctx) + if err != nil { + log.Fatalf("Error opening log source: %s", err) + } + defer logSrc.Close() + + exporter, err := NewPostfixExporter( + *postfixShowqPath, + logSrc, + *logUnsupportedLines, + ) + if err != nil { + log.Fatalf("Failed to create PostfixExporter: %s", err) + } + prometheus.MustRegister(exporter) + + http.Handle(*metricsPath, promhttp.Handler()) + http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) { + _, err = w.Write([]byte(` + + Postfix Exporter + +

Postfix Exporter

+

Metrics

+ + `)) + if err != nil { + panic(err) + } + }) + ctx, cancelFunc := context.WithCancel(ctx) + defer cancelFunc() + go exporter.StartMetricCollection(ctx) + log.Print("Listening on ", *listenAddress) + log.Fatal(http.ListenAndServe(*listenAddress, nil)) +} 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 4817364..56691cc 100644 --- a/postfix_exporter.go +++ b/postfix_exporter.go @@ -16,14 +16,12 @@ package main import ( "bufio" "bytes" + "context" "errors" - "flag" "fmt" "io" "log" "net" - "net/http" - "os" "regexp" "strconv" "strings" @@ -42,19 +40,26 @@ var ( // PostfixExporter holds the state that should be preserved by the // Postfix Prometheus metrics exporter across scrapes. type PostfixExporter struct { - showqPath string - logfilePath string + showqPath string + logSrc LogSource + logUnsupportedLines bool // Metrics that should persist after refreshes, based on logs. cleanupProcesses prometheus.Counter cleanupRejects prometheus.Counter + cleanupNotAccepted prometheus.Counter lmtpDelays *prometheus.HistogramVec pipeDelays *prometheus.HistogramVec qmgrInsertsNrcpt prometheus.Histogram qmgrInsertsSize prometheus.Histogram qmgrRemoves prometheus.Counter + qmgrExpires prometheus.Counter smtpDelays *prometheus.HistogramVec smtpTLSConnects *prometheus.CounterVec + 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 smtpdConnects prometheus.Counter smtpdDisconnects prometheus.Counter smtpdFCrDNSErrors prometheus.Counter @@ -64,6 +69,21 @@ type PostfixExporter struct { smtpdSASLAuthenticationFailures prometheus.Counter smtpdTLSConnects *prometheus.CounterVec unsupportedLogEntries *prometheus.CounterVec + // same as smtpProcesses{status=deferred}, kept for compatibility + smtpStatusDeferred prometheus.Counter + opendkimSignatureAdded *prometheus.CounterVec + bounceNonDelivery prometheus.Counter + virtualDelivered prometheus.Counter +} + +// A LogSource is an interface to read log lines. +type LogSource interface { + // Path returns a representation of the log location. + Path() string + + // Read returns the next log line. Returns `io.EOF` at the end of + // the log. + Read(context.Context) (string, error) } // CollectShowqFromReader parses the output of Postfix's 'showq' command @@ -76,7 +96,10 @@ type PostfixExporter struct { // for null bytes in the first 128 bytes of output. func CollectShowqFromReader(file io.Reader, ch chan<- prometheus.Metric) error { reader := bufio.NewReader(file) - buf, _ := reader.Peek(128) + buf, err := reader.Peek(128) + if err != nil && err != io.EOF { + log.Printf("Could not read postfix output, %v", err) + } if bytes.IndexByte(buf, 0) >= 0 { return CollectBinaryShowqFromReader(reader, ch) } @@ -85,12 +108,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( @@ -110,46 +127,72 @@ func CollectTextualShowqFromReader(file io.Reader, ch chan<- prometheus.Metric) }, []string{"queue"}) - now := time.Now() - location, _ := time.LoadLocation("Local") - for scanner.Scan() { - matches := messageLine.FindStringSubmatch(scanner.Text()) - if matches != nil { - // Derive the name of the message queue. - queue := "other" - if matches[1] == "*" { - queue = "active" - } else if matches[1] == "!" { - queue = "hold" - } + err := CollectTextualShowqFromScanner(sizeHistogram, ageHistogram, file) - // Parse the message size. - size, err := strconv.ParseFloat(matches[2], 64) - if err != nil { - return err - } + sizeHistogram.Collect(ch) + ageHistogram.Collect(ch) + return err +} - // Parse the message date. Unfortunately, the - // 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) - if err != nil { - return err - } - date = date.AddDate(now.Year(), 0, 0) - if date.After(now) { - date = date.AddDate(-1, 0, 0) - } +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) + } - sizeHistogram.WithLabelValues(queue).Observe(size) - ageHistogram.WithLabelValues(queue).Observe(now.Sub(date).Seconds()) - } + location, err := time.LoadLocation("Local") + if err != nil { + log.Println(err) } - sizeHistogram.Collect(ch) - ageHistogram.Collect(ch) + // 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() { + 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 queueMatch == "*" { + queue = "active" + } else if queueMatch == "!" { + queue = "hold" + } + + // Parse the message size. + size, err := strconv.ParseFloat(sizeMatch, 64) + if err != nil { + return err + } + + // Parse the message date. Unfortunately, the + // 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", 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) + } + + sizeHistogram.WithLabelValues(queue).Observe(size) + ageHistogram.WithLabelValues(queue).Observe(now.Sub(date).Seconds()) + } return scanner.Err() } @@ -191,6 +234,12 @@ func CollectBinaryShowqFromReader(file io.Reader, ch chan<- prometheus.Metric) e }, []string{"queue"}) + // Initialize all queue buckets to zero. + for _, q := range []string{"active", "deferred", "hold", "incoming", "maildrop"} { + sizeHistogram.WithLabelValues(q) + ageHistogram.WithLabelValues(q) + } + now := float64(time.Now().UnixNano()) / 1e9 queue := "unknown" for scanner.Scan() { @@ -218,11 +267,11 @@ func CollectBinaryShowqFromReader(file io.Reader, ch chan<- prometheus.Metric) e sizeHistogram.WithLabelValues(queue).Observe(size) } else if key == "time" { // Message time as a UNIX timestamp. - time, err := strconv.ParseFloat(value, 64) + utime, err := strconv.ParseFloat(value, 64) if err != nil { return err } - ageHistogram.WithLabelValues(queue).Observe(now - time) + ageHistogram.WithLabelValues(queue).Observe(now - utime) } } @@ -231,16 +280,6 @@ func CollectBinaryShowqFromReader(file io.Reader, ch chan<- prometheus.Metric) e return scanner.Err() } -// CollectShowqFromFile collects Postfix queue statistics from a file. -func CollectShowqFromFile(path string, ch chan<- prometheus.Metric) error { - fd, err := os.Open(path) - if err != nil { - return err - } - defer fd.Close() - return CollectShowqFromReader(fd, ch) -} - // CollectShowqFromSocket collects Postfix queue statistics from a socket. func CollectShowqFromSocket(path string, ch chan<- prometheus.Metric) error { fd, err := net.Dial("unix", path) @@ -251,144 +290,177 @@ func CollectShowqFromSocket(path string, ch chan<- prometheus.Metric) error { return CollectShowqFromReader(fd, ch) } -// CollectLogfileFromReader collects metrics from a Postfix logfile, -// using a reader object. -func (e *PostfixExporter) CollectLogfileFromReader(file io.Reader) error { - scanner := bufio.NewScanner(file) - scanner.Split(bufio.ScanLines) +// Patterns for parsing log messages. +var ( + 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\.]+), `) + qmgrInsertLine = regexp.MustCompile(`:.*, size=(\d+), nrcpt=(\d+) `) + 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\)`) + smtpConnectionTimedOut = regexp.MustCompile(`^connect\s+to\s+(.*)\[(.*)\]:(\d+):\s+(Connection timed out)$`) + smtpdFCrDNSErrorsLine = regexp.MustCompile(`^warning: hostname \S+ does not resolve to address `) + smtpdProcessesSASLLine = regexp.MustCompile(`: client=.*, sasl_method=(\S+)`) + smtpdRejectsLine = regexp.MustCompile(`^NOQUEUE: reject: RCPT from \S+: ([0-9]+) `) + smtpdLostConnectionLine = regexp.MustCompile(`^lost connection after (\w+) from `) + 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\)`) + opendkimSignatureAdded = regexp.MustCompile(`^[\w\d]+: DKIM-Signature field added \(s=(\w+), d=(.*)\)$`) + bounceNonDeliveryLine = regexp.MustCompile(`: sender non-delivery notification: `) +) - // Patterns for parsing log messages. - logLine := regexp.MustCompile(" postfix/(\\w+)\\[\\d+\\]: (.*)") - lmtpPipeSMTPLine := regexp.MustCompile(", relay=(\\S+), .*, delays=([0-9\\.]+)/([0-9\\.]+)/([0-9\\.]+)/([0-9\\.]+), ") - qmgrInsertLine := regexp.MustCompile(":.*, size=(\\d+), nrcpt=(\\d+) ") - smtpTLSLine := regexp.MustCompile("^(\\S+) TLS connection established to \\S+: (\\S+) with cipher (\\S+) \\((\\d+)/(\\d+) bits\\)$") - smtpdFCrDNSErrorsLine := regexp.MustCompile("^warning: hostname \\S+ does not resolve to address ") - smtpdProcessesSASLLine := regexp.MustCompile(": client=.*, sasl_username=(\\S+)") - smtpdRejectsLine := regexp.MustCompile("^NOQUEUE: reject: RCPT from \\S+: ([0-9]+) ") - smtpdLostConnectionLine := regexp.MustCompile("^lost connection after (\\w+) from ") - 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\\)$") +// CollectFromLogline collects metrict from a Postfix log line. +func (e *PostfixExporter) CollectFromLogLine(line string) { + // Strip off timestamp, hostname, etc. + logMatches := logLine.FindStringSubmatch(line) - for scanner.Scan() { - // Strip off timestamp, hostname, etc. - if logMatches := logLine.FindStringSubmatch(scanner.Text()); logMatches != nil { - // Group patterns to check by Postfix service. - if logMatches[1] == "cleanup" { - if strings.Contains(logMatches[2], ": message-id=<") { - e.cleanupProcesses.Inc() - } else if strings.Contains(logMatches[2], ": reject: ") { - e.cleanupRejects.Inc() - } else { - e.unsupportedLogEntries.WithLabelValues(logMatches[1]).Inc() - } - } else if logMatches[1] == "lmtp" { - if lmtpMatches := lmtpPipeSMTPLine.FindStringSubmatch(logMatches[2]); lmtpMatches != nil { - pdelay, _ := strconv.ParseFloat(lmtpMatches[2], 64) - e.lmtpDelays.WithLabelValues("before_queue_manager").Observe(pdelay) - adelay, _ := strconv.ParseFloat(lmtpMatches[3], 64) - e.lmtpDelays.WithLabelValues("queue_manager").Observe(adelay) - sdelay, _ := strconv.ParseFloat(lmtpMatches[4], 64) - e.lmtpDelays.WithLabelValues("connection_setup").Observe(sdelay) - xdelay, _ := strconv.ParseFloat(lmtpMatches[5], 64) - e.lmtpDelays.WithLabelValues("transmission").Observe(xdelay) - } else { - e.unsupportedLogEntries.WithLabelValues(logMatches[1]).Inc() - } - } else if logMatches[1] == "pipe" { - if pipeMatches := lmtpPipeSMTPLine.FindStringSubmatch(logMatches[2]); pipeMatches != nil { - pdelay, _ := strconv.ParseFloat(pipeMatches[2], 64) - e.pipeDelays.WithLabelValues(pipeMatches[1], "before_queue_manager").Observe(pdelay) - adelay, _ := strconv.ParseFloat(pipeMatches[3], 64) - e.pipeDelays.WithLabelValues(pipeMatches[1], "queue_manager").Observe(adelay) - sdelay, _ := strconv.ParseFloat(pipeMatches[4], 64) - e.pipeDelays.WithLabelValues(pipeMatches[1], "connection_setup").Observe(sdelay) - xdelay, _ := strconv.ParseFloat(pipeMatches[5], 64) - e.pipeDelays.WithLabelValues(pipeMatches[1], "transmission").Observe(xdelay) - } else { - e.unsupportedLogEntries.WithLabelValues(logMatches[1]).Inc() - } - } else if logMatches[1] == "qmgr" { - if qmgrInsertMatches := qmgrInsertLine.FindStringSubmatch(logMatches[2]); qmgrInsertMatches != nil { - size, _ := strconv.ParseFloat(qmgrInsertMatches[1], 64) - e.qmgrInsertsSize.Observe(size) - nrcpt, _ := strconv.ParseFloat(qmgrInsertMatches[2], 64) - e.qmgrInsertsNrcpt.Observe(nrcpt) - } else if strings.HasSuffix(logMatches[2], ": removed") { - e.qmgrRemoves.Inc() - } else { - e.unsupportedLogEntries.WithLabelValues(logMatches[1]).Inc() - } - } else if logMatches[1] == "smtp" { - if smtpMatches := lmtpPipeSMTPLine.FindStringSubmatch(logMatches[2]); smtpMatches != nil { - pdelay, _ := strconv.ParseFloat(smtpMatches[2], 64) - e.smtpDelays.WithLabelValues("before_queue_manager").Observe(pdelay) - adelay, _ := strconv.ParseFloat(smtpMatches[3], 64) - e.smtpDelays.WithLabelValues("queue_manager").Observe(adelay) - sdelay, _ := strconv.ParseFloat(smtpMatches[4], 64) - e.smtpDelays.WithLabelValues("connection_setup").Observe(sdelay) - xdelay, _ := strconv.ParseFloat(smtpMatches[5], 64) - e.smtpDelays.WithLabelValues("transmission").Observe(xdelay) - } else if smtpTLSMatches := smtpTLSLine.FindStringSubmatch(logMatches[2]); smtpTLSMatches != nil { - e.smtpTLSConnects.WithLabelValues(smtpTLSMatches[1:]...).Inc() - } else { - e.unsupportedLogEntries.WithLabelValues(logMatches[1]).Inc() - } - } else if logMatches[1] == "smtpd" { - if strings.HasPrefix(logMatches[2], "connect from ") { - e.smtpdConnects.Inc() - } else if strings.HasPrefix(logMatches[2], "disconnect from ") { - e.smtpdDisconnects.Inc() - } else if smtpdFCrDNSErrorsLine.MatchString(logMatches[2]) { - e.smtpdFCrDNSErrors.Inc() - } else if smtpdLostConnectionMatches := smtpdLostConnectionLine.FindStringSubmatch(logMatches[2]); smtpdLostConnectionMatches != nil { - e.smtpdLostConnections.WithLabelValues(smtpdLostConnectionMatches[1]).Inc() - } else if smtpdProcessesSASLMatches := smtpdProcessesSASLLine.FindStringSubmatch(logMatches[2]); smtpdProcessesSASLMatches != nil { - e.smtpdProcesses.WithLabelValues(smtpdProcessesSASLMatches[1]).Inc() - } else if strings.Contains(logMatches[2], ": client=") { - e.smtpdProcesses.WithLabelValues("").Inc() - } else if smtpdRejectsMatches := smtpdRejectsLine.FindStringSubmatch(logMatches[2]); smtpdRejectsMatches != nil { - e.smtpdRejects.WithLabelValues(smtpdRejectsMatches[1]).Inc() - } else if smtpdSASLAuthenticationFailuresLine.MatchString(logMatches[2]) { - e.smtpdSASLAuthenticationFailures.Inc() - } else if smtpdTLSMatches := smtpdTLSLine.FindStringSubmatch(logMatches[2]); smtpdTLSMatches != nil { - e.smtpdTLSConnects.WithLabelValues(smtpdTLSMatches[1:]...).Inc() - } else { - e.unsupportedLogEntries.WithLabelValues(logMatches[1]).Inc() + if logMatches == nil { + // Unknown log entry format. + e.addToUnsupportedLine(line, "", "") + return + } + process := logMatches[1] + level := logMatches[5] + remainder := logMatches[4] + switch process { + case "postfix": + // Group patterns to check by Postfix service. + subprocess := logMatches[3] + switch subprocess { + case "cleanup": + if strings.Contains(remainder, ": message-id=<") { + e.cleanupProcesses.Inc() + } else if strings.Contains(remainder, ": reject: ") { + e.cleanupRejects.Inc() + } else { + e.addToUnsupportedLine(line, subprocess, level) + } + case "lmtp": + if lmtpMatches := lmtpPipeSMTPLine.FindStringSubmatch(remainder); lmtpMatches != nil { + addToHistogramVec(e.lmtpDelays, lmtpMatches[2], "LMTP pdelay", "before_queue_manager") + addToHistogramVec(e.lmtpDelays, lmtpMatches[3], "LMTP adelay", "queue_manager") + addToHistogramVec(e.lmtpDelays, lmtpMatches[4], "LMTP sdelay", "connection_setup") + addToHistogramVec(e.lmtpDelays, lmtpMatches[5], "LMTP xdelay", "transmission") + } else { + e.addToUnsupportedLine(line, subprocess, level) + } + case "pipe": + if pipeMatches := lmtpPipeSMTPLine.FindStringSubmatch(remainder); pipeMatches != nil { + addToHistogramVec(e.pipeDelays, pipeMatches[2], "PIPE pdelay", pipeMatches[1], "before_queue_manager") + addToHistogramVec(e.pipeDelays, pipeMatches[3], "PIPE adelay", pipeMatches[1], "queue_manager") + addToHistogramVec(e.pipeDelays, pipeMatches[4], "PIPE sdelay", pipeMatches[1], "connection_setup") + addToHistogramVec(e.pipeDelays, pipeMatches[5], "PIPE xdelay", pipeMatches[1], "transmission") + } else { + e.addToUnsupportedLine(line, subprocess, level) + } + case "qmgr": + if qmgrInsertMatches := qmgrInsertLine.FindStringSubmatch(remainder); qmgrInsertMatches != nil { + addToHistogram(e.qmgrInsertsSize, qmgrInsertMatches[1], "QMGR size") + addToHistogram(e.qmgrInsertsNrcpt, qmgrInsertMatches[2], "QMGR nrcpt") + } else if strings.HasSuffix(remainder, ": removed") { + e.qmgrRemoves.Inc() + } else if qmgrExpired := qmgrExpiredLine.FindStringSubmatch(remainder); qmgrExpired != nil { + e.qmgrExpires.Inc() + } else { + e.addToUnsupportedLine(line, subprocess, level) + } + 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", "") + if smtpStatusMatches := smtpStatusLine.FindStringSubmatch(remainder); smtpStatusMatches != nil { + e.smtpProcesses.WithLabelValues(smtpStatusMatches[1]).Inc() + if smtpStatusMatches[1] == "deferred" { + e.smtpStatusDeferred.Inc() + } } + } else if smtpTLSMatches := smtpTLSLine.FindStringSubmatch(remainder); smtpTLSMatches != nil { + e.smtpTLSConnects.WithLabelValues(smtpTLSMatches[1:]...).Inc() + } else if smtpMatches := smtpConnectionTimedOut.FindStringSubmatch(remainder); smtpMatches != nil { + e.smtpConnectionTimedOut.Inc() + } else { + e.addToUnsupportedLine(line, subprocess, level) + } + case "smtpd": + if strings.HasPrefix(remainder, "connect from ") { + e.smtpdConnects.Inc() + } else if strings.HasPrefix(remainder, "disconnect from ") { + e.smtpdDisconnects.Inc() + } else if smtpdFCrDNSErrorsLine.MatchString(remainder) { + e.smtpdFCrDNSErrors.Inc() + } else if smtpdLostConnectionMatches := smtpdLostConnectionLine.FindStringSubmatch(remainder); smtpdLostConnectionMatches != nil { + e.smtpdLostConnections.WithLabelValues(smtpdLostConnectionMatches[1]).Inc() + } else if smtpdProcessesSASLMatches := smtpdProcessesSASLLine.FindStringSubmatch(remainder); smtpdProcessesSASLMatches != nil { + e.smtpdProcesses.WithLabelValues(smtpdProcessesSASLMatches[1]).Inc() + } else if strings.Contains(remainder, ": client=") { + e.smtpdProcesses.WithLabelValues("").Inc() + } else if smtpdRejectsMatches := smtpdRejectsLine.FindStringSubmatch(remainder); smtpdRejectsMatches != nil { + e.smtpdRejects.WithLabelValues(smtpdRejectsMatches[1]).Inc() + } else if smtpdSASLAuthenticationFailuresLine.MatchString(remainder) { + e.smtpdSASLAuthenticationFailures.Inc() + } else if smtpdTLSMatches := smtpdTLSLine.FindStringSubmatch(remainder); smtpdTLSMatches != nil { + e.smtpdTLSConnects.WithLabelValues(smtpdTLSMatches[1:]...).Inc() } else { - // Unknown Postfix service. - e.unsupportedLogEntries.WithLabelValues(logMatches[1]).Inc() + 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: + e.addToUnsupportedLine(line, subprocess, level) + } + case "opendkim": + if opendkimMatches := opendkimSignatureAdded.FindStringSubmatch(remainder); opendkimMatches != nil { + e.opendkimSignatureAdded.WithLabelValues(opendkimMatches[1], opendkimMatches[2]).Inc() } else { - // Unknown log entry format. - e.unsupportedLogEntries.WithLabelValues("").Inc() + e.addToUnsupportedLine(line, process, level) } + default: + // Unknown log entry format. + e.addToUnsupportedLine(line, process, level) } +} - return scanner.Err() +func (e *PostfixExporter) addToUnsupportedLine(line string, subprocess string, level string) { + if e.logUnsupportedLines { + log.Printf("Unsupported Line: %v", line) + } + e.unsupportedLogEntries.WithLabelValues(subprocess, level).Inc() } -// CollectLogfileFromFile Collects entries from a Postfix log file and -// truncates it. Truncation is performed to ensure that the next -// iteration doesn't end up processing the same log entry twice. -func (e *PostfixExporter) CollectLogfileFromFile(path string) error { - fd, err := os.OpenFile(path, os.O_RDWR, 0) +func addToHistogram(h prometheus.Histogram, value, fieldName string) { + float, err := strconv.ParseFloat(value, 64) if err != nil { - return err + log.Printf("Couldn't convert value '%s' for %v: %v", value, fieldName, err) } - defer fd.Close() - err = e.CollectLogfileFromReader(fd) + h.Observe(float) +} +func addToHistogramVec(h *prometheus.HistogramVec, value, fieldName string, labels ...string) { + float, err := strconv.ParseFloat(value, 64) if err != nil { - return err + log.Printf("Couldn't convert value '%s' for %v: %v", value, fieldName, err) } - return fd.Truncate(0) + h.WithLabelValues(labels...).Observe(float) } // NewPostfixExporter creates a new Postfix exporter instance. -func NewPostfixExporter(showqPath string, logfilePath string) (*PostfixExporter, error) { +func NewPostfixExporter(showqPath string, logSrc LogSource, logUnsupportedLines bool) (*PostfixExporter, error) { + timeBuckets := []float64{1e-3, 1e-2, 1e-1, 1.0, 10, 1 * 60, 1 * 60 * 60, 24 * 60 * 60, 2 * 24 * 60 * 60} return &PostfixExporter{ - showqPath: showqPath, - logfilePath: logfilePath, + logUnsupportedLines: logUnsupportedLines, + showqPath: showqPath, + logSrc: logSrc, cleanupProcesses: prometheus.NewCounter(prometheus.CounterOpts{ Namespace: "postfix", @@ -400,12 +472,17 @@ func NewPostfixExporter(showqPath string, logfilePath string) (*PostfixExporter, Name: "cleanup_messages_rejected_total", Help: "Total number of messages rejected by cleanup.", }), + cleanupNotAccepted: prometheus.NewCounter(prometheus.CounterOpts{ + Namespace: "postfix", + Name: "cleanup_messages_not_accepted_total", + Help: "Total number of messages not accepted by cleanup.", + }), lmtpDelays: prometheus.NewHistogramVec( prometheus.HistogramOpts{ Namespace: "postfix", Name: "lmtp_delivery_delay_seconds", Help: "LMTP message processing time in seconds.", - Buckets: []float64{1e-3, 1e-2, 1e-1, 1e0, 1e1, 1e2, 1e3}, + Buckets: timeBuckets, }, []string{"stage"}), pipeDelays: prometheus.NewHistogramVec( @@ -413,7 +490,7 @@ func NewPostfixExporter(showqPath string, logfilePath string) (*PostfixExporter, Namespace: "postfix", Name: "pipe_delivery_delay_seconds", Help: "Pipe message processing time in seconds.", - Buckets: []float64{1e-3, 1e-2, 1e-1, 1e0, 1e1, 1e2, 1e3}, + Buckets: timeBuckets, }, []string{"relay", "stage"}), qmgrInsertsNrcpt: prometheus.NewHistogram(prometheus.HistogramOpts{ @@ -433,12 +510,17 @@ func NewPostfixExporter(showqPath string, logfilePath string) (*PostfixExporter, Name: "qmgr_messages_removed_total", 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( prometheus.HistogramOpts{ Namespace: "postfix", Name: "smtp_delivery_delay_seconds", Help: "SMTP message processing time in seconds.", - Buckets: []float64{1e-3, 1e-2, 1e-1, 1e0, 1e1, 1e2, 1e3}, + Buckets: timeBuckets, }, []string{"stage"}), smtpTLSConnects: prometheus.NewCounterVec( @@ -448,6 +530,23 @@ func NewPostfixExporter(showqPath string, logfilePath string) (*PostfixExporter, Help: "Total number of outgoing TLS connections.", }, []string{"trust", "protocol", "cipher", "secret_bits", "algorithm_bits"}), + smtpDeferreds: prometheus.NewCounter(prometheus.CounterOpts{ + Namespace: "postfix", + Name: "smtp_deferred_messages_total", + 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{ + Namespace: "postfix", + Name: "smtp_connection_timed_out_total", + Help: "Total number of messages that have been deferred on SMTP.", + }), smtpdConnects: prometheus.NewCounter(prometheus.CounterOpts{ Namespace: "postfix", Name: "smtpd_connects_total", @@ -476,7 +575,7 @@ func NewPostfixExporter(showqPath string, logfilePath string) (*PostfixExporter, Name: "smtpd_messages_processed_total", Help: "Total number of messages processed.", }, - []string{"sasl_username"}), + []string{"sasl_method"}), smtpdRejects: prometheus.NewCounterVec( prometheus.CounterOpts{ Namespace: "postfix", @@ -502,7 +601,30 @@ func NewPostfixExporter(showqPath string, logfilePath string) (*PostfixExporter, Name: "unsupported_log_entries_total", Help: "Log entries that could not be processed.", }, - []string{"service"}), + []string{"service", "level"}), + smtpStatusDeferred: prometheus.NewCounter(prometheus.CounterOpts{ + Namespace: "postfix", + Name: "smtp_status_deferred", + Help: "Total number of messages deferred.", + }), + opendkimSignatureAdded: prometheus.NewCounterVec( + prometheus.CounterOpts{ + Namespace: "opendkim", + Name: "signatures_added_total", + Help: "Total number of messages signed.", + }, + []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 } @@ -510,15 +632,22 @@ func NewPostfixExporter(showqPath string, logfilePath string) (*PostfixExporter, func (e *PostfixExporter) Describe(ch chan<- *prometheus.Desc) { ch <- postfixUpDesc + if e.logSrc == nil { + return + } ch <- e.cleanupProcesses.Desc() ch <- e.cleanupRejects.Desc() + ch <- e.cleanupNotAccepted.Desc() e.lmtpDelays.Describe(ch) e.pipeDelays.Describe(ch) ch <- e.qmgrInsertsNrcpt.Desc() ch <- e.qmgrInsertsSize.Desc() ch <- e.qmgrRemoves.Desc() + ch <- e.qmgrExpires.Desc() e.smtpDelays.Describe(ch) e.smtpTLSConnects.Describe(ch) + ch <- e.smtpDeferreds.Desc() + e.smtpProcesses.Describe(ch) ch <- e.smtpdConnects.Desc() ch <- e.smtpdDisconnects.Desc() ch <- e.smtpdFCrDNSErrors.Desc() @@ -527,7 +656,41 @@ func (e *PostfixExporter) Describe(ch chan<- *prometheus.Desc) { e.smtpdRejects.Describe(ch) ch <- e.smtpdSASLAuthenticationFailures.Desc() e.smtpdTLSConnects.Describe(ch) + ch <- e.smtpStatusDeferred.Desc() e.unsupportedLogEntries.Describe(ch) + e.smtpConnectionTimedOut.Describe(ch) + e.opendkimSignatureAdded.Describe(ch) + ch <- e.bounceNonDelivery.Desc() + ch <- e.virtualDelivered.Desc() +} + +func (e *PostfixExporter) StartMetricCollection(ctx context.Context) { + if e.logSrc == nil { + return + } + + gaugeVec := prometheus.NewGaugeVec( + prometheus.GaugeOpts{ + Namespace: "postfix", + Subsystem: "", + Name: "up", + Help: "Whether scraping Postfix's metrics was successful.", + }, + []string{"path"}) + gauge := gaugeVec.WithLabelValues(e.logSrc.Path()) + defer gauge.Set(0) + + for { + line, err := e.logSrc.Read(ctx) + if err != nil { + if err != io.EOF { + log.Printf("Couldn't read journal: %v", err) + } + return + } + e.CollectFromLogLine(line) + gauge.Set(1) + } } // Collect metrics from Postfix's showq socket and its log file. @@ -548,31 +711,22 @@ func (e *PostfixExporter) Collect(ch chan<- prometheus.Metric) { e.showqPath) } - err = e.CollectLogfileFromFile(e.logfilePath) - if err == nil { - ch <- prometheus.MustNewConstMetric( - postfixUpDesc, - prometheus.GaugeValue, - 1.0, - e.logfilePath) - } else { - log.Printf("Failed to scrape logfile: %s", err) - ch <- prometheus.MustNewConstMetric( - postfixUpDesc, - prometheus.GaugeValue, - 0.0, - e.logfilePath) + if e.logSrc == nil { + return } - ch <- e.cleanupProcesses ch <- e.cleanupRejects + ch <- e.cleanupNotAccepted e.lmtpDelays.Collect(ch) e.pipeDelays.Collect(ch) ch <- e.qmgrInsertsNrcpt ch <- e.qmgrInsertsSize ch <- e.qmgrRemoves + ch <- e.qmgrExpires e.smtpDelays.Collect(ch) e.smtpTLSConnects.Collect(ch) + ch <- e.smtpDeferreds + e.smtpProcesses.Collect(ch) ch <- e.smtpdConnects ch <- e.smtpdDisconnects ch <- e.smtpdFCrDNSErrors @@ -581,34 +735,10 @@ func (e *PostfixExporter) Collect(ch chan<- prometheus.Metric) { e.smtpdRejects.Collect(ch) ch <- e.smtpdSASLAuthenticationFailures e.smtpdTLSConnects.Collect(ch) + ch <- e.smtpStatusDeferred e.unsupportedLogEntries.Collect(ch) -} - -func main() { - var ( - listenAddress = flag.String("web.listen-address", ":9154", "Address to listen on for web interface and telemetry.") - metricsPath = flag.String("web.telemetry-path", "/metrics", "Path under which to expose metrics.") - postfixShowqPath = flag.String("postfix.showq_path", "/var/spool/postfix/public/showq", "Path at which Postfix places its showq socket.") - postfixLogfilePath = flag.String("postfix.logfile_path", "/var/log/postfix_exporter_input.log", "Path where Postfix writes log entries. This file will be truncated by this exporter.") - ) - flag.Parse() - - exporter, err := NewPostfixExporter(*postfixShowqPath, *postfixLogfilePath) - if err != nil { - panic(err) - } - prometheus.MustRegister(exporter) - - http.Handle(*metricsPath, prometheus.Handler()) - http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) { - w.Write([]byte(` - - Postfix Exporter - -

Postfix Exporter

-

Metrics

- - `)) - }) - log.Fatal(http.ListenAndServe(*listenAddress, nil)) + ch <- e.smtpConnectionTimedOut + e.opendkimSignatureAdded.Collect(ch) + ch <- e.bounceNonDelivery + ch <- e.virtualDelivered } diff --git a/postfix_exporter_test.go b/postfix_exporter_test.go new file mode 100644 index 0000000..8f057a8 --- /dev/null +++ b/postfix_exporter_test.go @@ -0,0 +1,348 @@ +package main + +import ( + "testing" + + "github.com/prometheus/client_golang/prometheus" + io_prometheus_client "github.com/prometheus/client_model/go" + "github.com/stretchr/testify/assert" +) + +func TestPostfixExporter_CollectFromLogline(t *testing.T) { + type fields struct { + showqPath string + logSrc LogSource + cleanupProcesses prometheus.Counter + cleanupRejects prometheus.Counter + cleanupNotAccepted prometheus.Counter + lmtpDelays *prometheus.HistogramVec + pipeDelays *prometheus.HistogramVec + qmgrInsertsNrcpt prometheus.Histogram + qmgrInsertsSize prometheus.Histogram + qmgrRemoves prometheus.Counter + qmgrExpires prometheus.Counter + smtpDelays *prometheus.HistogramVec + smtpTLSConnects *prometheus.CounterVec + smtpDeferreds prometheus.Counter + smtpStatusDeferred prometheus.Counter + smtpProcesses *prometheus.CounterVec + smtpdConnects prometheus.Counter + smtpdDisconnects prometheus.Counter + smtpdFCrDNSErrors prometheus.Counter + smtpdLostConnections *prometheus.CounterVec + smtpdProcesses *prometheus.CounterVec + smtpdRejects *prometheus.CounterVec + smtpdSASLAuthenticationFailures prometheus.Counter + smtpdTLSConnects *prometheus.CounterVec + bounceNonDelivery prometheus.Counter + virtualDelivered prometheus.Counter + unsupportedLogEntries *prometheus.CounterVec + } + type args struct { + line []string + removedCount int + expiredCount int + saslFailedCount int + outgoingTLS int + smtpdMessagesProcessed int + smtpMessagesProcessed int + bounceNonDelivery int + virtualDelivered int + unsupportedLogEntries []string + } + tests := []struct { + name string + fields fields + args args + }{ + { + name: "Single line", + args: args{ + line: []string{ + "Feb 11 16:49:24 letterman postfix/qmgr[8204]: AAB4D259B1: removed", + }, + removedCount: 1, + saslFailedCount: 0, + }, + fields: fields{ + qmgrRemoves: prometheus.NewCounter(prometheus.CounterOpts{}), + unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"service", "level"}), + }, + }, + { + name: "Multiple lines", + args: args{ + line: []string{ + "Feb 11 16:49:24 letterman postfix/qmgr[8204]: AAB4D259B1: removed", + "Feb 11 16:49:24 letterman postfix/qmgr[8204]: C2032259E6: removed", + "Feb 11 16:49:24 letterman postfix/qmgr[8204]: B83C4257DC: removed", + "Feb 11 16:49:24 letterman postfix/qmgr[8204]: 721BE256EA: removed", + "Feb 11 16:49:25 letterman postfix/qmgr[8204]: CA94A259EB: removed", + "Feb 11 16:49:25 letterman postfix/qmgr[8204]: AC1E3259E1: removed", + "Feb 11 16:49:25 letterman postfix/qmgr[8204]: D114D221E3: removed", + "Feb 11 16:49:25 letterman postfix/qmgr[8204]: A55F82104D: removed", + "Feb 11 16:49:25 letterman postfix/qmgr[8204]: D6DAA259BC: removed", + "Feb 11 16:49:25 letterman postfix/qmgr[8204]: E3908259F0: removed", + "Feb 11 16:49:25 letterman postfix/qmgr[8204]: 0CBB8259BF: removed", + "Feb 11 16:49:25 letterman postfix/qmgr[8204]: EA3AD259F2: removed", + "Feb 11 16:49:25 letterman postfix/qmgr[8204]: DDEF824B48: removed", + "Feb 11 16:49:26 letterman postfix/qmgr[8204]: 289AF21DB9: removed", + "Feb 11 16:49:26 letterman postfix/qmgr[8204]: 6192B260E8: removed", + "Feb 11 16:49:26 letterman postfix/qmgr[8204]: F2831259F4: removed", + "Feb 11 16:49:26 letterman postfix/qmgr[8204]: 09D60259F8: removed", + "Feb 11 16:49:26 letterman postfix/qmgr[8204]: 13A19259FA: removed", + "Feb 11 16:49:26 letterman postfix/qmgr[8204]: 2D42722065: removed", + "Feb 11 16:49:26 letterman postfix/qmgr[8204]: 746E325A0E: removed", + "Feb 11 16:49:26 letterman postfix/qmgr[8204]: 4D2F125A02: removed", + "Feb 11 16:49:26 letterman postfix/qmgr[8204]: E30BC259EF: removed", + "Feb 11 16:49:26 letterman postfix/qmgr[8204]: DC88924DA1: removed", + "Feb 11 16:49:26 letterman postfix/qmgr[8204]: 2164B259FD: removed", + "Feb 11 16:49:26 letterman postfix/qmgr[8204]: 8C30525A14: removed", + "Feb 11 16:49:26 letterman postfix/qmgr[8204]: 8DCCE25A15: removed", + "Feb 11 16:49:26 letterman postfix/qmgr[8204]: C5217255D5: removed", + "Feb 11 16:49:27 letterman postfix/qmgr[8204]: D8EE625A28: removed", + "Feb 11 16:49:27 letterman postfix/qmgr[8204]: 9AD7C25A19: removed", + "Feb 11 16:49:27 letterman postfix/qmgr[8204]: D0EEE2596C: removed", + "Feb 11 16:49:27 letterman postfix/qmgr[8204]: DFE732172E: removed", + }, + removedCount: 31, + saslFailedCount: 0, + }, + fields: fields{ + qmgrRemoves: prometheus.NewCounter(prometheus.CounterOpts{}), + 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=, status=expired, returned to sender", + "Apr 10 14:50:16 mail postfix/qmgr[3663]: BACE842E73: from=, status=force-expired, returned to sender", + }, + expiredCount: 2, + }, + fields: fields{ + qmgrExpires: prometheus.NewCounter(prometheus.CounterOpts{}), + }, + }, + { + name: "SASL Failed", + args: args{ + line: []string{ + "Apr 26 10:55:19 tcc1 postfix/smtpd[21126]: warning: SASL authentication failure: cannot connect to saslauthd server: Permission denied", + "Apr 26 10:55:19 tcc1 postfix/smtpd[21126]: warning: SASL authentication failure: Password verification failed", + "Apr 26 10:55:19 tcc1 postfix/smtpd[21126]: warning: laptop.local[192.168.1.2]: SASL PLAIN authentication failed: generic failure", + }, + saslFailedCount: 1, + removedCount: 0, + }, + fields: fields{ + smtpdSASLAuthenticationFailures: prometheus.NewCounter(prometheus.CounterOpts{}), + unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"service", "level"}), + smtpProcesses: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"status"}), + }, + }, + { + name: "SASL login", + 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: 2, + }, + fields: fields{ + unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"service", "level"}), + smtpdProcesses: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"sasl_method"}), + }, + }, + { + name: "Issue #35", + args: args{ + line: []string{ + "Jul 24 04:38:17 mail postfix/smtp[30582]: Verified TLS connection established to gmail-smtp-in.l.google.com[108.177.14.26]:25: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits) server-digest SHA256", + "Jul 24 03:28:15 mail postfix/smtp[24052]: Verified TLS connection established to mx2.comcast.net[2001:558:fe21:2a::6]:25: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)", + }, + removedCount: 0, + saslFailedCount: 0, + outgoingTLS: 2, + smtpdMessagesProcessed: 0, + }, + fields: fields{ + unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"service", "level"}), + smtpTLSConnects: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"Verified", "TLSv1.2", "ECDHE-RSA-AES256-GCM-SHA384", "256", "256"}), + smtpProcesses: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"status"}), + }, + }, + { + 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, + smtpMessagesProcessed: 1, + }, + fields: fields{ + 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=, 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=, 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=, 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: label: counter: `, + `label: label: counter: `, + `label: label: counter: `, + }, + }, + fields: fields{ + unsupportedLogEntries: prometheus.NewCounterVec(prometheus.CounterOpts{}, []string{"service", "level"}), + }, + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + e := &PostfixExporter{ + showqPath: tt.fields.showqPath, + logSrc: tt.fields.logSrc, + cleanupProcesses: tt.fields.cleanupProcesses, + cleanupRejects: tt.fields.cleanupRejects, + cleanupNotAccepted: tt.fields.cleanupNotAccepted, + lmtpDelays: tt.fields.lmtpDelays, + pipeDelays: tt.fields.pipeDelays, + qmgrInsertsNrcpt: tt.fields.qmgrInsertsNrcpt, + qmgrInsertsSize: tt.fields.qmgrInsertsSize, + qmgrRemoves: tt.fields.qmgrRemoves, + qmgrExpires: tt.fields.qmgrExpires, + smtpDelays: tt.fields.smtpDelays, + smtpTLSConnects: tt.fields.smtpTLSConnects, + smtpDeferreds: tt.fields.smtpDeferreds, + smtpStatusDeferred: tt.fields.smtpStatusDeferred, + smtpProcesses: tt.fields.smtpProcesses, + smtpdConnects: tt.fields.smtpdConnects, + smtpdDisconnects: tt.fields.smtpdDisconnects, + smtpdFCrDNSErrors: tt.fields.smtpdFCrDNSErrors, + smtpdLostConnections: tt.fields.smtpdLostConnections, + smtpdProcesses: tt.fields.smtpdProcesses, + smtpdRejects: tt.fields.smtpdRejects, + smtpdSASLAuthenticationFailures: tt.fields.smtpdSASLAuthenticationFailures, + smtpdTLSConnects: tt.fields.smtpdTLSConnects, + bounceNonDelivery: tt.fields.bounceNonDelivery, + virtualDelivered: tt.fields.virtualDelivered, + unsupportedLogEntries: tt.fields.unsupportedLogEntries, + logUnsupportedLines: true, + } + for _, line := range tt.args.line { + e.CollectFromLogLine(line) + } + 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.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.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") + }) + } +} +func assertCounterEquals(t *testing.T, counter prometheus.Collector, expected int, message string) { + + if counter != nil && expected > 0 { + switch counter.(type) { + case *prometheus.CounterVec: + counter := counter.(*prometheus.CounterVec) + metricsChan := make(chan prometheus.Metric) + go func() { + counter.Collect(metricsChan) + close(metricsChan) + }() + var count int = 0 + for metric := range metricsChan { + metricDto := io_prometheus_client.Metric{} + metric.Write(&metricDto) + count += int(*metricDto.Counter.Value) + } + assert.Equal(t, expected, count, message) + case prometheus.Counter: + metricsChan := make(chan prometheus.Metric) + go func() { + counter.Collect(metricsChan) + close(metricsChan) + }() + var count int = 0 + for metric := range metricsChan { + metricDto := io_prometheus_client.Metric{} + metric.Write(&metricDto) + count += int(*metricDto.Counter.Value) + } + assert.Equal(t, expected, count, message) + default: + t.Fatal("Type not implemented") + } + } +} +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) + } +} 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