Blackbox smtp_starttls and imap_starttls don't get metrics

Petar Kozic

unread,

Oct 19, 2020, 9:48:45 AM10/19/20

to Prometheus Users

Hi,

I tried to setup blackbox monitoring for one my mail server but everything waht I tried in prometheus I get only:

probe_success 0

In blackbox config I have:

imap_starttls:

prober: tcp

timeout: 5s

tcp:

query_response:

- expect: "OK.*STARTTLS"

- send: ". STARTTLS"

- expect: "OK"

- send: "QUIT"

smtp_starttls:

prober: tcp

timeout: 5s

tcp:

query_response:

- expect: "^220 ([^ ]+) ESMTP (.+)$"

- send: "EHLO prober"

- expect: "^250-STARTTLS"

- send: "STARTTLS"

- expect: "^220"

- send: "QUIT"

If I run this command from command line from telnet where is blackbox started I get valid response. That mean mail server answer valid.

What can be problem, some idea?

Brian Candler

unread,

Oct 20, 2020, 2:31:25 AM10/20/20

to Prometheus Users

You need to add a query_response step "- starttls: true" between sending the STARTTLS command and getting back the OK (which at that point will be encrypted).

See: https://github.com/prometheus/blackbox_exporter/blob/master/CONFIGURATION.md#tcp_probe

Brian Candler

unread,

Oct 20, 2020, 5:44:43 AM10/20/20

to Prometheus Users

The other thing you can do is to run blackbox_exporter with flag --log.level=debug, and then you'll see in detail what's going on in its stderr output. Either run it in the foreground, or look at "journalctl -eu blackbox_exporter" if running it under systemd.

Here is an example of a probe which fails:

# curl 'localhost:9115/probe?target=smtp.google.com:25&module=smtp_starttls'

# HELP probe_dns_lookup_time_seconds Returns the time taken for probe dns lookup in seconds

# TYPE probe_dns_lookup_time_seconds gauge

probe_dns_lookup_time_seconds 0.002062806

# HELP probe_duration_seconds Returns how long the probe took to complete in seconds

# TYPE probe_duration_seconds gauge

probe_duration_seconds 0.07643425

# HELP probe_failed_due_to_regex Indicates if probe failed due to regex

# TYPE probe_failed_due_to_regex gauge

probe_failed_due_to_regex 0

# HELP probe_ip_addr_hash Specifies the hash of IP address. It's useful to detect if the IP address changes.

# TYPE probe_ip_addr_hash gauge

probe_ip_addr_hash 4.223917065e+09

# HELP probe_ip_protocol Specifies whether probe ip protocol is IP4 or IP6

# TYPE probe_ip_protocol gauge

probe_ip_protocol 6

# HELP probe_success Displays whether or not the probe was a success

# TYPE probe_success gauge

probe_success 0

And here are the corresponding logs:

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.663Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Beginning probe" probe=tcp timeout_seconds=5

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.663Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Resolving target address" ip_protocol=ip6

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.692Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Resolved target address" ip=2a00:1450:400c:c0b::1a

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.692Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Dialing TCP without TLS"

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.705Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Successfully dialed"

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.705Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Processing query response entry" entry_number=0

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.719Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Read line" line="220 mx.google.com ESMTP z7si1287659wro.321 - gsmtp"

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.719Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Regexp matched" regexp="^220 ([^ ]+) ESMTP (.+)$" line="220 mx.google.com ESMTP z7si1287659wro.321 - gsmtp"

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.719Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Processing query response entry" entry_number=1

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.719Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Sending line" line="EHLO prober"

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.721Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Processing query response entry" entry_number=2

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.735Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Read line" line="250-mx.google.com at your service, [2a01:5d00:1000:8ff::33]"

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.735Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Read line" line="250-SIZE 157286400"

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.735Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Read line" line=250-8BITMIME

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.735Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Read line" line=250-STARTTLS

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.735Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Regexp matched" regexp=^250-STARTTLS line=250-STARTTLS

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.735Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Processing query response entry" entry_number=3

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.735Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.735Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Read line" line=250-PIPELINING

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.735Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Read line" line=250-CHUNKING

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.735Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Read line" line="250 SMTPUTF8"

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.735Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Regexp matched" regexp="^250 " line="250 SMTPUTF8"

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.735Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Processing query response entry" entry_number=4

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.735Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Sending line" line=STARTTLS

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.736Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Processing query response entry" entry_number=5

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.748Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Read line" line="220 2.0.0 Ready to start TLS"

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.748Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Regexp matched" regexp="^220 " line="220 2.0.0 Ready to start TLS"

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.748Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Processing query response entry" entry_number=6

Oct 20 09:39:39 prometheus blackbox_exporter[16273]: ts=2020-10-20T09:39:39.779Z caller=main.go:169 module=smtp_starttls target=smtp.google.com:25 level=debug msg="Probe failed" duration_seconds=0.115539274

You can see clearly what the problem is here: smtp.google.com's certificate doesn't include "smtp.google.com" as one of its names. You can fix this by probing aspmx.l.google.com instead (but then there's a different issue, the server doesn't appear to send 250-AUTH). smtp.gmail.com (which is a different service) doesn't have this problem: probe_success is 1.

Here is the blackbox_exporter config I was using:

smtp_starttls:

prober: tcp

timeout: 5s

tcp:

query_response:

- expect: "^220 ([^ ]+) ESMTP (.+)$"

- send: "EHLO prober"

- expect: "^250-STARTTLS"

- expect: "^250 "

- send: "STARTTLS"

- expect: "^220 "

- starttls: true

- send: "EHLO prober"

- expect: "^250-AUTH"

- send: "QUIT"

Brian Candler

unread,

Oct 20, 2020, 5:53:58 AM10/20/20

to Prometheus Users

Oh, there's a much way to get the debug output, which is to add &debug=true to the URL.

curl 'localhost:9115/probe?target=smtp.google.com:25&module=smtp_starttls&debug=true'

Petar Kozic

unread,

Oct 20, 2020, 9:20:21 AM10/20/20

to Prometheus Users

Thank you for all yours help.

With debug command:

curl 'localhost:9115/probe?target=smtp.google.com:25&module=smtp_starttls&debug=true'

I found problem.

Problem was because in prometheus.yml I was set only hostname without port number.

caller=tcp.go:37 module=smtp_starttls target=my_mail_server level=error msg="Error splitting target address and port" err="address my_mail_server: missing port in address"