blackbox metrics scraping

[nina guo]

Hi dears,

I'm trying to define an alert rule as below, and the scrape and evaluation interval are 3m.

I checked from log, blackbox will send probe every 2-3second, then the metrics will be generated every 2-3second, and the data will be compare with the alert rules to dertermine an alert will be triggered or not? 

I have a question if Prometheus compares the Live data from blackbox probe, or compares the data with Prometheus scrapped in last 3 mins?

prometheus.yml: |-
    global:
      scrape_interval: 3m
      evaluation_interval: 3m

- alert: EndpointDown
          expr: probe_success == 0
          for: 5s
          labels:
            severity: critical
          annotations:
            description: Service {{ $labels.instance }} is unavailable.
            value: DOWN ({{ $value }})
            summary: "Endpointdown {{ $labels.instance }} is down."

[Brian Candler]

The alerting rules run on their own schedule, separately from the scraping schedule.

The expression "probe_success == 0" uses the value of that metric in the prometheus TSDB *at the current instant of time*. However, the value of a metric at any given time T is the most recent value *on or before* time T (up to T - 5 minutes).

[nina guo]

Thank you Brian. " up to T - 5 minutes  ", this 5 mins is the scraping interval?

[Stuart Clark]

On 25/07/2022 01:08, nina guo wrote:
> Thank you Brian. " up to T - 5 minutes  ", this 5 mins is the scraping
> interval?

No. The scraping interval doesn't matter. Prometheus will by default
look back at most 5 minutes for a value.

--
Stuart Clark

[nina guo]

Got it thank you both Brian and Stuart.

[nina guo]

And one more question pls, I checked the log that the probe is sending every 2-3 seconds, can I adjust this frequency to about 1min?

[Stuart Clark]

On 25/07/2022 08:28, nina guo wrote:
> And one more question pls, I checked the log that the probe is sending
> every 2-3 seconds, can I adjust this frequency to about 1min?

Yes that's the scrape frequency, so you can adjust the job configuration
up to a maximum of about 2.5 minutes.

--
Stuart Clark

[nina guo]

Thank you Stuart.

May I ask why the maximum if 2.5mins?

[Stuart Clark]

On 2022-07-25 09:18, nina guo wrote:
> Thank you Stuart.
>
> May I ask why the maximum if 2.5mins?
>

By default Prometheus will look back for a maximum of 5 minutes to find
the "most recent" data point. Therefore if there was no data recorded in
the past 5 minutes a "no value" would be returned, and you'd have gaps
in your graphs. The recommended maximum of about 2-2.5 minutes is to
allow for a single scrape failure not to result in gaps as well as all
the various processing times to actually do the scrape.

--
Stuart Clark

[nina guo]

Hi Stuart, Brian

I checked the blackbox exporter logs as below for module check_smtp, seems only every 30 secs, the next probe started. But actually I set the scrape_interval for this job is 60s..

07:54:34  Beginning probe
07:55:05  Beginning probe
07:55:34  Beginning probe
07:56:05  Beginning probe
07:56:34  Beginning probe
07:57:05  Beginning probe
07:57:34  Beginning probe

kubectl logs prometheus-blackbox-exporter -c blackbox-exporter -n monitoring  | findstr "1.1.1.1:25"

ts=2022-07-26T07:54:34.872Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Beginning probe" probe=tcp timeout_seconds=9.5
ts=2022-07-26T07:54:34.872Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip6
ts=2022-07-26T07:54:34.872Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip4
ts=2022-07-26T07:54:34.872Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolved target address" ip=1.1.1.1
ts=2022-07-26T07:54:34.872Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Dialing TCP without TLS"
ts=2022-07-26T07:54:34.873Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Successfully dialed"
ts=2022-07-26T07:54:34.873Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=0
ts=2022-07-26T07:54:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220"
ts=2022-07-26T07:54:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^220 ([^ ]+) ESMTP( .+)?$" line="220 ESMTP"
ts=2022-07-26T07:54:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:54:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=1
ts=2022-07-26T07:54:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-STARTTLS
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^250-STARTTLS line=250-STARTTLS
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=2
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="STARTTLS\r"
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=3
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:54:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^220 line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:54:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="TLS Handshake (client) succeeded."
ts=2022-07-26T07:54:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=4
ts=2022-07-26T07:54:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:54:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=5
ts=2022-07-26T07:54:34.883Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:54:34.883Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:54:34.883Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:54:34.883Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:54:34.883Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:54:34.883Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:54:34.883Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:54:34.883Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:54:34.883Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:54:34.883Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="QUIT\r"
ts=2022-07-26T07:54:34.883Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Probe succeeded" duration_seconds=0.011216145

*********************************

ts=2022-07-26T07:55:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Beginning probe" probe=tcp timeout_seconds=9.5
ts=2022-07-26T07:55:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip6
ts=2022-07-26T07:55:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip4
ts=2022-07-26T07:55:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolved target address" ip=1.1.1.1
ts=2022-07-26T07:55:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Dialing TCP without TLS"
ts=2022-07-26T07:55:05.739Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Successfully dialed"
ts=2022-07-26T07:55:05.739Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=0
ts=2022-07-26T07:55:05.740Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220  ESMTP"
ts=2022-07-26T07:55:05.740Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^220 ([^ ]+) ESMTP( .+)?$" line="220 ESMTP"
ts=2022-07-26T07:55:05.740Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:55:05.740Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=1
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-STARTTLS
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^250-STARTTLS line=250-STARTTLS
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=2
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="STARTTLS\r"
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=3
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:55:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^220 line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:55:05.748Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="TLS Handshake (client) succeeded."
ts=2022-07-26T07:55:05.748Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=4
ts=2022-07-26T07:55:05.748Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:55:05.748Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=5
ts=2022-07-26T07:55:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:55:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:55:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:55:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:55:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:55:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:55:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:55:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:55:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:55:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="QUIT\r"
ts=2022-07-26T07:55:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Probe succeeded" duration_seconds=0.010762214
ts=2022-07-26T07:55:26.309Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Beginning probe" probe=tcp timeout_seconds=9.5
ts=2022-07-26T07:55:26.309Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip6
ts=2022-07-26T07:55:26.309Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip4
ts=2022-07-26T07:55:26.309Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolved target address" ip=1.1.1.1
ts=2022-07-26T07:55:26.310Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Dialing TCP without TLS"
ts=2022-07-26T07:55:26.310Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Successfully dialed"
ts=2022-07-26T07:55:26.310Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=0
ts=2022-07-26T07:55:26.311Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 ESMTP"
ts=2022-07-26T07:55:26.311Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^220 ([^ ]+) ESMTP( .+)?$" line="220 ESMTP"
ts=2022-07-26T07:55:26.311Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:55:26.311Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=1
ts=2022-07-26T07:55:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:55:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:55:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:55:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:55:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-STARTTLS
ts=2022-07-26T07:55:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^250-STARTTLS line=250-STARTTLS
ts=2022-07-26T07:55:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=2
ts=2022-07-26T07:55:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:55:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:55:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:55:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:55:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:55:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="STARTTLS\r"
ts=2022-07-26T07:55:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=3
ts=2022-07-26T07:55:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:55:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^220 line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:55:26.319Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="TLS Handshake (client) succeeded."
ts=2022-07-26T07:55:26.320Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=4
ts=2022-07-26T07:55:26.320Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:55:26.320Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=5
ts=2022-07-26T07:55:26.320Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:55:26.320Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:55:26.320Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:55:26.320Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:55:26.320Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:55:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:55:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:55:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:55:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:55:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="QUIT\r"
ts=2022-07-26T07:55:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Probe succeeded" duration_seconds=0.011277742

***********************************
ts=2022-07-26T07:55:34.871Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Beginning probe" probe=tcp timeout_seconds=9.5
ts=2022-07-26T07:55:34.871Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip6
ts=2022-07-26T07:55:34.871Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip4
ts=2022-07-26T07:55:34.872Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolved target address" ip=1.1.1.1
ts=2022-07-26T07:55:34.872Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Dialing TCP without TLS"
ts=2022-07-26T07:55:34.873Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Successfully dialed"
ts=2022-07-26T07:55:34.873Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=0
ts=2022-07-26T07:55:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 ESMTP"
ts=2022-07-26T07:55:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^220 ([^ ]+) ESMTP( .+)?$" line="220 ESMTP"
ts=2022-07-26T07:55:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:55:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=1
ts=2022-07-26T07:55:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:55:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:55:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:55:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:55:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-STARTTLS
ts=2022-07-26T07:55:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^250-STARTTLS line=250-STARTTLS
ts=2022-07-26T07:55:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=2
ts=2022-07-26T07:55:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:55:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:55:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:55:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:55:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:55:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="STARTTLS\r"
ts=2022-07-26T07:55:34.876Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=3
ts=2022-07-26T07:55:34.876Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:55:34.876Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^220 line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:55:34.885Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="TLS Handshake (client) succeeded."
ts=2022-07-26T07:55:34.885Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=4
ts=2022-07-26T07:55:34.885Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:55:34.885Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=5
ts=2022-07-26T07:55:34.885Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:55:34.885Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:55:34.886Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:55:34.886Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:55:34.886Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:55:34.886Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:55:34.886Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:55:34.886Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:55:34.886Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:55:34.886Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="QUIT\r"
ts=2022-07-26T07:55:34.886Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Probe succeeded" duration_seconds=0.014441032

*********************************

ts=2022-07-26T07:56:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Beginning probe" probe=tcp timeout_seconds=9.5
ts=2022-07-26T07:56:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip6
ts=2022-07-26T07:56:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip4
ts=2022-07-26T07:56:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolved target address" ip=1.1.1.1
ts=2022-07-26T07:56:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Dialing TCP without TLS"
ts=2022-07-26T07:56:05.739Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Successfully dialed"
ts=2022-07-26T07:56:05.739Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=0
ts=2022-07-26T07:56:05.740Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220  ESMTP"
ts=2022-07-26T07:56:05.740Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^220 ([^ ]+) ESMTP( .+)?$" line="220 ESMTP"
ts=2022-07-26T07:56:05.740Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:56:05.740Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=1
ts=2022-07-26T07:56:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:56:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:56:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:56:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:56:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-STARTTLS
ts=2022-07-26T07:56:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^250-STARTTLS line=250-STARTTLS
ts=2022-07-26T07:56:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=2
ts=2022-07-26T07:56:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:56:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:56:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:56:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:56:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:56:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="STARTTLS\r"
ts=2022-07-26T07:56:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=3
ts=2022-07-26T07:56:05.742Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:56:05.742Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^220 line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:56:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="TLS Handshake (client) succeeded."
ts=2022-07-26T07:56:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=4
ts=2022-07-26T07:56:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:56:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=5
ts=2022-07-26T07:56:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:56:05.750Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:56:05.750Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:56:05.750Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:56:05.750Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:56:05.750Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:56:05.750Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:56:05.750Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:56:05.750Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:56:05.750Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="QUIT\r"
ts=2022-07-26T07:56:05.750Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Probe succeeded" duration_seconds=0.011471922
ts=2022-07-26T07:56:26.309Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Beginning probe" probe=tcp timeout_seconds=9.5
ts=2022-07-26T07:56:26.309Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip6
ts=2022-07-26T07:56:26.309Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip4
ts=2022-07-26T07:56:26.309Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolved target address" ip=1.1.1.1
ts=2022-07-26T07:56:26.309Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Dialing TCP without TLS"
ts=2022-07-26T07:56:26.310Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Successfully dialed"
ts=2022-07-26T07:56:26.310Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=0
ts=2022-07-26T07:56:26.311Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220  ESMTP"
ts=2022-07-26T07:56:26.311Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^220 ([^ ]+) ESMTP( .+)?$" line="220 ESMTP"
ts=2022-07-26T07:56:26.311Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:56:26.311Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=1
ts=2022-07-26T07:56:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:56:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:56:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:56:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:56:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-STARTTLS
ts=2022-07-26T07:56:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^250-STARTTLS line=250-STARTTLS
ts=2022-07-26T07:56:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=2
ts=2022-07-26T07:56:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:56:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:56:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:56:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:56:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:56:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="STARTTLS\r"
ts=2022-07-26T07:56:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=3
ts=2022-07-26T07:56:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:56:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^220 line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:56:26.320Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="TLS Handshake (client) succeeded."
ts=2022-07-26T07:56:26.320Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=4
ts=2022-07-26T07:56:26.320Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:56:26.320Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=5
ts=2022-07-26T07:56:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:56:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:56:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:56:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:56:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:56:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:56:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:56:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:56:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:56:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="QUIT\r"
ts=2022-07-26T07:56:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Probe succeeded" duration_seconds=0.011515721

************************************************************************

ts=2022-07-26T07:56:34.871Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Beginning probe" probe=tcp timeout_seconds=9.5
ts=2022-07-26T07:56:34.871Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip6
ts=2022-07-26T07:56:34.871Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip4
ts=2022-07-26T07:56:34.871Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolved target address" ip=1.1.1.1
ts=2022-07-26T07:56:34.871Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Dialing TCP without TLS"
ts=2022-07-26T07:56:34.872Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Successfully dialed"
ts=2022-07-26T07:56:34.872Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=0
ts=2022-07-26T07:56:34.873Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 ESMTP"
ts=2022-07-26T07:56:34.873Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^220 ([^ ]+) ESMTP( .+)?$" line="220
ESMTP"
ts=2022-07-26T07:56:34.873Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:56:34.873Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=1
ts=2022-07-26T07:56:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:56:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:56:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:56:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:56:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-STARTTLS
ts=2022-07-26T07:56:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^250-STARTTLS line=250-STARTTLS
ts=2022-07-26T07:56:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=2
ts=2022-07-26T07:56:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:56:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:56:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:56:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:56:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:56:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="STARTTLS\r"
ts=2022-07-26T07:56:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=3
ts=2022-07-26T07:56:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:56:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^220 line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:56:34.881Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="TLS Handshake (client) succeeded."
ts=2022-07-26T07:56:34.881Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=4
ts=2022-07-26T07:56:34.881Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:56:34.881Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=5
ts=2022-07-26T07:56:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:56:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:56:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:56:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:56:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:56:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:56:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:56:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:56:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:56:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="QUIT\r"
ts=2022-07-26T07:56:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Probe succeeded" duration_seconds=0.010919237

****************************************************************************************************

ts=2022-07-26T07:57:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Beginning probe" probe=tcp timeout_seconds=9.5
ts=2022-07-26T07:57:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip6
ts=2022-07-26T07:57:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip4
ts=2022-07-26T07:57:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolved target address" ip=1.1.1.1
ts=2022-07-26T07:57:05.738Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Dialing TCP without TLS"
ts=2022-07-26T07:57:05.739Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Successfully dialed"
ts=2022-07-26T07:57:05.739Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=0
ts=2022-07-26T07:57:05.740Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 ESMTP"
ts=2022-07-26T07:57:05.740Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^220 ([^ ]+) ESMTP( .+)?$" line="220
ESMTP"
ts=2022-07-26T07:57:05.740Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:57:05.740Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=1
ts=2022-07-26T07:57:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:57:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:57:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:57:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:57:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-STARTTLS
ts=2022-07-26T07:57:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^250-STARTTLS line=250-STARTTLS
ts=2022-07-26T07:57:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=2
ts=2022-07-26T07:57:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:57:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:57:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:57:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:57:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:57:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="STARTTLS\r"
ts=2022-07-26T07:57:05.741Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=3
ts=2022-07-26T07:57:05.742Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:57:05.742Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^220 line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:57:05.748Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="TLS Handshake (client) succeeded."
ts=2022-07-26T07:57:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=4
ts=2022-07-26T07:57:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:57:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=5
ts=2022-07-26T07:57:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:57:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:57:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:57:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:57:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:57:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:57:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:57:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:57:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:57:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="QUIT\r"
ts=2022-07-26T07:57:05.749Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Probe succeeded" duration_seconds=0.01131548
ts=2022-07-26T07:57:26.310Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Beginning probe" probe=tcp timeout_seconds=9.5
ts=2022-07-26T07:57:26.310Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip6
ts=2022-07-26T07:57:26.310Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip4
ts=2022-07-26T07:57:26.310Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolved target address" ip=1.1.1.1
ts=2022-07-26T07:57:26.310Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Dialing TCP without TLS"
ts=2022-07-26T07:57:26.311Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Successfully dialed"
ts=2022-07-26T07:57:26.311Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=0
ts=2022-07-26T07:57:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220  ESMTP"
ts=2022-07-26T07:57:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^220 ([^ ]+) ESMTP( .+)?$" line="220
ESMTP"
ts=2022-07-26T07:57:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:57:26.312Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=1
ts=2022-07-26T07:57:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:57:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:57:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:57:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:57:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-STARTTLS
ts=2022-07-26T07:57:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^250-STARTTLS line=250-STARTTLS
ts=2022-07-26T07:57:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=2
ts=2022-07-26T07:57:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:57:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:57:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:57:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:57:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:57:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="STARTTLS\r"
ts=2022-07-26T07:57:26.313Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=3
ts=2022-07-26T07:57:26.314Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:57:26.314Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^220 line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:57:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="TLS Handshake (client) succeeded."
ts=2022-07-26T07:57:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=4
ts=2022-07-26T07:57:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:57:26.321Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=5
ts=2022-07-26T07:57:26.322Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:57:26.322Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:57:26.322Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:57:26.322Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:57:26.322Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:57:26.322Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:57:26.322Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:57:26.322Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:57:26.322Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:57:26.322Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="QUIT\r"
ts=2022-07-26T07:57:26.322Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Probe succeeded" duration_seconds=0.012004202

***********************************************************************************************

ts=2022-07-26T07:57:34.871Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Beginning probe" probe=tcp timeout_seconds=9.5
ts=2022-07-26T07:57:34.871Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip6
ts=2022-07-26T07:57:34.871Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolving target address" ip_protocol=ip4
ts=2022-07-26T07:57:34.871Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Resolved target address" ip=1.1.1.1
ts=2022-07-26T07:57:34.871Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Dialing TCP without TLS"
ts=2022-07-26T07:57:34.872Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Successfully dialed"
ts=2022-07-26T07:57:34.872Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=0
ts=2022-07-26T07:57:34.873Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 ESMTP"
ts=2022-07-26T07:57:34.873Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^220 ([^ ]+) ESMTP( .+)?$" line="220
ESMTP"
ts=2022-07-26T07:57:34.873Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:57:34.873Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=1
ts=2022-07-26T07:57:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:57:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:57:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:57:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:57:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-STARTTLS
ts=2022-07-26T07:57:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^250-STARTTLS line=250-STARTTLS
ts=2022-07-26T07:57:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=2
ts=2022-07-26T07:57:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:57:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:57:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:57:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:57:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:57:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="STARTTLS\r"
ts=2022-07-26T07:57:34.874Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=3
ts=2022-07-26T07:57:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:57:34.875Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp=^220 line="220 2.0.0 Ready to start TLS"
ts=2022-07-26T07:57:34.881Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="TLS Handshake (client) succeeded."
ts=2022-07-26T07:57:34.881Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=4
ts=2022-07-26T07:57:34.881Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="EHLO prober\r"
ts=2022-07-26T07:57:34.881Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Processing query response entry" entry_number=5
ts=2022-07-26T07:57:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250
ts=2022-07-26T07:57:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-PIPELINING
ts=2022-07-26T07:57:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-SIZE 10240000"
ts=2022-07-26T07:57:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ETRN
ts=2022-07-26T07:57:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250-AUTH PLAIN LOGIN"
ts=2022-07-26T07:57:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-ENHANCEDSTATUSCODES
ts=2022-07-26T07:57:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line=250-8BITMIME
ts=2022-07-26T07:57:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Read line" line="250 DSN"
ts=2022-07-26T07:57:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Regexp matched" regexp="^250 .*$" line="250 DSN"
ts=2022-07-26T07:57:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Sending line" line="QUIT\r"
ts=2022-07-26T07:57:34.882Z caller=main.go:180 module=smtp_starttls_server target=1.1.1.1:25 level=debug msg="Probe succeeded" duration_seconds=0.010906375

[Brian Candler]

Can't help without seeing your entire scrape job and service discovery config.

If the scrape job definitely has a 60 second interval, then the most likely reasons are:

1. The same target is listed multiple times in service discovery.  You can check in Prometheus web interface by looking at "Status > Targets".  (The scrapes will be spread over the 60 second period. Refresh periodically and look how "Last Scrape" value changes)

2. You have multiple prometheus server instances scraping the same blackbox_exporter

Either way, it's something you've done wrong: but you'll need to check your configs and your non-obfuscated logs to see what it is.  Using tcpdump to inspect the traffic to/from blackbox_exporter may also give you clues as to where the scrapes are coming from.

[nina guo]

The whole configuration is as below. The part of targets which are from pod1.json are also included in pod0.json. But the the jobs are with different module(tcp/http_2xxx).

global:
      scrape_interval: 60s
      evaluation_interval: 60s

- job_name: TCP
        # scheme: http

        scrape_interval: 60s
        metrics_path: /probe
        params:
          module: [tcp]  # Look for a HTTP 200 response.
        file_sd_configs:
        - files:
          - '/etc/prometheus/targets/pod0.json'
        relabel_configs:
          - source_labels: [__address__]
            target_label: __param_target
          - source_labels: [__param_target]
            target_label: instance
          - target_label: __address__
            replacement: prometheus-blackbox-exporter:9115  # The blackbox exporter
     

      - job_name: Connection

        scrape_interval: 60s
        metrics_path: /probe
        params:
          module: [http_2xx]
        file_sd_configs:
        - files:
          - '/etc/prometheus/targets/pod1.json'
        relabel_configs:
          - source_labels: [__address__]
            target_label: __param_target
          - source_labels: [__param_target]
            target_label: instance
          - target_label: __address__
            replacement: prometheus-blackbox-exporter:9115

[Brian Candler]

That's clearly not the relevant config, because you said your problem was with "module check_smtp".  Those two scrape jobs are for module=tcp and module=http_2xx

[nina guo]

Sorry I pasted wrong config here

      - job_name: Mail Server

        scrape_interval: 60s
        metrics_path: /probe
        params:

          module: [smtp_starttls]
        file_sd_configs:
        - files:
          - '/etc/prometheus/targets/target_files/pod0.json' # mail01, mail02

        relabel_configs:
          - source_labels: [__address__]
            target_label: __param_target
          - source_labels: [__param_target]
            target_label: instance
          - target_label: __address__
            replacement: prometheus-blackbox-exporter:9115
           

      - job_name: Mail LB

         scrape_interval: 60s
        metrics_path: /probe
        params:

          module: [smtp_starttls]
        file_sd_configs:
        - files:
          - '/etc/prometheus/targets/target_files/pod1.json' # mail LB

        relabel_configs:
          - source_labels: [__address__]
            target_label: __param_target
          - source_labels: [__param_target]
            target_label: instance
          - target_label: __address__
            replacement: prometheus-blackbox-exporter:9115 

[Brian Candler]

The answer will be clear if you did what I said before: look in the Prometheus web interface under Status > Targets

Then you'll be able to see clearly if you've listed the same target twice, either twice within the same job (say pod0.json), or once each in pod0.json and pod1.json.

And if that's not the case, then it may be that you have another prometheus server scraping the same blackbox_exporter. Obvious ways to check: remove all the contents from pod0.json and pod1.json, or remove the scrape jobs entirely, or even just shutdown the prometheus server. Then look at the blackbox_exporter logs to see if it's still being scraped by something else.

This is just basic analysis.  Make a theory as to what might be the problem; change one thing which would verify or refute that theory; and check if it behaves as you expect.