HTTP monitor and TLS connection in Heartbeat 7.17.0

gigaset · March 22, 2022, 1:22pm

Hi,

I'm using Heartbeat v7.17.0, and it looks like there is a problem with establishing the TLS connection in the HTTP monitor. The first problem is that the config option ssl.verification_mode: none seems not to work. The second problem is that even with the option ssl.verification_mode set to full, the heartbeat does not recognise the certificate while, e.g. curl does:

curl https://portal:5004/customerapi/health-status
UP 1.7.5 1647512016950

Part of my config:

---
#heartbeat.config.monitors:
#  path: ${path.config}/monitors.d/*.yml
#  reload.enabled: true
#  reload.period: 5s

# Configure monitors
heartbeat.monitors:

- type: http
  id: portal-customer-service
  name: portal-customer-service http status
  service_name: portal-customer-service
  hosts: ["portal:5004/customerapi/health-status"]
  schedule: "@every 5s"
  ssl.enabled: true
  ssl.verification_mode: none

2022-03-22T13:00:00.722Z        WARN    [tls]   tlscommon/tls_config.go:101     SSL/TLS verifications disabled.
2022-03-22T13:00:45.581Z        DEBUG   [processors]    processing/processors.go:203    Publish event: {
  "@timestamp": "2022-03-22T13:00:45.578Z",
  "@metadata": {
    "beat": "heartbeat",
    "type": "_doc",
    "version": "7.17.0"
  },
  "url": {
    "port": 5004,
    "path": "/customerapi/health-status",
    "full": "https://portal:5004/customerapi/health-status",
    "scheme": "https",
    "domain": "portal"
  },
  "service": {
    "name": "portal-customer-service",
    "environment": "dev"
  },
  "error": {
    "message": "Get \"https://portal:5004/customerapi/health-status\": remote error: tls: handshake failure",
    "type": "io"
  },
  "event": {
    "dataset": "http",
    "timezone": "+00:00"
  },
  "agent": {
    "version": "7.17.0",
    "hostname": "xxx-useast1-b-portal-app-dev-i1.dev.aws.xxx.lan",
    "ephemeral_id": "41b98773-591a-4550-a02f-a5ec5a44be46",
    "id": "e7c95814-bb9a-42ac-af59-9b152d12951f",
    "name": "xxx-useast1-b-portal-app-dev-i1.dev.aws.xxx.lan",
    "type": "heartbeat"
  },
  "tcp": {
    "rtt": {
      "connect": {
        "us": 221
      }
    }
  },
  "monitor": {
    "duration": {
      "us": 3306
    },
    "check_group": "137479c5-a9e0-11ec-ac2c-0a1e93c29b69",
    "ip": "127.0.0.1",
    "type": "http",
    "timespan": {
      "lt": "2022-03-22T13:00:50.581Z",
      "gte": "2022-03-22T13:00:45.581Z"
    },
    "id": "portal-customer-service",
    "name": "portal-customer-service http status",
    "status": "down"
  },
  "resolve": {
    "rtt": {
      "us": 244
    },
    "ip": "127.0.0.1"
  },
  "observer": {
    "hostname": "xxx-useast1-b-portal-app-dev-i1.dev.aws.xxx.lan",
    "ip": [
      "XXX.XXX.XXX.XXX",
      "fe80::81e:93ff:fec2:9b69",
      "172.17.0.1",
      "172.18.0.1"
    ],
    "mac": [
      "0a:1e:93:c2:9b:69",
      "02:42:2c:88:fe:1a",
      "02:42:a3:6c:bc:5c",
      "6e:7f:bc:9e:d4:f0"
    ],
    "geo": {
      "continent_name": "North America",
      "country_iso_code": "US",
      "region_name": "Virginia",
      "region_iso_code": "VA",
      "city_name": "Ashburn",
      "name": "us-east-1",
      "location": "39.03, -77.47"
    }
  },
  "summary": {
    "up": 0,
    "down": 1
  },
  "tags": [
    "dev"
  ],
  "ecs": {
    "version": "1.12.0"
  }
}

Do you know what is going on here?

Thanks
Les

TiagoQueiroz · March 22, 2022, 5:43pm

Hi @gigaset, this seems to be related to a race condition that has been fixed on 7.17.1

What is puzzling me is the fact that ssl.verification_mode: none did not work.

My suggestion:

If possible upgrade to 7.17.1 (it's a bug fix release, so it should be an easy upgrade)
if upgrading is not an option, then set ssl.verification_mode: certificate in your monitor configuration
If that does not work either, then run heartbeat with log level info and ssl.verification_mode: certificate, then post the logs here so I can take a look. I only need the logs, not the published events.

gigaset · March 23, 2022, 12:26pm

Hi,

I have upgraded Heartbeat to 7.17.1. The result is the same. Then, I've changed the config to ssl.verification_mode: certificate. That also has not changed anything.

---
#heartbeat.config.monitors:
#  path: ${path.config}/monitors.d/*.yml
#  reload.enabled: true
#  reload.period: 5s

# Configure monitors
heartbeat.monitors:

- type: http
  id: portal-customer-service
  name: portal-customer-service http status
  service_name: portal-customer-service
  hosts: ["portal:5004/customerapi/health-status"]
  schedule: "@every 5s"
  ssl.enabled: true
  ssl.verification_mode: certificate

I'm starting to think, that GoLang does not recognise the host name if the certificate does not have it in the SAN. Our certificate currently contains the host name only in the CommonName. I had a similar issue with Hashicorp Vault which is also written in GoLang.

2022-03-23T12:11:39.790Z        WARN    [cfgwarn]       tlscommon/config.go:100 DEPRECATED: Treating the CommonName field on X.509 certificates as a host name when no Subject Alternative Names are present is going to be removed. Please update your certificates if needed. Will be removed in version: 8.0.0

Full log output

2022-03-23T12:11:39.777Z        INFO    instance/beat.go:686    Home path: [/usr/share/heartbeat] Config path: [/etc/heartbeat] Data path: [/var/lib/heartbeat] Logs path: [/var/log/heartbeat] Hostfs Path: [/]
2022-03-23T12:11:39.780Z        INFO    instance/beat.go:694    Beat ID: e7c95814-bb9a-42ac-af59-9b152d12951f
2022-03-23T12:11:39.783Z        INFO    [seccomp]       seccomp/seccomp.go:124  Syscall filter successfully installed
2022-03-23T12:11:39.785Z        INFO    [beat]  instance/beat.go:1040   Beat info       {"system_info": {"beat": {"path": {"config": "/etc/heartbeat", "data": "/var/lib/heartbeat", "home": "/usr/share/heartbeat", "logs": "/var/log/heartbeat"}, "type": "heartbeat", "uuid": "e7c95814-bb9a-42ac-af59-9b152d12951f"}}}
2022-03-23T12:11:39.787Z        INFO    [beat]  instance/beat.go:1049   Build info      {"system_info": {"build": {"commit": "1d05ba86138cfc9a5ae5c0acc64a57b8d81678ff", "libbeat": "7.17.1", "time": "2022-02-23T23:44:00.000Z", "version": "7.17.1"}}}
2022-03-23T12:11:39.787Z        INFO    [beat]  instance/beat.go:1052   Go runtime info {"system_info": {"go": {"os":"linux","arch":"amd64","max_procs":4,"version":"go1.17.6"}}}
2022-03-23T12:11:39.788Z        INFO    [beat]  instance/beat.go:1056   Host info       {"system_info": {"host": {"architecture":"x86_64","boot_time":"2022-03-15T02:29:47Z","containerized":false,"name":"XXX-useast1-b-portal-app-dev-i1.dev.aws.XXX.lan","ip":["127.0.0.1/8","::1/128","10.191.38.223/24","fe80::81e:93ff:fec2:9b69/64","172.17.0.1/16","172.18.0.1/16","fe80::42:a3ff:fe6c:bc5c/64","fe80::54d1:53ff:fe49:5c9a/64"],"kernel_version":"4.14.268-205.500.amzn2.x86_64","mac":["0a:1e:93:c2:9b:69","02:42:2c:88:fe:1a","02:42:a3:6c:bc:5c","56:d1:53:49:5c:9a"],"os":{"type":"linux","family":"redhat","platform":"amzn","name":"Amazon Linux","version":"2","major":2,"minor":0,"patch":0,"codename":"Karoo"},"timezone":"UTC","timezone_offset_sec":0,"id":"ec248073e7a1a4c17549244489685049"}}}
2022-03-23T12:11:39.788Z        INFO    [beat]  instance/beat.go:1085   Process info    {"system_info": {"process": {"capabilities": {"inheritable":null,"permitted":["net_raw"],"effective":["net_raw"],"bounding":["chown","dac_override","dac_read_search","fowner","fsetid","kill","setgid","setuid","setpcap","linux_immutable","net_bind_service","net_broadcast","net_admin","net_raw","XXX_lock","XXX_owner","sys_module","sys_rawio","sys_chroot","sys_ptrace","sys_pacct","sys_admin","sys_boot","sys_nice","sys_resource","sys_time","sys_tty_config","mknod","lease","audit_write","audit_control","setfcap","mac_override","mac_admin","syslog","wake_alarm","block_suspend","audit_read"],"ambient":null}, "cwd": "/", "exe": "/usr/share/heartbeat/bin/heartbeat", "name": "heartbeat", "pid": 9499, "ppid": 1, "seccomp": {"mode":"filter","no_new_privs":true}, "start_time": "2022-03-23T12:11:39.050Z"}}}
2022-03-23T12:11:39.788Z        INFO    instance/beat.go:328    Setup Beat: heartbeat; Version: 7.17.1
2022-03-23T12:11:39.788Z        INFO    [index-management]      idxmgmt/std.go:184      Set output.elasticsearch.index to 'heartbeat-7.17.1' as ILM is enabled.
2022-03-23T12:11:39.788Z        INFO    [esclientleg]   eslegclient/connection.go:105   elasticsearch url: https://XXXXXXXXXXXXXX.us-east-1.aws.found.io:443
2022-03-23T12:11:39.789Z        INFO    [publisher]     pipeline/module.go:113  Beat name: XXX-useast1-b-portal-app-dev-i1.dev.aws.XXX.lan
2022-03-23T12:11:39.790Z        INFO    [esclientleg]   eslegclient/connection.go:105   elasticsearch url: https://XXXXXXXXXXXXXX.us-east-1.aws.found.io:443
2022-03-23T12:11:39.790Z        INFO    instance/beat.go:492    heartbeat start running.
2022-03-23T12:11:39.790Z        INFO    beater/heartbeat.go:85  heartbeat is running! Hit CTRL-C to stop it.
2022-03-23T12:11:39.790Z        INFO    beater/heartbeat.go:87  Effective user/group ids: 0/0, with groups: []
2022-03-23T12:11:39.791Z        INFO    [monitoring]    log/log.go:142  Starting metrics logging every 30s
2022-03-23T12:11:39.790Z        WARN    [cfgwarn]       tlscommon/config.go:100 DEPRECATED: Treating the CommonName field on X.509 certificates as a host name when no Subject Alternative Names are present is going to be removed. Please update your certificates if needed. Will be removed in version: 8.0.0
2022-03-23T12:11:39.852Z        INFO    [esclientleg]   eslegclient/connection.go:284   Attempting to connect to Elasticsearch version 7.16.1
2022-03-23T12:11:39.863Z        INFO    [monitoring]    elasticsearch/elasticsearch.go:244      Successfully connected to X-Pack Monitoring endpoint.
2022-03-23T12:11:39.863Z        INFO    [monitoring]    elasticsearch/elasticsearch.go:258      Start monitoring stats metrics snapshot loop with period 10s.
2022-03-23T12:11:39.863Z        INFO    [monitoring]    elasticsearch/elasticsearch.go:258      Start monitoring state metrics snapshot loop with period 1m0s.
2022-03-23T12:11:40.820Z        INFO    [publisher]     pipeline/retry.go:219   retryer: send unwait signal to consumer
2022-03-23T12:11:40.820Z        INFO    [publisher_pipeline_output]     pipeline/output.go:143  Connecting to backoff(elasticsearch(https://XXXXXXXXXXXXXX.us-east-1.aws.found.io:443))
2022-03-23T12:11:40.820Z        INFO    [publisher]     pipeline/retry.go:223     done
2022-03-23T12:11:40.833Z        INFO    [esclientleg]   eslegclient/connection.go:284   Attempting to connect to Elasticsearch version 7.16.1
2022-03-23T12:11:40.845Z        INFO    [esclientleg]   eslegclient/connection.go:284   Attempting to connect to Elasticsearch version 7.16.1
2022-03-23T12:11:40.848Z        INFO    [index-management]      idxmgmt/std.go:261      Auto ILM enable success.
2022-03-23T12:11:40.854Z        INFO    [index-management.ilm]  ilm/std.go:170  ILM policy heartbeat exists already.
2022-03-23T12:11:40.854Z        INFO    [index-management]      idxmgmt/std.go:397      Set setup.template.name to '{heartbeat-7.17.1 {now/d}-000001}' as ILM is enabled.
2022-03-23T12:11:40.854Z        INFO    [index-management]      idxmgmt/std.go:402      Set setup.template.pattern to 'heartbeat-7.17.1-*' as ILM is enabled.
2022-03-23T12:11:40.854Z        INFO    [index-management]      idxmgmt/std.go:436      Set settings.index.lifecycle.rollover_alias in template to {heartbeat-7.17.1 {now/d}-000001} as ILM is enabled.
2022-03-23T12:11:40.854Z        INFO    [index-management]      idxmgmt/std.go:440      Set settings.index.lifecycle.name in template to {heartbeat {"policy":{"phases":{"hot":{"actions":{"rollover":{"max_age":"30d","max_size":"50gb"}}}}}}} as ILM is enabled.
2022-03-23T12:11:40.861Z        INFO    template/load.go:110    Template "heartbeat-7.17.1" already exists and will not be overwritten.
2022-03-23T12:11:40.861Z        INFO    [index-management]      idxmgmt/std.go:297      Loaded index template.
2022-03-23T12:11:40.870Z        INFO    [index-management.ilm]  ilm/std.go:126  Index Alias heartbeat-7.17.1 exists already.
2022-03-23T12:11:40.872Z        INFO    [publisher_pipeline_output]     pipeline/output.go:151  Connection to backoff(elasticsearch(https://XXXXXXXXXXXXXX.us-east-1.aws.found.io:443)) established
2022-03-23T12:11:49.869Z        INFO    [publisher_pipeline_output]     pipeline/output.go:143  Connecting to backoff(monitoring(https://XXXXXXXXXXXXXX.us-east-1.aws.found.io:443))
2022-03-23T12:11:49.869Z        INFO    [monitoring]    pipeline/retry.go:219   retryer: send unwait signal to consumer
2022-03-23T12:11:49.869Z        INFO    [monitoring]    pipeline/retry.go:223     done
2022-03-23T12:11:49.872Z        INFO    [esclientleg]   eslegclient/connection.go:284   Attempting to connect to Elasticsearch version 7.16.1
2022-03-23T12:11:49.876Z        INFO    [publisher_pipeline_output]     pipeline/output.go:151  Connection to backoff(monitoring(https://XXXXXXXXXXXXXX.us-east-1.aws.found.io:443)) established
2022-03-23T12:12:52.137Z        INFO    [monitoring]    log/log.go:193  Uptime: 1m12.534088944s
2022-03-23T12:12:52.137Z        INFO    [monitoring]    log/log.go:160  Stopping metrics logging.
2022-03-23T12:12:52.137Z        INFO    [monitoring]    elasticsearch/elasticsearch.go:266      Stop monitoring stats metrics snapshot loop.
2022-03-23T12:12:52.137Z        INFO    [monitoring]    elasticsearch/elasticsearch.go:266      Stop monitoring state metrics snapshot loop.
2022-03-23T12:12:52.138Z        INFO    instance/beat.go:498    heartbeat stopped.

Thanks
Les

gigaset · March 24, 2022, 1:27pm

Hi @TiagoQueiroz

An update.

I have added portal and 127.0.0.1 to the certificate's SAN, tested with curl and it works that way.

curl https://127.0.0.1:5004/customerapi/health-status
UP 1.9.0 1648126996372

I've reconfigured Heartbeat to use 127.0.0.1 instead

---
# Configure monitors
heartbeat.monitors:

- type: http
  id: portal-customer-service
  name: portal-customer-service http status
  service_name: portal-customer-service
  hosts: ["127.0.0.1:5004/customerapi/health-status"]
  schedule: "@every 5s"
  ssl.enabled: true
  ssl.verification_mode: certificate

Sadly that again gives me this message:

io:Get "https://127.0.0.1:5004/customerapi/health-status": remote error: tls: handshake failure

TiagoQueiroz · March 24, 2022, 6:00pm

Hey @gigaset, I don't believe the problem is with the certificate itself, based on the error messages there is something wrong during the TLS handshake, before the certificate is validated. That's why ssl.verification_mode: none did not work.

It seems the server you're connecting to does not support the TLS versions Heartbeat is using. By default Heartbeat supports: TLSv1.1, TLSv1.2, TLSv1.3

One way to see the protocols suported by your server is to run curl with the -v option:

curl -v --insecure https://localhost:8000/
*   Trying 127.0.0.1:8000...
* Connected to localhost (127.0.0.1) port 8000 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.0 (IN), TLS handshake, Certificate (11):
* TLSv1.0 (IN), TLS handshake, Server key exchange (12):
* TLSv1.0 (IN), TLS handshake, Server finished (14):
* TLSv1.0 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.0 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.0 (OUT), TLS handshake, Finished (20):
* TLSv1.0 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1 / ECDHE-RSA-AES128-SHA
* ALPN, server accepted to use h2
* Server certificate:

There you can see the different protocols tried by curl as well as the final one negotiated with the remote server, in that example it's: * SSL connection using TLSv1 / ECDHE-RSA-AES128-SHA.

gigaset · March 25, 2022, 9:59am

Hi @TiagoQueiroz,

You are right. I didn't know it, but the CA issuing these certs is outdated and does not support the TLS version higher than 1.0 - * ALPN, server did not agree to a protocol.

curl -v -k https://localhost:5004/customerapi/health-status
*   Trying 127.0.0.1:5004...
* Connected to localhost (127.0.0.1) port 5004 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
*  CAfile: /etc/pki/tls/certs/ca-bundle.crt
*  CApath: none
* TLSv1.2 (OUT), TLS header, Certificate Status (22):
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS change cipher, Change cipher spec (1):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
* ALPN, server did not agree to a protocol
* Server certificate:

Until we replace the CA with something up to date, I have added ssl.supported_protocols: ["TLSv1.0", "TLSv1.1", "TLSv1.2"] to the config. Now it works!

Thank you for being so helpful!
Les

system · April 22, 2022, 12:00pm

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.

Topic		Replies	Views
Heartbeat Won't Ignore SSL Verification Beats heartbeat	3	2477	November 22, 2019
Bug? Heartbeat Browsermonitoring ignoring SSL settings? Beats docker , heartbeat	3	639	September 1, 2021
Monitor urls with Windows Authentication Beats heartbeat	4	627	June 7, 2022
Heartbeat HTTP pings fails with 403 Beats heartbeat	2	1144	March 28, 2022
Crypto/rsa: verification error - using heartbeat Beats	7	971	July 31, 2020

HTTP monitor and TLS connection in Heartbeat 7.17.0

Related Topics