Filebeat setup issue: Ping request failed in https only environment

Hi,

I think I have stumbled upon a bug/feature when setting up filebeat or any other beat in my environment. I initially opened this as an issue at the github beats repository but was told that this was the right place to discuss this issue.

Problem description

I'm running everything on a kubernetes cluster with the official elastic operator and the cluster setup worked pretty straight forward (see setup information below). In the kubernetes environment I'm using an nginx ingress controller (configuration below) which only allows https traffic on port 443 to the elastic stack. It is possible to sucessfully connect to the elastic stack and issue curl commands. However, when trying to setup filebeat (configuration below), or any other beat, on an ec2 instance to index the data into elasticsearch I'm running into connection issues as can be seen below in the debug section.

Debugging/Analysis steps taken

When I allow traffic on port 80 the setup works fine. This lead me to the conclusion that something might not be implemented in the correct way. After analysing the debug log I had a closer look at the file libbeat/outputs/elasticsearch/client.go where the method execRequest is responsible for executing the http ping request. As far as my golang knowledge goes, which is essentially non existent, the call http.NewRequest in line 801 ignores the https setting and tries to connect to the given url on port 80.

Question

  • Is this behaviour intended for the different beats?
  • If so, since elastic is pushing it's SIEM features and encrypted traffic is becoming more and more present, how should I setup filebeat in an https only environment.

Setup details

elastic kubernetes operator: 1.0.1
elastic version: 7.6.2
filebeat version: 7.6.2
master nodes: 3
data nodes: 2
kibana nodes: 1

filebeat configuration

filebeat.inputs:
- type: log
  enabled: true
  paths:
    - /var/log/cron
  fields:
    log_type: cron

output.elasticsearch:
  enabled: true
  hosts: ["https://es.domain.tld:443"]
  protocol: "https"
  username: xxx
  password: xxx
  index: "filebeat-%{+yyyy.MM.dd}"
  ssl.enabled: true
  ssl.verification_mode: full

ingress configuration

apiVersion: extensions/v1beta1
kind: Ingress
metadata:
  name: es-ingress
  namespace: <namespace>
  annotations:
    kubernetes.io/ingress.class: "nginx"
    nginx.ingress.kubernetes.io/ssl-redirect: "true"
    nginx.ingress.kubernetes.io/backend-protocol: "HTTPS"
    # "413 Request Entity Too Large" uploading plugins, increase client_max_body_size
    nginx.ingress.kubernetes.io/proxy-body-size: 50m
    nginx.ingress.kubernetes.io/proxy-request-buffering: "off"
    # For nginx-ingress controller < 0.9.0.beta-18
    ingress.kubernetes.io/ssl-redirect: "true"
    # "413 Request Entity Too Large" uploading plugins, increase client_max_body_size
    ingress.kubernetes.io/proxy-body-size: 50m
    ingress.kubernetes.io/proxy-request-buffering: "off"
    nginx.ingress.kubernetes.io/force-ssl-redirect: "true"
spec:
  tls:
  - hosts:
    - <es.domain.tld>
  rules:
  - host: <es.domain.tld>
    http:
      paths:
      - path: /
        backend:
          serviceName: <clustername>-es-http
          servicePort: 9200

Debug log

[user@host ~]$ sudo filebeat setup -c /etc/filebeat/filebeat.yml -e -d "*"
2020-04-17T08:45:19.595Z        INFO    instance/beat.go:622    Home path: [/usr/share/filebeat] Config path: [/etc/filebeat] Data path: [/var/lib/filebeat] Logs path: [/var/log/filebeat]
2020-04-17T08:45:19.595Z        DEBUG   [beat]  instance/beat.go:674    Beat metadata path: /var/lib/filebeat/meta.json
2020-04-17T08:45:19.596Z        INFO    instance/beat.go:630    Beat ID: 1b1ff016-e1cc-457b-b093-149575aa0e9b
2020-04-17T08:45:19.596Z        INFO    [beat]  instance/beat.go:958    Beat info       {"system_info": {"beat": {"path": {"config": "/etc/filebeat", "data": "/var/lib/filebeat", "home": "/usr/share/filebeat", "logs": "/var/log/filebeat"}, "type": "filebeat", "uuid": "1b1ff016-e1cc-457b-b093-149575aa0e9b"}}}
2020-04-17T08:45:19.596Z        INFO    [beat]  instance/beat.go:967    Build info      {"system_info": {"build": {"commit": "6a2e173b41fb655ef2226c92833ac0a469ed1577", "libbeat": "7.6.2", "time": "2020-03-05T09:08:43.000Z", "version": "7.6.2"}}}
2020-04-17T08:45:19.597Z        INFO    [beat]  instance/beat.go:970    Go runtime info {"system_info": {"go": {"os":"linux","arch":"amd64","max_procs":1,"version":"go1.13.7"}}}
2020-04-17T08:45:19.598Z        INFO    [beat]  instance/beat.go:974    Host info       {"system_info": {"host": {"architecture":"x86_64","boot_time":"2020-03-17T12:56:05Z","containerized":false,"name":"xxxxxxxxxxx","ip":["127.0.0.1/8","::1/128","xxx.xxx.xxx.xxx/xx","xxx","xxx","xxx","172.17.0.1/16",""],"kernel_version":"4.14.171-105.231.amzn1.x86_64","mac":["xxx","xxx","xxx"],"os":{"family":"redhat","platform":"amzn","name":"Amazon Linux AMI","version":"2018.03","major":2018,"minor":3,"patch":0},"timezone":"UTC","timezone_offset_sec":0,"id":""}}}
2020-04-17T08:45:19.599Z        INFO    [beat]  instance/beat.go:1003   Process info    {"system_info": {"process": {"capabilities": {"inheritable":null,"permitted":["chown","dac_override","dac_read_search","fowner","fsetid","kill","setgid","setuid","setpcap","linux_immutable","net_bind_service","net_broadcast","net_admin","net_raw","ipc_lock","ipc_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"],"effective":["chown","dac_override","dac_read_search","fowner","fsetid","kill","setgid","setuid","setpcap","linux_immutable","net_bind_service","net_broadcast","net_admin","net_raw","ipc_lock","ipc_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"],"bounding":["chown","dac_override","dac_read_search","fowner","fsetid","kill","setgid","setuid","setpcap","linux_immutable","net_bind_service","net_broadcast","net_admin","net_raw","ipc_lock","ipc_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": "/home/xxx/", "exe": "/usr/share/filebeat/bin/filebeat", "name": "filebeat", "pid": 4798, "ppid": 4797, "seccomp": {"mode":"disabled","no_new_privs":false}, "start_time": "2020-04-17T08:45:18.780Z"}}}
2020-04-17T08:45:19.600Z        INFO    instance/beat.go:298    Setup Beat: filebeat; Version: 7.6.2
2020-04-17T08:45:19.600Z        DEBUG   [beat]  instance/beat.go:324    Initializing output plugins
2020-04-17T08:45:19.600Z        INFO    elasticsearch/client.go:174     Elasticsearch url: https://es.domain.tld:443
2020-04-17T08:45:19.601Z        DEBUG   [publisher]     pipeline/consumer.go:137        start pipeline event consumer
2020-04-17T08:45:19.601Z        INFO    [publisher]     pipeline/module.go:110  Beat name: xxx
2020-04-17T08:45:19.601Z        INFO    elasticsearch/client.go:174     Elasticsearch url: https://es.domain.tld:443
2020-04-17T08:45:19.601Z        DEBUG   [elasticsearch] elasticsearch/client.go:733     ES Ping(url=https://es.domain.tld:443)
2020-04-17T08:46:49.601Z        DEBUG   [elasticsearch] elasticsearch/client.go:737     Ping request failed with: Get https://es.domain.tld:443: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
2020-04-17T08:46:49.601Z        ERROR   elasticsearch/elasticsearch.go:261      Error connecting to Elasticsearch at https://es.domain.tld:443: Get https://es.domain.tld:443: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
2020-04-17T08:46:49.601Z        ERROR   instance/beat.go:933    Exiting: Couldn't connect to any of the configured Elasticsearch hosts. Errors: [Error connection to Elasticsearch https://es.domain.tld:443: Get https://es.domain.tld:443: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)]
Exiting: Couldn't connect to any of the configured Elasticsearch hosts. Errors: [Error connection to Elasticsearch https://es.domain.tld:443: Get https://es.domain.tld:443: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)]

Thank you in advance for your assistance.

First off, very much appreciate you digging into the libbeat code! :clap:

However, this is actually not how it works. When the HTTP client is created it takes a "regular" TCP dialer but also a TLS dialer. That way, depending on the protocol (HTTP vs. HTTPS), it can use the appropriate dialer. You can see the TLS dialer object being constructed a few lines earlier, with the appropriate settings from the user-specified configuration.

Nothing in your Filebeat configuration, particularly the output.elasticsearch section, jumps out as unusual to me. You shouldn't even need to specify ssl.enabled: true and ssl.verification_mode: full as those are the default values since your URL in the hosts setting is using the https protocol. Nevertheless, specifying them explicitly should do no harm either.

Unfortunately I'm far from an expert on k8s so I don't have any intelligent thoughts to offer about that configuration. I'm assuming you have it correct :slightly_smiling_face:.

Given your thorough analysis, you've probably checked this already but I'd be remiss not to ask: have you tried the curl from the Filebeat ec2 instance to https://es.domain.tld:443?

Hi,

Thank you for replying in such a short time. I'm sorry that it took me so long to reply.

Given your thorough analysis, you've probably checked this already but I'd be remiss not to ask: have you tried the curl from the Filebeat ec2 instance to https://es.domain.tld:443?

Yes it tried curl on https://es.domain.tld:443 coming from a regular ec2 instance and from inside a kubernetes cluster as well. It works fine for both cases and without credentials I'm receiving the appropriate error message. If I execute a curl command for http://es.domain.tld:80 I get a timeout exception as expected.

However, this is actually not how it works. When the HTTP client is created it takes a "regular" TCP dialer but also a TLS dialer. That way, depending on the protocol (HTTP vs. HTTPS), it can use the appropriate dialer. You can see the TLS dialer object being constructed a few lines earlier, with the appropriate settings from the user-specified configuration.

You are completely right that the NewClient function creates a TLS dialer object. Unfortunately the Ping function (Line 732) where my error message comes (see below) from never instanciates a NewClient object. Instead it directly calls the execRequest method. Am I reading this completely wrong?

DEBUG   [elasticsearch] elasticsearch/client.go:737     Ping request failed with: Get https://es.domain.tld:443: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)

@shaunak Do you have an update on this issue?

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