Problem 1: timeout / regexp mismatch > ts=2022-07-05T02:29:41.609572861Z caller=main.go:130 module=smtp_starttls target=1.1.1.1:25 level=debug msg="Read line" line="220 mail.com ESMTP" > ts=2022-07-05T02:29:46.607798497Z caller=main.go:130 module=smtp_starttls target=11.1.1.1:25 level=error msg="Error reading from connection" err="read tcp4 0.0.0.0:57074->1.1.1.1:25: i/o timeout"
You asked it to match "^220 ([^ ]+) ESMTP (.+)$" which means: - "220" - <space> - 1 or more <non-space> - <space> - "ESMTP" - <space> - 1 or more <any-character> - end of line But in the banner you got back from the target host, there's nothing after the word "ESMTP": the line ends there immediately. Hence you were right to change the regexp. "I'm not sure if the change is acceptable from blackbox's view" - Blackbox will do whatever you ask it to do. If you want to match both cases (i.e. mail servers which do and don't put any text after "ESMTP"), then use a regexp which does that: "^220 ([^ ]+) ESMTP( .+)?$" or "^220 ([^ ]+) ESMTP.*$" or even just "^220 ([^ ]+) ESMTP" (no need to match all the way to the end of the line) Problem 2: TLS handshake failed * You asked Blackbox Exporter to connect to a host by IP address (1.1.1.1), instead of using a DNS name (smtp.example.com) * Therefore, Blackbox Exporter cannot verify the certificate unless the certificate itself contains an IP address It's the same as if you put https://1.1.1.1/ in your web browser. There's no way the browser can validate the certificate, unless the certificate itself contains IP address "1.1.1.1". And that is a very uncommon sort of certificate. Please, try *exactly* the command I gave you before: *curl -g 'localhost:9115/probe?module=smtp_starttls&target=aspmx.l.google.com:25&debug=true'* No changes. Copy-paste exactly that, with the hostname "aspmx.l.google.com" in it. You should find that it verifies correctly, as long as the ESMTP regexp matches OK. Then to get it to work with your own mail server, you will need to do exactly the same: * Refer to your mail server by its DNS name, not IP address, when asking blackbox_exporter to test it * The mail server must have a certificate which contains this name [^1] * The mail server's certificate must be signed by a certificate authority that blackbox_exporter trusts [^2] * The mail server's certificate must not have expired, i.e. the current time is within its notBefore and notAfter times [^1] If you still want to connect to the server by IP address but check for a different name in the certificate, then use the "server_name" setting in tls_config: see https://prometheus.io/docs/prometheus/latest/configuration/configuration/#tls_config [^2] If the certificate authority that signed your mail server's certificate is not in the system trust store then use the "ca_file" setting in tls_config: see https://github.com/prometheus/blackbox_exporter/blob/v0.21.1/example.yml#L53-L54 Or you can give up, and use "insecure_skip_verify: true" to disable certificate validation altogether: https://github.com/prometheus/blackbox_exporter/blob/v0.21.1/example.yml#L27-L28 (although then you lose valuable tests, because if your certificate was valid and becomes invalid you won't know. I also note that if you can't get blackbox_exporter to validate the certificate, then your clients probably won't be able to validate it either) At this point, it isn't really an issue with blackbox_exporter any more: it's a case of understanding how certificates and certificate validation work. On Tuesday, 5 July 2022 at 05:53:46 UTC+1 [email protected] wrote: > I tried to change the first expect to ^220 ([^ ]+) ESMTP$. But I'm not > sure if the change is acceptable from blackbox's view. > > smtp_starttls: > prober: tcp > timeout: 20s > tcp: > query_response: > #- expect: "^220 ([^ ]+) ESMTP (.+)$" > - expect: "^220 ([^ ]+) ESMTP$" > > send: "EHLO prober\r" > - expect: "^250-STARTTLS" > - expect: "^250 .*$" > send: "STARTTLS\r" > - expect: "^220" > starttls: true > - send: "EHLO prober\r" > - expect: "^250 .*$" > send: "QUIT\r" > > > Curled and got the following error. Does it mean the mail server doesn't > contain any IP SANs? And on mail server certificate cannot be validated? > ts=2022-07-05T04:18:10.539326118Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=error msg="TLS Handshake (client) failed" > err="x509: cannot validate certificate for 1.1.1.1 because it doesn't > contain any IP SANs" > > curl -g ' > http://0.0.0.0:9115/probe?module=smtp_starttls&target=1.1.1.1:25&debug=true > ' > Logs for the probe: > ts=2022-07-05T04:18:10.527958378Z caller=main.go:320 module=smtp_starttls > target=1.1.1.1:25 level=info msg="Beginning probe" probe=tcp > timeout_seconds=20 > ts=2022-07-05T04:18:10.528040568Z caller=tcp.go:40 module=smtp_starttls > target=1.1.1.1:25 level=info msg="Resolving target address" > ip_protocol=ip6 > ts=2022-07-05T04:18:10.528063021Z caller=tcp.go:40 module=smtp_starttls > target=1.1.1.1:25 level=info msg="Resolving target address" > ip_protocol=ip4 > ts=2022-07-05T04:18:10.528076698Z caller=tcp.go:40 module=smtp_starttls > target=1.1.1.1:25 level=info msg="Resolved target address" ip=1.1.1.1 > ts=2022-07-05T04:18:10.528115109Z caller=tcp.go:121 module=smtp_starttls > target=1.1.1.1:25 level=info msg="Dialing TCP without TLS" > ts=2022-07-05T04:18:10.529223463Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=info msg="Successfully dialed" > ts=2022-07-05T04:18:10.529258037Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=info msg="Processing query response entry" > entry_number=0 > ts=2022-07-05T04:18:10.530236839Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=debug msg="Read line" line="220 mail.com ESMTP" > ts=2022-07-05T04:18:10.530278493Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=info msg="Regexp matched" regexp="^220 ([^ ]+) > ESMTP$" line="220 mail.com ESMTP" > ts=2022-07-05T04:18:10.53030557Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r" > ts=2022-07-05T04:18:10.530348868Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=info msg="Processing query response entry" > entry_number=1 > ts=2022-07-05T04:18:10.530919204Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=debug msg="Read line" line=250-mail.com > ts=2022-07-05T04:18:10.530955761Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING > ts=2022-07-05T04:18:10.530971243Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000" > ts=2022-07-05T04:18:10.530985701Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN > ts=2022-07-05T04:18:10.531006196Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=debug msg="Read line" line=250-STARTTLS > ts=2022-07-05T04:18:10.531025088Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=info msg="Regexp matched" regexp=^250-STARTTLS > line=250-STARTTLS > ts=2022-07-05T04:18:10.531045174Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=info msg="Processing query response entry" > entry_number=2 > ts=2022-07-05T04:18:10.531064549Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN" > ts=2022-07-05T04:18:10.531077325Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES > ts=2022-07-05T04:18:10.531088466Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME > ts=2022-07-05T04:18:10.53110099Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN" > ts=2022-07-05T04:18:10.531134286Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=info msg="Regexp matched" regexp="^250 .*$" > line="250 DSN" > ts=2022-07-05T04:18:10.531186418Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=debug msg="Sending line" line="STARTTLS\r" > ts=2022-07-05T04:18:10.531234743Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=info msg="Processing query response entry" > entry_number=3 > ts=2022-07-05T04:18:10.531762621Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=debug msg="Read line" line="220 2.0.0 Ready to > start TLS" > ts=2022-07-05T04:18:10.531779841Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=info msg="Regexp matched" regexp=^220 line="220 > 2.0.0 Ready to start TLS" > ts=2022-07-05T04:18:10.539326118Z caller=main.go:130 module=smtp_starttls > target=1.1.1.1:25 level=error msg="TLS Handshake (client) failed" > err="x509: cannot validate certificate for 1.1.1.1 because it doesn't > contain any IP SANs" > ts=2022-07-05T04:18:10.53937693Z caller=main.go:320 module=smtp_starttls > target=1.1.1.1:25 level=error msg="Probe failed" > duration_seconds=0.011375261 > > On Tuesday, July 5, 2022 at 12:03:50 PM UTC+8 nina guo wrote: > >> I may find the root cause - comparing the output between google's mail >> server and my mail server >> >> my mail server >> ts=2022-07-05T02:29:41.608566903Z caller=main.go:130 module=smtp_starttls >> target=1.1.1.1:25 level=info msg="Successfully dialed" >> ts=2022-07-05T02:29:41.608652361Z caller=main.go:130 module=smtp_starttls >> target=1.1.1.1:25 level=info msg="Processing query response entry" >> entry_number=0 >> ts=2022-07-05T02:29:41.609572861Z caller=main.go:130 module=smtp_starttls >> target=1.1.1.1:25 level=debug msg="Read line" line="220 mail.com ESMTP" >> ts=2022-07-05T02:29:46.607798497Z caller=main.go:130 module=smtp_starttls >> target=11.1.1.1:25 level=error msg="Error reading from connection" >> err="read tcp4 0.0.0.0:57074->1.1.1.1:25: i/o timeout" >> >> google's mail server >> ts=2022-07-05T02:04:33.385587664Z caller=main.go:130 module=smtp_starttls >> target=142.250.102.27:25 level=info msg="Successfully dialed" >> ts=2022-07-05T02:04:33.385613189Z caller=main.go:130 module=smtp_starttls >> target=142.250.102.27:25 level=info msg="Processing query response >> entry" entry_number=0 >> ts=2022-07-05T02:04:33.419235886Z caller=main.go:130 module=smtp_starttls >> target=142.250.102.27:25 level=debug msg="Read line" line="220 >> mx.google.com ESMTP >> dn22-20020a17090794d600b006dfc3945326si6666807ejc.152 - gsmtp" >> ts=2022-07-05T02:04:33.419280493Z caller=main.go:130 module=smtp_starttls >> target=142.250.102.27:25 level=info msg="Regexp matched" regexp="^220 >> ([^ ]+) ESMTP (.+)$" line="220 mx.google.com ESMTP >> dn22-20020a17090794d600b006dfc3945326si6666807ejc.152 - gsmtp" >> >> From the output it shows the regex is not matched for my mail server - >> ^220 ([^ ]+) ESMTP (.+)$ >> >> In config file >> smtp_starttls: >> prober: tcp >> timeout: 20s >> >> tcp: >> query_response: >> - expect: "^220 ([^ ]+) ESMTP (.+)$" >> send: "EHLO prober\r" >> - expect: "^250-STARTTLS" >> - expect: "^250 .*$" >> send: "STARTTLS\r" >> >> - expect: "^220" >> starttls: true >> - send: "EHLO prober\r" >> - expect: "^250 .*$" >> send: "QUIT\r" >> On Tuesday, July 5, 2022 at 11:40:06 AM UTC+8 nina guo wrote: >> >>> I searched this info blackbox_exporter for SMTP monitoring w/ TCP >>> module : PrometheusMonitoring (reddit.com) >>> <https://www.reddit.com/r/PrometheusMonitoring/comments/q60357/blackbox_exporter_for_smtp_monitoring_w_tcp_module/> >>> , >>> added "\r", but still got the same issue.. >>> >>> On Tuesday, July 5, 2022 at 11:26:49 AM UTC+8 nina guo wrote: >>> >>>> telnet got succeed. >>>> >>>> telnet 1.1.1.1 25 >>>> Trying 1.1.1.1... >>>> Connected to 1.1.1.1. >>>> Escape character is '^]'. >>>> 220 ... ESMTP >>> >>> >>>> >>>> On Tuesday, July 5, 2022 at 11:11:48 AM UTC+8 nina guo wrote: >>>> >>>>> Probe failed due to TLS issue...it is not the same issue with my mail >>>>> server.. >>>>> There is no "i/o timeout" issue for google's mail server. >>>>> >>>>> curl -g ' >>>>> http://0.0.0.0:9115/probe?module=smtp_starttls&target=142.250.102.27:25&debug=true >>>>> >>>>> <http://100.100.3.9:9115/probe?module=smtp_starttls&target=142.250.102.27:25&debug=true> >>>>> ' >>>>> Logs for the probe: >>>>> ts=2022-07-05T02:04:33.373763474Z caller=main.go:320 >>>>> module=smtp_starttls target=142.250.102.27:25 level=info >>>>> msg="Beginning probe" probe=tcp timeout_seconds=5 >>>>> ts=2022-07-05T02:04:33.373850167Z caller=tcp.go:40 >>>>> module=smtp_starttls target=142.250.102.27:25 level=info >>>>> msg="Resolving target address" ip_protocol=ip6 >>>>> ts=2022-07-05T02:04:33.373867876Z caller=tcp.go:40 >>>>> module=smtp_starttls target=142.250.102.27:25 level=info >>>>> msg="Resolving target address" ip_protocol=ip4 >>>>> ts=2022-07-05T02:04:33.373882263Z caller=tcp.go:40 >>>>> module=smtp_starttls target=142.250.102.27:25 level=info >>>>> msg="Resolved target address" ip=142.250.102.27 >>>>> ts=2022-07-05T02:04:33.373903614Z caller=tcp.go:121 >>>>> module=smtp_starttls target=142.250.102.27:25 level=info msg="Dialing >>>>> TCP without TLS" >>>>> ts=2022-07-05T02:04:33.385587664Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=info >>>>> msg="Successfully dialed" >>>>> ts=2022-07-05T02:04:33.385613189Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=info >>>>> msg="Processing query response entry" entry_number=0 >>>>> ts=2022-07-05T02:04:33.419235886Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=debug msg="Read >>>>> line" line="220 mx.google.com ESMTP >>>>> dn22-20020a17090794d600b006dfc3945326si6666807ejc.152 - gsmtp" >>>>> ts=2022-07-05T02:04:33.419280493Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=info msg="Regexp >>>>> matched" regexp="^220 ([^ ]+) ESMTP (.+)$" line="220 mx.google.com ESMTP >>>>> dn22-20020a17090794d600b006dfc3945326si6666807ejc.152 - gsmtp" >>>>> ts=2022-07-05T02:04:33.419310506Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=debug >>>>> msg="Sending line" line="EHLO prober" >>>>> ts=2022-07-05T02:04:33.419356415Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=info >>>>> msg="Processing query response entry" entry_number=1 >>>>> ts=2022-07-05T02:04:33.43519464Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=debug msg="Read >>>>> line" line="250-mx.google.com at your service, [130.214.226.41]" >>>>> ts=2022-07-05T02:04:33.435229899Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=debug msg="Read >>>>> line" line="250-SIZE 157286400" >>>>> ts=2022-07-05T02:04:33.435242182Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=debug msg="Read >>>>> line" line=250-8BITMIME >>>>> ts=2022-07-05T02:04:33.435254457Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=debug msg="Read >>>>> line" line=250-STARTTLS >>>>> ts=2022-07-05T02:04:33.435270364Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=info msg="Regexp >>>>> matched" regexp=^250-STARTTLS line=250-STARTTLS >>>>> ts=2022-07-05T02:04:33.435285968Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=info >>>>> msg="Processing query response entry" entry_number=2 >>>>> ts=2022-07-05T02:04:33.435310813Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=debug msg="Read >>>>> line" line=250-ENHANCEDSTATUSCODES >>>>> ts=2022-07-05T02:04:33.435323258Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=debug msg="Read >>>>> line" line=250-PIPELINING >>>>> ts=2022-07-05T02:04:33.435337373Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=debug msg="Read >>>>> line" line=250-CHUNKING >>>>> ts=2022-07-05T02:04:33.435373931Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=debug msg="Read >>>>> line" line="250 SMTPUTF8" >>>>> ts=2022-07-05T02:04:33.435392537Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=info msg="Regexp >>>>> matched" regexp="^250 .*$" line="250 SMTPUTF8" >>>>> ts=2022-07-05T02:04:33.435409638Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=debug >>>>> msg="Sending line" line=STARTTLS >>>>> ts=2022-07-05T02:04:33.435451742Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=info >>>>> msg="Processing query response entry" entry_number=3 >>>>> ts=2022-07-05T02:04:33.449015201Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=debug msg="Read >>>>> line" line="220 2.0.0 Ready to start TLS" >>>>> ts=2022-07-05T02:04:33.449039996Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=info msg="Regexp >>>>> matched" regexp=^220 line="220 2.0.0 Ready to start TLS" >>>>> ts=2022-07-05T02:04:33.476697731Z caller=main.go:130 >>>>> module=smtp_starttls target=142.250.102.27:25 level=error msg="TLS >>>>> Handshake (client) failed" err="x509: cannot validate certificate for >>>>> 142.250.102.27 because it doesn't contain any IP SANs" >>>>> ts=2022-07-05T02:04:33.47676603Z caller=main.go:320 >>>>> module=smtp_starttls target=142.250.102.27:25 level=error msg="Probe >>>>> failed" duration_seconds=0.102953678 >>>>> >>>>> >>>>> >>>>> >>>>> Metrics that would have been returned: >>>>> # 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 5.1452e-05 >>>>> >>>>> # HELP probe_duration_seconds Returns how long the probe took to >>>>> complete in seconds >>>>> # TYPE probe_duration_seconds gauge >>>>> probe_duration_seconds 0.102953678 >>>>> >>>>> # 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 9.60720384e+08 >>>>> # HELP probe_ip_protocol Specifies whether probe ip protocol is IP4 or >>>>> IP6 >>>>> # TYPE probe_ip_protocol gauge >>>>> probe_ip_protocol 4 >>>>> # HELP probe_success Displays whether or not the probe was a success >>>>> # TYPE probe_success gauge >>>>> probe_success 0 >>>>> >>>>> Module configuration: >>>>> prober: tcp >>>>> timeout: 5s >>>>> http: >>>>> ip_protocol_fallback: true >>>>> follow_redirects: true >>>>> tcp: >>>>> ip_protocol_fallback: true >>>>> query_response: >>>>> - expect: ^220 ([^ ]+) ESMTP (.+)$ >>>>> send: EHLO prober >>>>> - expect: ^250-STARTTLS >>>>> - expect: ^250 .*$ >>>>> send: STARTTLS >>>>> - expect: ^220 >>>>> starttls: true >>>>> - send: EHLO prober >>>>> - expect: ^250 .*$ >>>>> send: QUIT >>>>> icmp: >>>>> ip_protocol_fallback: true >>>>> dns: >>>>> ip_protocol_fallback: true >>>>> >>>>> >>>>> On Monday, July 4, 2022 at 8:44:49 PM UTC+8 Brian Candler wrote: >>>>> >>>>>> And if you try it with Google's mail server? >>>>>> *curl -g >>>>>> 'localhost:9115/probe?module=smtp_starttls&target=aspmx.l.google.com:25&debug=true'* >>>>>> >>>>>> On Monday, 4 July 2022 at 12:50:47 UTC+1 [email protected] wrote: >>>>>> >>>>>>> Still received the same error msg: >>>>>>> >>>>>>> curl -g ' >>>>>>> http://0.0.0.0:9115/probe?module=smtp_starttls&target=1.1.1.1:25&debug=true >>>>>>> ' >>>>>>> Logs for the probe: >>>>>>> ts=2022-07-04T11:47:59.071097704Z caller=main.go:320 >>>>>>> module=smtp_starttls target= 1.1.1.1 :25 level=info msg="Beginning >>>>>>> probe" >>>>>>> probe=tcp timeout_seconds=5 >>>>>>> ts=2022-07-04T11:47:59.071251831Z caller=tcp.go:40 >>>>>>> module=smtp_starttls target=1 1.1.1.1 :25 level=info msg="Resolving >>>>>>> target >>>>>>> address" ip_protocol=ip6 >>>>>>> ts=2022-07-04T11:47:59.071292289Z caller=tcp.go:40 >>>>>>> module=smtp_starttls target= 1.1.1.1 :25 level=info msg="Resolving >>>>>>> target >>>>>>> address" ip_protocol=ip4 >>>>>>> ts=2022-07-04T11:47:59.071327224Z caller=tcp.go:40 >>>>>>> module=smtp_starttls target= 1.1.1.1 :25 level=info msg="Resolved >>>>>>> target >>>>>>> address" ip= 1.1.1.1 >>>>>>> ts=2022-07-04T11:47:59.071354819Z caller=tcp.go:121 >>>>>>> module=smtp_starttls target= 1.1.1.1 :25 level=info msg="Dialing TCP >>>>>>> without TLS" >>>>>>> ts=2022-07-04T11:47:59.072469713Z caller=main.go:130 >>>>>>> module=smtp_starttls target= 1.1.1.1 :25 level=info msg="Successfully >>>>>>> dialed" >>>>>>> ts=2022-07-04T11:47:59.072508076Z caller=main.go:130 >>>>>>> module=smtp_starttls target= 1.1.1.1 :25 level=info msg="Processing >>>>>>> query >>>>>>> response entry" entry_number=0 >>>>>>> ts=2022-07-04T11:47:59.073453639Z caller=main.go:130 >>>>>>> module=smtp_starttls target= 1.1.1.1 :25 level=debug msg="Read line" >>>>>>> line="220 ESMTP" >>>>>>> ts=2022-07-04T11:48:04.072081695Z caller=main.go:130 >>>>>>> module=smtp_starttls target= 1.1.1.1 :25 level=error msg="Error >>>>>>> reading >>>>>>> from connection" err="read tcp4 0.0.0.0:53872->1.1.1.1:25: i/o >>>>>>> timeout" >>>>>>> ts=2022-07-04T11:48:04.072269643Z caller=main.go:320 >>>>>>> module=smtp_starttls target= 1.1.1.1 :25 level=error msg="Probe >>>>>>> failed" >>>>>>> duration_seconds=5.00106792 >>>>>>> >>>>>>> >>>>>>> >>>>>>> Metrics that would have been returned: >>>>>>> # 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.000101683 >>>>>>> # HELP probe_duration_seconds Returns how long the probe took to >>>>>>> complete in seconds >>>>>>> # TYPE probe_duration_seconds gauge >>>>>>> probe_duration_seconds 5.00106792 >>>>>>> # 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 2.493392506e+09 >>>>>>> # HELP probe_ip_protocol Specifies whether probe ip protocol is IP4 >>>>>>> or IP6 >>>>>>> # TYPE probe_ip_protocol gauge >>>>>>> probe_ip_protocol 4 >>>>>>> # HELP probe_success Displays whether or not the probe was a success >>>>>>> # TYPE probe_success gauge >>>>>>> probe_success 0 >>>>>>> >>>>>>> >>>>>>> >>>>>>> Module configuration: >>>>>>> prober: tcp >>>>>>> timeout: 5s >>>>>>> http: >>>>>>> ip_protocol_fallback: true >>>>>>> follow_redirects: true >>>>>>> tcp: >>>>>>> ip_protocol_fallback: true >>>>>>> query_response: >>>>>>> - expect: ^220 ([^ ]+) ESMTP (.+)$ >>>>>>> send: EHLO prober >>>>>>> - expect: ^250-STARTTLS >>>>>>> - expect: ^250 .*$ >>>>>>> send: STARTTLS >>>>>>> - expect: ^220 >>>>>>> starttls: true >>>>>>> - send: EHLO prober >>>>>>> - expect: ^250 .*$ >>>>>>> send: QUIT >>>>>>> icmp: >>>>>>> ip_protocol_fallback: true >>>>>>> dns: >>>>>>> ip_protocol_fallback: true >>>>>>> >>>>>>> On Monday, July 4, 2022 at 7:22:08 PM UTC+8 Brian Candler wrote: >>>>>>> >>>>>>>> Could you first just try copy-pasting the working config I gave >>>>>>>> you, and see if it gives a different result to yours? >>>>>>>> >>>>>>>> I doubt a mail server would take more than 5 seconds to give a >>>>>>>> banner, but it's possible. Simply doing "telnet x.x.x.x 25" will show >>>>>>>> you >>>>>>>> how your mail server behaves. >>>>>>>> >>>>>>>> On Monday, 4 July 2022 at 11:14:23 UTC+1 [email protected] wrote: >>>>>>>> >>>>>>>>> >>>>>>>>> Yes in my code the first expect is quoted. >>>>>>>>> >>>>>>>>> smtp_starttls: >>>>>>>>> prober: tcp >>>>>>>>> timeout: 5s >>>>>>>>> tcp: >>>>>>>>> query_response: >>>>>>>>> - expect: "^220 ([^ ]+) ESMTP (.+)$" >>>>>>>>> - send: "EHLO prober\r" >>>>>>>>> - expect: "^250-STARTTLS" >>>>>>>>> - send: "STARTTLS\r" >>>>>>>>> - expect: "^220" >>>>>>>>> - starttls: true >>>>>>>>> - send: "EHLO prober\r" >>>>>>>>> - expect: "^250-AUTH" >>>>>>>>> - send: "QUIT\r" >>>>>>>>> >>>>>>>>> Probably due to the "timeout" is too less? Should I adjust 5s to >>>>>>>>> 15s or 60s? >>>>>>>>> On Monday, July 4, 2022 at 5:55:09 PM UTC+8 Brian Candler wrote: >>>>>>>>> >>>>>>>>>> The following works for me with blackbox_exporter 0.21.0 (maybe >>>>>>>>>> your first 'expect' regexp needs to be quoted?) >>>>>>>>>> >>>>>>>>>> modules: >>>>>>>>>> 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 .*$" >>>>>>>>>> send: "QUIT" >>>>>>>>>> >>>>>>>>>> Result: >>>>>>>>>> >>>>>>>>>> # *curl -g >>>>>>>>>> 'localhost:9115/probe?module=smtp_starttls&target=aspmx.l.google.com:25&debug=true'* >>>>>>>>>> Logs for the probe: >>>>>>>>>> ts=2022-07-04T09:50:46.764604425Z caller=main.go:351 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Beginning probe" probe=tcp timeout_seconds=5 >>>>>>>>>> ts=2022-07-04T09:50:46.764875668Z caller=tcp.go:40 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Resolving target address" target=aspmx.l.google.com >>>>>>>>>> ip_protocol=ip6 >>>>>>>>>> ts=2022-07-04T09:50:46.765954096Z caller=tcp.go:40 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Resolved target address" target=aspmx.l.google.com >>>>>>>>>> ip=2a00:1450:400c:c07::1b >>>>>>>>>> ts=2022-07-04T09:50:46.766011111Z caller=tcp.go:121 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Dialing TCP without TLS" >>>>>>>>>> ts=2022-07-04T09:50:46.776962616Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Successfully dialed" >>>>>>>>>> ts=2022-07-04T09:50:46.77708032Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Processing query response entry" entry_number=0 >>>>>>>>>> ts=2022-07-04T09:50:46.788075017Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line="220 mx.google.com ESMTP >>>>>>>>>> u1-20020a056000038100b0021bbcef3a69si36572085wrf.542 - gsmtp" >>>>>>>>>> ts=2022-07-04T09:50:46.788168204Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Regexp matched" regexp="^220 ([^ ]+) ESMTP (.+)$" line="220 >>>>>>>>>> mx.google.com ESMTP >>>>>>>>>> u1-20020a056000038100b0021bbcef3a69si36572085wrf.542 - gsmtp" >>>>>>>>>> ts=2022-07-04T09:50:46.788223914Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Sending line" line="EHLO prober" >>>>>>>>>> ts=2022-07-04T09:50:46.788362926Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Processing query response entry" entry_number=1 >>>>>>>>>> ts=2022-07-04T09:50:46.801755535Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line="250-mx.google.com at your service, >>>>>>>>>> [xx:xx:xx:xx::33]" >>>>>>>>>> ts=2022-07-04T09:50:46.801856147Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line="250-SIZE 157286400" >>>>>>>>>> ts=2022-07-04T09:50:46.801889927Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line=250-8BITMIME >>>>>>>>>> ts=2022-07-04T09:50:46.801922312Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line=250-STARTTLS >>>>>>>>>> ts=2022-07-04T09:50:46.801955499Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Regexp matched" regexp=^250-STARTTLS line=250-STARTTLS >>>>>>>>>> ts=2022-07-04T09:50:46.801989646Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Processing query response entry" entry_number=2 >>>>>>>>>> ts=2022-07-04T09:50:46.802029066Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line=250-ENHANCEDSTATUSCODES >>>>>>>>>> ts=2022-07-04T09:50:46.802063318Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line=250-PIPELINING >>>>>>>>>> ts=2022-07-04T09:50:46.802094713Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line=250-CHUNKING >>>>>>>>>> ts=2022-07-04T09:50:46.802126198Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line="250 SMTPUTF8" >>>>>>>>>> ts=2022-07-04T09:50:46.802159858Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Regexp matched" regexp="^250 .*$" line="250 SMTPUTF8" >>>>>>>>>> ts=2022-07-04T09:50:46.802191065Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Sending line" line=STARTTLS >>>>>>>>>> ts=2022-07-04T09:50:46.802271697Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Processing query response entry" entry_number=3 >>>>>>>>>> ts=2022-07-04T09:50:46.812211682Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line="220 2.0.0 Ready to start TLS" >>>>>>>>>> ts=2022-07-04T09:50:46.812279339Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Regexp matched" regexp=^220 line="220 2.0.0 Ready to start TLS" >>>>>>>>>> ts=2022-07-04T09:50:46.833573801Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="TLS Handshake (client) succeeded." >>>>>>>>>> ts=2022-07-04T09:50:46.833793385Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Processing query response entry" entry_number=4 >>>>>>>>>> ts=2022-07-04T09:50:46.833838422Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Sending line" line="EHLO prober" >>>>>>>>>> ts=2022-07-04T09:50:46.833960852Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Processing query response entry" entry_number=5 >>>>>>>>>> ts=2022-07-04T09:50:46.84464181Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line="250-mx.google.com at your service, >>>>>>>>>> [xx:xx:xx:xx::33]" >>>>>>>>>> ts=2022-07-04T09:50:46.844771942Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line="250-SIZE 157286400" >>>>>>>>>> ts=2022-07-04T09:50:46.844839074Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line=250-8BITMIME >>>>>>>>>> ts=2022-07-04T09:50:46.844910271Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line=250-ENHANCEDSTATUSCODES >>>>>>>>>> ts=2022-07-04T09:50:46.844974538Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line=250-PIPELINING >>>>>>>>>> ts=2022-07-04T09:50:46.845061058Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line=250-CHUNKING >>>>>>>>>> ts=2022-07-04T09:50:46.84512579Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Read line" line="250 SMTPUTF8" >>>>>>>>>> ts=2022-07-04T09:50:46.845193403Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Regexp matched" regexp="^250 .*$" line="250 SMTPUTF8" >>>>>>>>>> ts=2022-07-04T09:50:46.84525809Z caller=main.go:144 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=debug >>>>>>>>>> msg="Sending line" line=QUIT >>>>>>>>>> ts=2022-07-04T09:50:46.845583228Z caller=main.go:351 >>>>>>>>>> module=smtp_starttls target=aspmx.l.google.com:25 level=info >>>>>>>>>> msg="Probe succeeded" duration_seconds=0.080912196 >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> Metrics that would have been returned: >>>>>>>>>> # 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.001103057 >>>>>>>>>> >>>>>>>>>> # HELP probe_duration_seconds Returns how long the probe took to >>>>>>>>>> complete in seconds >>>>>>>>>> # TYPE probe_duration_seconds gauge >>>>>>>>>> probe_duration_seconds 0.080912196 >>>>>>>>>> >>>>>>>>>> # 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 2.766777767e+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_ssl_earliest_cert_expiry Returns earliest SSL cert >>>>>>>>>> expiry date >>>>>>>>>> # TYPE probe_ssl_earliest_cert_expiry gauge >>>>>>>>>> probe_ssl_earliest_cert_expiry 1.661764429e+09 >>>>>>>>>> # HELP probe_ssl_last_chain_expiry_timestamp_seconds Returns last >>>>>>>>>> SSL chain expiry in unixtime >>>>>>>>>> # TYPE probe_ssl_last_chain_expiry_timestamp_seconds gauge >>>>>>>>>> probe_ssl_last_chain_expiry_timestamp_seconds 1.661764429e+09 >>>>>>>>>> >>>>>>>>>> # HELP probe_success Displays whether or not the probe was a >>>>>>>>>> success >>>>>>>>>> # TYPE probe_success gauge >>>>>>>>>> probe_success 1 >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> Module configuration: >>>>>>>>>> prober: tcp >>>>>>>>>> timeout: 5s >>>>>>>>>> http: >>>>>>>>>> ip_protocol_fallback: true >>>>>>>>>> follow_redirects: true >>>>>>>>>> enable_http2: true >>>>>>>>>> >>>>>>>>>> tcp: >>>>>>>>>> ip_protocol_fallback: true >>>>>>>>>> query_response: >>>>>>>>>> - expect: ^220 ([^ ]+) ESMTP (.+)$ >>>>>>>>>> send: EHLO prober >>>>>>>>>> - expect: ^250-STARTTLS >>>>>>>>>> - expect: ^250 .*$ >>>>>>>>>> send: STARTTLS >>>>>>>>>> - expect: ^220 >>>>>>>>>> >>>>>>>>>> starttls: true >>>>>>>>>> - send: EHLO prober >>>>>>>>>> - expect: ^250 .*$ >>>>>>>>>> send: QUIT >>>>>>>>>> >>>>>>>>>> icmp: >>>>>>>>>> ip_protocol_fallback: true >>>>>>>>>> dns: >>>>>>>>>> ip_protocol_fallback: true >>>>>>>>>> recursion_desired: true >>>>>>>>>> >>>>>>>>> -- You received this message because you are subscribed to the Google Groups "Prometheus Users" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. To view this discussion on the web visit https://groups.google.com/d/msgid/prometheus-users/e929986f-0139-4054-b03d-5968cde89592n%40googlegroups.com.
