Log raw events to a separate log file

[belimawr]

Notes for Reviewers

1. The upgrade of elastic-agent-libs to the latest version brought along some breaking changes in transport.Dialer, so this PR also updates all types implementing this interface to be compatible with the new interface definition.

Proposed commit message

This commit introduces a new logger core that can be configured through logging.event_data and is used to log any message that contains the whole event or could contain any sensitive data. This is accomplished by adding log.type: event to the log entry. The logger core is responsible for filtering the log entries and directing them to the correct files.

At the moment it is used by multiple outputs to log indexing errors containing the whole event and errors returned by Elasticsearch that can potentially contain the whole event.

Expected behaviour when running under Elastic-Agent

When running under Elastic-Agent, Beats are started passing the the CLI flags -E logging.sensitive.to_stderr=true -E logging.sensitive.to_files=false. The Elastic-Agent collects the stderr and stdout from the Beat, wraps every line in a JSON containing some metadata and logs it to the correct log file. The concept of a event log file will be added to the Elastic-Agent.

Checklist

• My code follows the style guidelines of this project
• I have commented my code, particularly in hard-to-understand areas
• I have made corresponding changes to the documentation
• I have made corresponding change to the default configuration files
• I have added tests that prove my fix is effective or that my feature works
• I have added an entry in CHANGELOG.next.asciidoc or CHANGELOG-developer.next.asciidoc.

Author's Checklist

• Update public documentation
• Update <beat>.reference.yml
• Update elastic-agent-libs once [logp] Add typed loggers allowing log entries to go to different outputs elastic-agent-libs#171 is merged
• Rebase onto main once build(deps): bump github.com/elastic/elastic-agent-libs from 0.7.5 to 0.9.4 #39013 is merged
• Rebase onto main once Disable logging when all outputs are disabled elastic-agent-libs#204 is merged
• Rebase onto main once Remove shipper #39584 is merged
• Rebase onto main once x-pack/filebeat/input/httpjson: skip flakey test on windows #39678 is merged or [Flaky Test] HTTPJSON input - TestMetrics/Test_pagination_metrics - expected non zero value for metric httpjson_interval_pages_execution_time #39676 is solved

How to test this PR locally

Standalone Filebeat

Start Filebeat with the following configuration

filebeat.inputs:
  - type: filestream
    id: filestream-input-id
    enabled: true
    parsers:
      - ndjson:
          target: ""
          overwrite_keys: true
          expand_keys: true
          add_error_key: true
          ignore_decoding_error: false
    paths:
      - /tmp/flog.log

output:
  elasticsearch:
    hosts:
      - localhost:9200
    protocol: https
    username: elastic
    password: changeme
    allow_older_versions: true
    ssl.verification_mode: none

logging:
  level: debug
  event_data:
    files:
      name: filebeat-events-data # that's the default, change it if you want another name.

Create the log file /tmp/flog.log with the following content:

{"message":"foo bar","int":10,"string":"str"}
{"message":"another message","int":20,"string":"str2"}
{"message":"index failure","int":"not a number","string":10}
{"message":"second index failure","int":"not a number","string":10}
A broken JSON

Raw events should be logged to a different log file, in the same folder as the normal logs, the filename matches the glob filebeat-events-data*.ndjson.

By default the logs go in a logs folder that's created in the same folder you're running Filebeat from, here are the files created when running this branch:

% ls -la logs 
-rw------- 1 tiago tiago  65K Jan 16 16:24 filebeat-20240116.ndjson
-rw------- 1 tiago tiago 2.8K Jan 16 16:22 filebeat-events-data-20240116.ndjson

If you need to run the test again, either add more data to /tmp/flog.log or remove the data folder Filebeat created at star up, this will make Filebeat re-ingest the file.

Filebeat in Kubernetes

1. Build the Docker image: DEV=true SNAPSHOT=true PACKAGES=docker PLATFORMS=linux/amd64 mage -v package (adjust the platform as needed)
2. Start a Kubernetes cluster, that can be done using Kind: kind create cluster
3. Load the built docker image in the cluster: kind load docker-image docker.elastic.co/beats/filebeat:8.15.0-SNAPSHOT
4. Generate some logs in the default namespace: kubectl create deployment flog --image=mingrammer/flog -- flog -d 1 -s 1 -l
5. Start Filebeat using the following manifest file below: kubectl apply -f filebeat-kubernetes.yaml
6. Look at the logs and assert no event data is going to stderr:

   kubectl logs -f -n kube-system `kubectl get pod -n kube-system -l k8s-app=filebeat -o jsonpath='{.items[].metadata.name}'``
   

7. Shell into the container and assert the event log file exists and is getting the events:

   kubectl exec -it -n kube-system `kubectl get pod -n kube-system -l k8s-app=filebeat -o jsonpath='{.items[].metadata.name}'` -- /bin/bash
   # From inside the container
   # Ensure the event log file exit
   ls -la /usr/share/filebeat/logs/
   
   # Look at its content
   tail -F /usr/share/filebeat/logs/*
   

If you want to see the event logs going to stderr, uncomment the following lies from the configuration:

          # "-E",
          # "logging.event_data.to_stderr=true"

If you already created the Fielbeat pod, you'll have to delete it then recreate with the new configuration.

filebeat-kubernetes.yaml

apiVersion: v1
kind: ServiceAccount
metadata:
  name: filebeat
  namespace: kube-system
  labels:
    k8s-app: filebeat
---
apiVersion: rbac.authorization.k8s.io/v1
kind: ClusterRole
metadata:
  name: filebeat
  labels:
    k8s-app: filebeat
rules:
- apiGroups: [""] # "" indicates the core API group
  resources:
  - namespaces
  - pods
  - nodes
  verbs:
  - get
  - watch
  - list
- apiGroups: ["apps"]
  resources:
    - replicasets
  verbs: ["get", "list", "watch"]
- apiGroups: ["batch"]
  resources:
    - jobs
  verbs: ["get", "list", "watch"]
---
apiVersion: rbac.authorization.k8s.io/v1
kind: Role
metadata:
  name: filebeat
  # should be the namespace where filebeat is running
  namespace: kube-system
  labels:
    k8s-app: filebeat
rules:
  - apiGroups:
      - coordination.k8s.io
    resources:
      - leases
    verbs: ["get", "create", "update"]
---
apiVersion: rbac.authorization.k8s.io/v1
kind: Role
metadata:
  name: filebeat-kubeadm-config
  namespace: kube-system
  labels:
    k8s-app: filebeat
rules:
  - apiGroups: [""]
    resources:
      - configmaps
    resourceNames:
      - kubeadm-config
    verbs: ["get"]
---
apiVersion: rbac.authorization.k8s.io/v1
kind: ClusterRoleBinding
metadata:
  name: filebeat
subjects:
- kind: ServiceAccount
  name: filebeat
  namespace: kube-system
roleRef:
  kind: ClusterRole
  name: filebeat
  apiGroup: rbac.authorization.k8s.io
---
apiVersion: rbac.authorization.k8s.io/v1
kind: RoleBinding
metadata:
  name: filebeat
  namespace: kube-system
subjects:
  - kind: ServiceAccount
    name: filebeat
    namespace: kube-system
roleRef:
  kind: Role
  name: filebeat
  apiGroup: rbac.authorization.k8s.io
---
apiVersion: rbac.authorization.k8s.io/v1
kind: RoleBinding
metadata:
  name: filebeat-kubeadm-config
  namespace: kube-system
subjects:
  - kind: ServiceAccount
    name: filebeat
    namespace: kube-system
roleRef:
  kind: Role
  name: filebeat-kubeadm-config
  apiGroup: rbac.authorization.k8s.io
---
apiVersion: v1
kind: ConfigMap
metadata:
  name: filebeat-config
  namespace: kube-system
  labels:
    k8s-app: filebeat
data:
  filebeat.yml: |-
    filebeat.inputs:
    filebeat.autodiscover:
     providers:
       - type: kubernetes
         node: ${NODE_NAME}
         namespace: default
         hints.enabled: true
         hints.default_config:
           type: filestream
           id: kubernetes-container-logs-${data.kubernetes.pod.name}-${data.kubernetes.container.id}
           paths:
           - /var/log/containers/*-${data.kubernetes.container.id}.log
           parsers:
           - container: ~
           prospector:
            scanner:
              fingerprint.enabled: true
              symlinks: true
           file_identity.fingerprint: ~

    output.discard:
      enabled: true

    logging:
      level: debug
      selectors:
        - processors
        - filestream
        - input.filestream
        - input
      # event_data:
      #   files:
      #     name: filebeat-events-data
---
apiVersion: apps/v1
kind: DaemonSet
metadata:
  name: filebeat
  namespace: kube-system
  labels:
    k8s-app: filebeat
spec:
  selector:
    matchLabels:
      k8s-app: filebeat
  template:
    metadata:
      labels:
        k8s-app: filebeat
    spec:
      serviceAccountName: filebeat
      terminationGracePeriodSeconds: 30
      hostNetwork: true
      dnsPolicy: ClusterFirstWithHostNet
      containers:
      - name: filebeat
        image: "docker.elastic.co/beats/filebeat:8.15.0-SNAPSHOT"
        args: [
          "-c", "/etc/filebeat.yml",
          "-e",
          # "-E",
          # "logging.event_data.to_stderr=true"
        ]
        env:
        - name: ELASTICSEARCH_HOST
          value: elasticsearch
        - name: ELASTICSEARCH_PORT
          value: "9200"
        - name: ELASTICSEARCH_USERNAME
          value: elastic
        - name: ELASTICSEARCH_PASSWORD
          value: changeme
        - name: ELASTIC_CLOUD_ID
          value:
        - name: ELASTIC_CLOUD_AUTH
          value:
        - name: NODE_NAME
          valueFrom:
            fieldRef:
              fieldPath: spec.nodeName
        securityContext:
          runAsUser: 0
          # If using Red Hat OpenShift uncomment this:
          #privileged: true
        resources:
          limits:
            memory: 200Mi
          requests:
            cpu: 100m
            memory: 100Mi
        volumeMounts:
        - name: config
          mountPath: /etc/filebeat.yml
          readOnly: true
          subPath: filebeat.yml
        - name: data
          mountPath: /usr/share/filebeat/data
        - name: varlibdockercontainers
          mountPath: /var/lib/docker/containers
          readOnly: true
        - name: varlog
          mountPath: /var/log
          readOnly: true
      volumes:
      - name: config
        configMap:
          defaultMode: 0640
          name: filebeat-config
      - name: varlibdockercontainers
        hostPath:
          path: /var/lib/docker/containers
      - name: varlog
        hostPath:
          path: /var/log
      # data folder stores a registry of read status for all files, so we don't send everything again on a Filebeat pod restart
      - name: data
        hostPath:
          # When filebeat runs as non-root user, this directory needs to be writable by group (g+w).
          path: /var/lib/filebeat-data
          type: DirectoryOrCreate
---

A couple important things to notice about the provided Kubernetes manifest/Filebeat configuration:

• The configuration uses the discard output, so all events are sent to /dev/null, however we still get the events debug logs (that's all we really need to test this PR)
• The logs are collected only from pods in the default namespace (namespace: default set in the config). This prevents Filebeat from collecting it's own logs, which at debug with the debug processors is a terrible idea (every event generates a log line that's collected, published as a new event, which logs again, and repeats the cycle indefinitely).

Related issues

• Elastic-Agent PR: Log raw events to a separate log file elastic-agent#4549

## Use cases
## Screenshots
## Logs

[mergify]

This pull request does not have a backport label.
If this is a bug or security fix, could you label this PR @belimawr? 🙏.
For such, you'll need to label your PR with:

• The upcoming major version of the Elastic Stack
• The upcoming minor version of the Elastic Stack (if you're not pushing a breaking change)

To fixup this pull request, you need to add the backport labels for the needed
branches, such as:

• backport-v8./d.0 is the label to automatically backport to the 8./d branch. /d is the digit

[elasticmachine]

💔 Build Failed

the below badges are clickable and redirect to their specific view in the CI or DOCS

Expand to view the summary

Build stats

• Duration: 110 min 12 sec

Pipeline error

This error is likely related to the pipeline itself. Click here
and then you will see the error (either incorrect syntax or an invalid configuration).

❕ Flaky test report

No test was executed to be analysed.

🤖 GitHub comments

Expand to view the GitHub comments

To re-run your PR in the CI, just comment with:

• /test : Re-trigger the build.

• /package : Generate the packages and run the E2E tests.

• /beats-tester : Run the installation tests with beats-tester.

• run elasticsearch-ci/docs : Re-trigger the docs validation. (use unformatted text in the comment!)

[elasticmachine]

Pinging @elastic/elastic-agent (Team:Elastic-Agent)

[elasticmachine]

Pinging @elastic/elastic-agent-data-plane (Team:Elastic-Agent-Data-Plane)

[rdner]

1. Unclear why the DialContext change is a part of this PR
2. A linter issue needs to be fixed
3. Looks like there is a forgotten replace directive that fails the check and docs CI steps.

[mergify]

This pull request is now in conflicts. Could you fix it? 🙏
To fixup this pull request, you can check out it locally. See documentation: https://help.github.com/articles/checking-out-pull-requests-locally/

git fetch upstream
git checkout -b log-raw-events-to-file-v2 upstream/log-raw-events-to-file-v2
git merge upstream/main
git push upstream log-raw-events-to-file-v2

[gizas]

@belimawr my only concern is that I can not make it work inside k8s environment as described here: #38767 (comment)

This is how I start the filebeat (that I built from your pr : GOOS=linux GOARCH=arm64 go build)

kubectl exec `kubectl get pod -n kube-system -l k8s-app=filebeat -o jsonpath='{.items[].metadata.name}'` -n kube-system -- bash -c “filebeat -e -c /etc/filebeat.yml -e logging.event_data.to_stderr=true"

And still don't see any event logging, only my filebeat logs:

root@kind-control-plane:/usr/share/filebeat# ls -lrt /var/log/containers/ | grep filebeat
lrwxrwxrwx 1 root root  92 May 22 07:36 filebeat-lkmpf_kube-system_filebeat-eff4163a56a2c461dc4f6ec77c971623869181261e251faec8ba2f145b5d1ff2.log -> /var/log/pods/kube-system_filebeat-lkmpf_241373d0-5916-4080-8c76-8e4b1152f7b5/filebeat/0.log

Should we test in k8s, or rephrase is this out of scope? Am I doing something wrong in my testing?

[belimawr]

@belimawr my only concern is that I can not make it work inside k8s environment as described here: #38767 (comment)

This is how I start the filebeat (that I built from your pr : GOOS=linux GOARCH=arm64 go build)

kubectl exec `kubectl get pod -n kube-system -l k8s-app=filebeat -o jsonpath='{.items[].metadata.name}'` -n kube-system -- bash -c “filebeat -e -c /etc/filebeat.yml -e logging.event_data.to_stderr=true"

And still don't see any event logging, only my filebeat logs:

root@kind-control-plane:/usr/share/filebeat# ls -lrt /var/log/containers/ | grep filebeat
lrwxrwxrwx 1 root root  92 May 22 07:36 filebeat-lkmpf_kube-system_filebeat-eff4163a56a2c461dc4f6ec77c971623869181261e251faec8ba2f145b5d1ff2.log -> /var/log/pods/kube-system_filebeat-lkmpf_241373d0-5916-4080-8c76-8e4b1152f7b5/filebeat/0.log

Should we test in k8s, or rephrase is this out of scope? Am I doing something wrong in my testing?

Hi @gizas There is a typo in the command you ran, the -e flag is to direct logs to stderr, the -E flag is to overwrite configurations, so the correct command to direct the event logs to stderr is:

filebeat -e -c /etc/filebeat.yml -E logging.event_data.to_stderr=true

I did test it again in Kubernetes (using Kind) with a fresh build from this PR and it works as expected. I edited the CLI arguments in the manifest directly because that felt easier for me. Here is the manifest I used:

filebeat-kubernetes.yaml

apiVersion: v1
kind: ServiceAccount
metadata:
  name: filebeat
  namespace: kube-system
  labels:
    k8s-app: filebeat
---
apiVersion: rbac.authorization.k8s.io/v1
kind: ClusterRole
metadata:
  name: filebeat
  labels:
    k8s-app: filebeat
rules:
- apiGroups: [""] # "" indicates the core API group
  resources:
  - namespaces
  - pods
  - nodes
  verbs:
  - get
  - watch
  - list
- apiGroups: ["apps"]
  resources:
    - replicasets
  verbs: ["get", "list", "watch"]
- apiGroups: ["batch"]
  resources:
    - jobs
  verbs: ["get", "list", "watch"]
---
apiVersion: rbac.authorization.k8s.io/v1
kind: Role
metadata:
  name: filebeat
  # should be the namespace where filebeat is running
  namespace: kube-system
  labels:
    k8s-app: filebeat
rules:
  - apiGroups:
      - coordination.k8s.io
    resources:
      - leases
    verbs: ["get", "create", "update"]
---
apiVersion: rbac.authorization.k8s.io/v1
kind: Role
metadata:
  name: filebeat-kubeadm-config
  namespace: kube-system
  labels:
    k8s-app: filebeat
rules:
  - apiGroups: [""]
    resources:
      - configmaps
    resourceNames:
      - kubeadm-config
    verbs: ["get"]
---
apiVersion: rbac.authorization.k8s.io/v1
kind: ClusterRoleBinding
metadata:
  name: filebeat
subjects:
- kind: ServiceAccount
  name: filebeat
  namespace: kube-system
roleRef:
  kind: ClusterRole
  name: filebeat
  apiGroup: rbac.authorization.k8s.io
---
apiVersion: rbac.authorization.k8s.io/v1
kind: RoleBinding
metadata:
  name: filebeat
  namespace: kube-system
subjects:
  - kind: ServiceAccount
    name: filebeat
    namespace: kube-system
roleRef:
  kind: Role
  name: filebeat
  apiGroup: rbac.authorization.k8s.io
---
apiVersion: rbac.authorization.k8s.io/v1
kind: RoleBinding
metadata:
  name: filebeat-kubeadm-config
  namespace: kube-system
subjects:
  - kind: ServiceAccount
    name: filebeat
    namespace: kube-system
roleRef:
  kind: Role
  name: filebeat-kubeadm-config
  apiGroup: rbac.authorization.k8s.io
---
apiVersion: v1
kind: ConfigMap
metadata:
  name: filebeat-config
  namespace: kube-system
  labels:
    k8s-app: filebeat
data:
  filebeat.yml: |-
    filebeat.inputs:
    filebeat.autodiscover:
     providers:
       - type: kubernetes
         node: ${NODE_NAME}
         namespace: default
         hints.enabled: true
         hints.default_config:
           type: filestream
           id: kubernetes-container-logs-${data.kubernetes.pod.name}-${data.kubernetes.container.id}
           paths:
           - /var/log/containers/*-${data.kubernetes.container.id}.log
           parsers:
           - container: ~
           prospector:
            scanner:
              fingerprint.enabled: true
              symlinks: true
           file_identity.fingerprint: ~

    output.discard:
      enabled: true

    logging:
      level: debug
      selectors:
        - processors
        - filestream
        - input.filestream
        - input
      # event_data:
      #   files:
      #     name: filebeat-events-data
---
apiVersion: apps/v1
kind: DaemonSet
metadata:
  name: filebeat
  namespace: kube-system
  labels:
    k8s-app: filebeat
spec:
  selector:
    matchLabels:
      k8s-app: filebeat
  template:
    metadata:
      labels:
        k8s-app: filebeat
    spec:
      serviceAccountName: filebeat
      terminationGracePeriodSeconds: 30
      hostNetwork: true
      dnsPolicy: ClusterFirstWithHostNet
      containers:
      - name: filebeat
        image: "docker.elastic.co/beats/filebeat:8.15.0-SNAPSHOT"
        args: [
          "-c", "/etc/filebeat.yml",
          "-e",
          # "-E",
          # "logging.event_data.to_stderr=true"
        ]
        env:
        - name: ELASTICSEARCH_HOST
          value: elasticsearch
        - name: ELASTICSEARCH_PORT
          value: "9200"
        - name: ELASTICSEARCH_USERNAME
          value: elastic
        - name: ELASTICSEARCH_PASSWORD
          value: changeme
        - name: ELASTIC_CLOUD_ID
          value:
        - name: ELASTIC_CLOUD_AUTH
          value:
        - name: NODE_NAME
          valueFrom:
            fieldRef:
              fieldPath: spec.nodeName
        securityContext:
          runAsUser: 0
          # If using Red Hat OpenShift uncomment this:
          #privileged: true
        resources:
          limits:
            memory: 200Mi
          requests:
            cpu: 100m
            memory: 100Mi
        volumeMounts:
        - name: config
          mountPath: /etc/filebeat.yml
          readOnly: true
          subPath: filebeat.yml
        - name: data
          mountPath: /usr/share/filebeat/data
        - name: varlibdockercontainers
          mountPath: /var/lib/docker/containers
          readOnly: true
        - name: varlog
          mountPath: /var/log
          readOnly: true
      volumes:
      - name: config
        configMap:
          defaultMode: 0640
          name: filebeat-config
      - name: varlibdockercontainers
        hostPath:
          path: /var/lib/docker/containers
      - name: varlog
        hostPath:
          path: /var/log
      # data folder stores a registry of read status for all files, so we don't send everything again on a Filebeat pod restart
      - name: data
        hostPath:
          # When filebeat runs as non-root user, this directory needs to be writable by group (g+w).
          path: /var/lib/filebeat-data
          type: DirectoryOrCreate
---

A few things to notice:

• The configuration uses the discard output, so all events are sent to /dev/null, however we still get the events debug logs (that's all we really need to test this PR)
• I'm collecting logs from the default namespace (namespace: default set in the config). This prevents Filebeat from collecting it's own logs, which at debug with the debug processors is a terrible idea (every event generates a log line that's collected, published as a new event, which logs again, and repeats the cycle indefinitely).
• I enabled a few debug loggers, the only required one is the processors that will log every raw event published to the queue. Those log entries will go to the events log file
• I left commented out the CLI arguments to direct the events log to stderr, you'll need to un-comment them to see the event logs on stderr.
• Even when logging to stderr the log entries containing event data will contain the field log.type: event. Whenever testing also assert it is present in the log messages.

[belimawr]

@gizas I also added the steps I'm using to test on Kuberentes to the PR description. I hope it helps.

Let me know if face any issues/need any more help.

[gizas]

@belimawr thank you so much for this! I would not find the -E, no way !!!!

The logs are collected only from pods in the default namespace (namespace: default set in the config). This prevents Filebeat from collecting it's own logs, which at debug with the debug processors is a terrible idea (every event generates a log line that's collected, published as a new event, which logs again, and repeats the cycle indefinitely).

I guess this is an important info to be written somewhere !!!

[belimawr]

I guess this is an important info to be written somewhere !!!

I created an issue about it last week: #39566. One thing I'm not 100% sure is where/how to document it.

Probably the manifest example is one of the best places to add it. We could add some rules to ensure Filebeat does not collect its own logs or at least drop/do not collect debug logs.

It will require a bit of time designing a robust solution. Just documenting "it's dangerous/don't do it" is not enough, we have to provide good solution/alternative to our users.