Vector crashes on k8s if the sink goes down #22498

rolandjitsu · 2025-02-24T05:49:18Z

rolandjitsu
Feb 24, 2025

I'm in a bit of a pickle. I'm running vector as an aggregator on k8s, configured to consume data from a http server source and push to an Elasticsearch sink.

After running a few tests, it looks like if the sink goes down, but data is still flowing in, Vector pods will eventually crash and show the following error:

The container last terminated with exit code 137 because of OOMKilled.

I've found the following related issues:

#11942
#17942
#18578 - similar; points to a bug in vector that was resolved, but for a different sink
#19815 - sounds similar to what we're experiencing

But I'm a bit confused about it. Mainly because as soon as the sink goes down, the sources will start seeing non-200 http status codes, which to me feels like the the buffering mechanism does not work or it's not intended to work in this case. If it would, I should see 200 since the request made it through to vector and should only start returning non-200 after the buffer is full and can no longer take anymore data.

I'm just looking for some clarification on what exactly is the expected behaviour:

Does vector buffer events send to the http endpoint?
If requests return non-200, does this mean that the events were still buffered? The non-200 just means that we didn't get an ack from vector/sink that the events made it through?
Is there some documentation on the status codes returned from vector when using the http source? At first, it looked like the status codes are the same as Elasticsearch returned, but that cannot be true since there may be multiple sinks returning different status codes

I use the vector helm chart with the following config:

Config

vector:
  role: "Aggregator"

  image:
    repository: timberio/vector
    pullPolicy: IfNotPresent
    tag: "0.42.0-alpine"

  replicas: 2

  secrets:
    generic: {}

  env:
    - name: ES_USERNAME
      value: elastic
    - name: ES_PASSWORD
      valueFrom:
        secretKeyRef:
          name: elastic-user
          key: elastic

  resources: {}

  persistence:
    enabled: true

  # NOTE: When we set this, we need to configure a bunch of other stuff (e.g. HAProxy, etc.)
  # https://github.com/vectordotdev/helm-charts/blob/develop/charts/vector/templates/configmap.yaml
  customConfig:
    data_dir: /vector-data-dir
    api:
      enabled: true
      address: 127.0.0.1:8686
      playground: false
    acknowledgements:
      enabled: true
    # https://vector.dev/blog/log-namespacing/
    schema:
      log_namespace: true
    sources:
      # https://vector.dev/docs/reference/configuration/sources/internal_metrics/
      internal_metrics:
        type: internal_metrics
      # https://vector.dev/docs/reference/configuration/sources/host_metrics/
      host_metrics:
        type: host_metrics
      # https://vector.dev/docs/reference/configuration/sources/vector/
      vector:
        address: 0.0.0.0:6000
        type: vector
        version: "2"
      vector_http:
        type: http_server
        address: 0.0.0.0:8888
        encoding: ndjson
        method: POST
        response_code: 200
    transforms:
      logs:
        type: filter
        inputs:
          - vector_http
        condition: '.kind == "Log"'
      remapped_logs:
        type: remap
        inputs:
          - logs
        source: |-
          .@timestamp = del(.timestamp)
          .metadata = {}
          .data_stream = {}
          .data_stream.type = "logs"
          .data_stream.dataset = "blackhole"
          .data_stream.namespace = "device"
      resource_usage:
        type: filter
        inputs:
          - vector_http
        condition: '.kind == "ResourceUsage"'
      remapped_resource_usage:
        type: remap
        inputs:
          - resource_usage
        source: |-
          .@timestamp = del(.timestamp)
          .metadata = {}
          .data_stream = {}
          .data_stream.type = "metrics"
          .data_stream.dataset = "resource_usage"
          .data_stream.namespace = "device"
    sinks:
      prom_exporter:
        type: prometheus_exporter
        inputs: [internal_metrics, host_metrics]
        address: 0.0.0.0:9090
      stdout:
        type: console
        inputs: [vector, vector_http]
        encoding:
          codec: json
      es_data_stream:
        type: elasticsearch
        inputs: [remapped_logs, remapped_resource_usage]
        # NOTE: We do not need to remap `timestamp` -> `@timestamp`; Vector does this for us when using `data_stream` mode.
        # https://github.com/vectordotdev/vector/blob/d49cf33748ad82292198888687b6b50a01d8500f/src/sinks/elasticsearch/mod.rs#L73
        # TODO: It seems that the above assumption is incorrect! Because w/o adding the `@timestamp`, we see:
        # 2025-02-12T05:53:22.008701Z ERROR sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}:request{request_id=2769}: vector::sinks::util::retries: Not retriable; dropping the request. reason="error type: document_parsing_exception, reason: [1:381] failed to parse: data stream timestamp field [@timestamp] is missing" internal_log_rate_limit=true
        mode: data_stream
        data_stream:
          auto_routing: true
        auth:
          user: "${ES_USERNAME}"
          password: "${ES_PASSWORD}"
          strategy: "basic"
        endpoints:
          - https://es-endpoint.svc.cluster.local:9200
        tls:
          verify_certificate: false

  service:
    enabled: true

    # https://github.com/vectordotdev/helm-charts/blob/develop/charts/vector/templates/service.yaml
    # https://github.com/vectordotdev/helm-charts/blob/develop/charts/vector/templates/service-headless.yaml
    ports:
      - name: vector
        port: 6000
        protocol: TCP
      - name: vector-http
        port: 8888
        protocol: TCP
      - name: prom-exporter
        port: 9090
        protocol: TCP

  haproxy:
    enabled: true

    image:
      repository: haproxytech/haproxy-alpine
      pullPolicy: IfNotPresent
      tag: "2.6.12"

    replicas: 1

    # https://github.com/vectordotdev/helm-charts/blob/develop/charts/vector/templates/haproxy/deployment.yaml
    containerPorts:
      - name: vector
        containerPort: 6000
        protocol: TCP
      - name: vector-http
        containerPort: 8888
        protocol: TCP
      - name: prom-exporter
        containerPort: 9090
        protocol: TCP

    # https://github.com/vectordotdev/helm-charts/blob/develop/charts/vector/templates/haproxy/service.yaml
    service:
      annotations:
      ports:
        - name: vector
          port: 6000
          protocol: TCP
        - name: vector-http
          port: 8888
          protocol: TCP
        - name: prom-exporter
          port: 9090
          protocol: TCP

    # https://github.com/vectordotdev/helm-charts/blob/develop/charts/vector/templates/haproxy/configmap.yaml
    customConfig: |
      global
        log stdout format raw local0 debug
        maxconn 4096
        stats socket /tmp/haproxy
        hard-stop-after {{ .Values.haproxy.terminationGracePeriodSeconds }}s

      defaults
        log     global
        option  dontlognull
        retries 3
        option  redispatch
        option  allbackups
        timeout client 15s
        timeout server 15s
        timeout connect 15s

      resolvers coredns
        nameserver dns1 kube-dns.kube-system.svc.cluster.local:53
        resolve_retries 3
        timeout resolve 2s
        timeout retry 1s
        accepted_payload_size 8192
        hold valid 10s
        hold obsolete 60s

      frontend stats
        mode http
        bind :::1024
        option httplog
        http-request use-service prometheus-exporter if { path /metrics }

      frontend vector
        mode http
        bind :::6000 proto h2
        option httplog
        default_backend vector

      frontend vector_http
        mode http
        bind :::8888 proto h1
        option httplog
        default_backend vector_http

      backend vector
        mode http
        balance roundrobin
        option tcp-check
        server-template srv 10 _vector._tcp.{{ include "vector.fullname" $ }}-headless.{{ $.Release.Namespace }}.svc.cluster.local resolvers coredns proto h2 check

      backend vector_http
        mode http
        balance roundrobin
        option tcp-check
        server-template srv 10 _vector-http._tcp.{{ include "vector.fullname" $ }}-headless.{{ $.Release.Namespace }}.svc.cluster.local resolvers coredns proto h1 check

  # Direct trafic to Traefik's vector entrypoint
  ingress:
    enabled: true
    annotations:
      traefik.ingress.kubernetes.io/router.entrypoints: vectorhttp
    hosts:
      - paths:
          - path: /
            pathType: Prefix
            port:
              name: vector-http

NOTE: On the source side, we have agents pushing to the http endpoint. As soon as a non-200 occurs, they will stop sending new events and keep retrying (at the first failure) until it receives 200, then it continues pushing. There's also a buffering mechanism on the agent side.

rolandjitsu · 2025-02-28T06:14:24Z

rolandjitsu
Feb 28, 2025
Author

On a related note, I've been testing the integration between http client <> Vector http server sink <> Vector Elasticsearch sink and found something that I find rather interesting.

According to the Elasticsearch sink buffer doc, events are flushed either when the timeout expires or when the batch size is >= max bytes/events.

But what I'm seeing right now is that Vector, at times, doesn't send a batch until another request is sent with another batch. I've enabled http logging on the Elasticsearch side to verify if requests are coming through, and that's how I discovered this.

I enabled debug logging in Vector to try to understand what's going on.

Events pushed log

2025-02-28T05:41:01.107168Z DEBUG hyper::proto::h1::conn: incoming body is content-length (1825 bytes)
2025-02-28T05:41:01.107247Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::internal_events::http: Internal log [Received HTTP request.] has been suppressed 1 times.
2025-02-28T05:41:01.107257Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::internal_events::http: Received HTTP request. internal_log_rate_limit=true
2025-02-28T05:41:01.107284Z DEBUG hyper::proto::h1::conn: incoming body completed
2025-02-28T05:41:01.107329Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: warp::filters::query: route was called without a query string, defaulting to empty
2025-02-28T05:41:01.107350Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::sources::util::http::prelude: Handling HTTP request. headers={"host": "vector.tld:8888", "content-length": "1825", "accept": "*/*", "content-type": "application/x-ndjson", "x-forwarded-for": "10.42.12.0", "x-forwarded-host": "vector.tld:8888", "x-forwarded-port": "8888", "x-forwarded-proto": "http", "x-forwarded-server": "traefik-555c9fc894-r5ndq", "x-real-ip": "10.42.12.0", "accept-encoding": "gzip"}
2025-02-28T05:41:01.107586Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector::utilization: utilization=0.00000973105699851513
2025-02-28T05:41:01.107684Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] has been suppressed 10 times.
2025-02-28T05:41:01.107696Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector_common::internal_event::component_events_dropped: Events dropped intentional=true count=1 reason="Events matched filter condition." internal_log_rate_limit=true
2025-02-28T05:41:01.107721Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] is being suppressed to avoid flooding.
2025-02-28T05:41:01.107756Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector::utilization: utilization=0.00001589998575215006
2025-02-28T05:41:01.107788Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] has been suppressed 10 times.
2025-02-28T05:41:01.107791Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Events dropped intentional=true count=1 reason="Events matched filter condition." internal_log_rate_limit=true
2025-02-28T05:41:01.107801Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] is being suppressed to avoid flooding.
2025-02-28T05:41:01.107933Z DEBUG hyper::proto::h1::io: flushed 75 bytes
2025-02-28T05:41:01.132427Z DEBUG hyper::proto::h1::conn: read eof
2025-02-28T05:41:01.132471Z DEBUG hyper::proto::h1::conn: error shutting down IO: Socket not connected (os error 107)
2025-02-28T05:41:01.132485Z DEBUG hyper::server::server::new_svc: connection error: error shutting down connection: Socket not connected (os error 107)
2025-02-28T05:41:01.132567Z DEBUG hyper::proto::h1::conn: read eof
2025-02-28T05:41:01.132584Z DEBUG hyper::proto::h1::conn: error shutting down IO: Socket not connected (os error 107)
2025-02-28T05:41:01.132590Z DEBUG hyper::server::server::new_svc: connection error: error shutting down connection: Socket not connected (os error 107)
2025-02-28T05:41:02.630770Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.00000006266195445047985
2025-02-28T05:41:02.630869Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.00000003396939700763696
2025-02-28T05:41:02.630889Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.00046719909873673776
2025-02-28T05:41:03.161134Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.00000002909161069744376
2025-02-28T05:41:03.161200Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.000000028856226449980936
2025-02-28T05:41:03.161224Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.0006325687698229273
2025-02-28T05:41:05.835236Z DEBUG hyper::proto::h1::io: parsed 12 headers
2025-02-28T05:41:05.835269Z DEBUG hyper::proto::h1::conn: incoming body is content-length (103 bytes)
2025-02-28T05:41:05.835346Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::internal_events::http: Internal log [Received HTTP request.] has been suppressed 1 times.
2025-02-28T05:41:05.835358Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::internal_events::http: Received HTTP request. internal_log_rate_limit=true
2025-02-28T05:41:05.835407Z DEBUG hyper::proto::h1::conn: incoming body completed
2025-02-28T05:41:05.835476Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: warp::filters::query: route was called without a query string, defaulting to empty
2025-02-28T05:41:05.835491Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::sources::util::http::prelude: Handling HTTP request. headers={"host": "vector.tld:8888", "user-agent": "curl/8.7.1", "content-length": "103", "accept": "*/*", "content-type": "application/x-ndjson", "x-forwarded-for": "10.42.12.0", "x-forwarded-host": "vector.tld:8888", "x-forwarded-port": "8888", "x-forwarded-proto": "http", "x-forwarded-server": "traefik-555c9fc894-r5ndq", "x-real-ip": "10.42.12.0", "accept-encoding": "gzip"}
2025-02-28T05:41:05.835690Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector::utilization: utilization=0.000007797886805428043
2025-02-28T05:41:05.835828Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector::utilization: utilization=0.000013016705738535815
2025-02-28T05:41:05.835869Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] has been suppressed 25 times.
2025-02-28T05:41:05.835873Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Events dropped intentional=true count=1 reason="Events matched filter condition." internal_log_rate_limit=true
2025-02-28T05:41:05.835893Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] is being suppressed to avoid flooding.
{"hostname":"dev-test","kind":"LogEntry","test":1,"timestamp":"2025-02-28T05:41:05.835547468Z"}
2025-02-28T05:41:05.836079Z DEBUG transform{component_kind="transform" component_id=remapped_log_entries component_type=remap}: vector::utilization: utilization=0.0012081890065487322
{"hostname":"dev-test","kind":"LogEntry","test":2,"timestamp":"2025-02-28T05:41:05.835555426Z"}
2025-02-28T05:41:05.836741Z DEBUG hyper::proto::h1::io: flushed 75 bytes
2025-02-28T05:41:06.838371Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: tower::balance::p2c::service: updating from discover
2025-02-28T05:41:06.838509Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: tower::buffer::worker: service.ready=true processing request
2025-02-28T05:41:06.838645Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}:request{request_id=1}:http: vector::internal_events::http_client: Sending HTTP request. uri=https://mcms-es-http.cp-dev.svc.cluster.local:9200/_bulk?timeout=60s method=POST version=HTTP/1.1 headers={"content-type": "application/x-ndjson", "authorization": Sensitive, "accept-encoding": "zstd,gzip,deflate,br", "user-agent": "Vector/0.42.0 (x86_64-unknown-linux-musl 3d16e34 2024-10-21 14:10:14.375255220)"} body=[460 bytes]
2025-02-28T05:41:06.838867Z DEBUG hyper::client::connect::dns: resolving host="mcms-es-http.cp-dev.svc.cluster.local"
2025-02-28T05:41:06.854791Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}:request{request_id=1}:http: hyper::client::connect::http: connecting to 10.43.47.189:9200
2025-02-28T05:41:06.855524Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}:request{request_id=1}:http: hyper::client::connect::http: connected to 10.43.47.189:9200
2025-02-28T05:41:06.863890Z DEBUG hyper::proto::h1::io: flushed 802 bytes
2025-02-28T05:41:06.905893Z DEBUG hyper::proto::h1::io: parsed 3 headers
2025-02-28T05:41:06.905926Z DEBUG hyper::proto::h1::conn: incoming body is chunked encoding
2025-02-28T05:41:06.905961Z DEBUG hyper::proto::h1::decode: incoming chunked header: 0x1E1 (481 bytes)
2025-02-28T05:41:06.906045Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}:request{request_id=1}:http: vector::internal_events::http_client: HTTP response. status=200 OK version=HTTP/1.1 headers={"x-elastic-product": "Elasticsearch", "content-type": "application/json", "transfer-encoding": "chunked"} body=[unknown]
2025-02-28T05:41:06.906144Z DEBUG hyper::proto::h1::conn: incoming body completed
2025-02-28T05:41:06.906193Z DEBUG hyper::client::pool: pooling idle connection for ("https", mcms-es-http.cp-dev.svc.cluster.local:9200)
2025-02-28T05:41:07.132415Z DEBUG hyper::proto::h1::io: parsed 11 headers
2025-02-28T05:41:07.132444Z DEBUG hyper::proto::h1::conn: incoming body is content-length (580 bytes)
2025-02-28T05:41:07.132486Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::internal_events::http: Internal log [Received HTTP request.] is being suppressed to avoid flooding.
2025-02-28T05:41:07.132513Z DEBUG hyper::proto::h1::conn: incoming body completed
2025-02-28T05:41:07.132536Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: warp::filters::query: route was called without a query string, defaulting to empty
2025-02-28T05:41:07.132547Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::sources::util::http::prelude: Handling HTTP request. headers={"host": "vector.tld:8888", "content-length": "580", "accept": "*/*", "content-type": "application/x-ndjson", "x-forwarded-for": "10.42.12.0", "x-forwarded-host": "vector.tld:8888", "x-forwarded-port": "8888", "x-forwarded-proto": "http", "x-forwarded-server": "traefik-555c9fc894-r5ndq", "x-real-ip": "10.42.12.0", "accept-encoding": "gzip"}
2025-02-28T05:41:07.132687Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector::utilization: utilization=0.000032077576651725154
2025-02-28T05:41:07.132765Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector::utilization: utilization=0.000056545882861012895
2025-02-28T05:41:07.132934Z DEBUG hyper::proto::h1::io: flushed 75 bytes
2025-02-28T05:41:07.630711Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.00011236414318682084
2025-02-28T05:41:07.630780Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.000006726877431155867
2025-02-28T05:41:07.630802Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.0005220790890996497
2025-02-28T05:41:08.160292Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.000000009750312015479939
2025-02-28T05:41:08.160336Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.000000030610411909380914
2025-02-28T05:41:08.160352Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.00046517332796512374
2025-02-28T05:41:08.731255Z DEBUG hyper::proto::h1::io: parsed 11 headers
2025-02-28T05:41:08.731296Z DEBUG hyper::proto::h1::conn: incoming body is content-length (289 bytes)
2025-02-28T05:41:08.731370Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::internal_events::http: Internal log [Received HTTP request.] is being suppressed to avoid flooding.
2025-02-28T05:41:08.731431Z DEBUG hyper::proto::h1::conn: incoming body completed
2025-02-28T05:41:08.731470Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: warp::filters::query: route was called without a query string, defaulting to empty
2025-02-28T05:41:08.731493Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::sources::util::http::prelude: Handling HTTP request. headers={"host": "vector.tld:8888", "content-length": "289", "accept": "*/*", "content-type": "application/x-ndjson", "x-forwarded-for": "10.42.12.0", "x-forwarded-host": "vector.tld:8888", "x-forwarded-port": "8888", "x-forwarded-proto": "http", "x-forwarded-server": "traefik-555c9fc894-r5ndq", "x-real-ip": "10.42.12.0", "accept-encoding": "gzip"}
2025-02-28T05:41:08.731725Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] has been suppressed 25 times.
2025-02-28T05:41:08.731743Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector_common::internal_event::component_events_dropped: Events dropped intentional=true count=1 reason="Events matched filter condition." internal_log_rate_limit=true
2025-02-28T05:41:08.731904Z DEBUG hyper::proto::h1::io: flushed 75 bytes
2025-02-28T05:41:11.090820Z DEBUG hyper::proto::h1::io: parsed 11 headers
2025-02-28T05:41:11.090852Z DEBUG hyper::proto::h1::conn: incoming body is content-length (242 bytes)
2025-02-28T05:41:11.091777Z DEBUG hyper::proto::h1::conn: incoming body completed
2025-02-28T05:41:11.091825Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: warp::filters::query: route was called without a query string, defaulting to empty
2025-02-28T05:41:11.091843Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::sources::util::http::prelude: Handling HTTP request. headers={"host": "vector.tld:8888", "content-length": "242", "accept": "*/*", "content-type": "application/x-ndjson", "x-forwarded-for": "10.42.12.0", "x-forwarded-host": "vector.tld:8888", "x-forwarded-port": "8888", "x-forwarded-proto": "http", "x-forwarded-server": "traefik-555c9fc894-r5ndq", "x-real-ip": "10.42.12.0", "accept-encoding": "gzip"}
2025-02-28T05:41:11.093153Z DEBUG hyper::proto::h1::io: flushed 75 bytes
2025-02-28T05:41:12.630538Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.000011264315285618916
2025-02-28T05:41:12.630614Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.0000006989686115970295
2025-02-28T05:41:12.630644Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.0005449127639888942
2025-02-28T05:41:13.161510Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.00000002670876814291704
2025-02-28T05:41:13.161558Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.000000025555545150462884
2025-02-28T05:41:13.161599Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.0004057439925070666
2025-02-28T05:41:16.092342Z DEBUG hyper::proto::h1::io: parsed 11 headers
2025-02-28T05:41:16.092379Z DEBUG hyper::proto::h1::conn: incoming body is content-length (1801 bytes)
2025-02-28T05:41:16.092453Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::internal_events::http: Internal log [Received HTTP request.] has been suppressed 1 times.
2025-02-28T05:41:16.092463Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::internal_events::http: Received HTTP request. internal_log_rate_limit=true
2025-02-28T05:41:16.092504Z DEBUG hyper::proto::h1::conn: incoming body completed
2025-02-28T05:41:16.092541Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: warp::filters::query: route was called without a query string, defaulting to empty
2025-02-28T05:41:16.092557Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::sources::util::http::prelude: Handling HTTP request. headers={"host": "vector.tld:8888", "content-length": "1801", "accept": "*/*", "content-type": "application/x-ndjson", "x-forwarded-for": "10.42.12.0", "x-forwarded-host": "vector.tld:8888", "x-forwarded-port": "8888", "x-forwarded-proto": "http", "x-forwarded-server": "traefik-555c9fc894-r5ndq", "x-real-ip": "10.42.12.0", "accept-encoding": "gzip"}
2025-02-28T05:41:16.092847Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector::utilization: utilization=0.00004032232609059612
2025-02-28T05:41:16.092938Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] is being suppressed to avoid flooding.
2025-02-28T05:41:16.092989Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector::utilization: utilization=0.00004819561346246862
2025-02-28T05:41:16.093030Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] has been suppressed 2 times.
2025-02-28T05:41:16.093036Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Events dropped intentional=true count=1 reason="Events matched filter condition." internal_log_rate_limit=true
2025-02-28T05:41:16.093046Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] is being suppressed to avoid flooding.
2025-02-28T05:41:16.093144Z DEBUG hyper::proto::h1::io: flushed 75 bytes
2025-02-28T05:41:17.630641Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.0000011599108315917731
2025-02-28T05:41:17.630696Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.00000009671642183200056
2025-02-28T05:41:17.630721Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.0005096259768824398
2025-02-28T05:41:18.160681Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.00000003345598527673058
2025-02-28T05:41:18.160736Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.00000003100022933059942
2025-02-28T05:41:18.160753Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.0005696949968227037
2025-02-28T05:41:22.630901Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.00000015000940272046815
2025-02-28T05:41:22.630973Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.00000003649015279545876
2025-02-28T05:41:22.630994Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.0006868079835133507
2025-02-28T05:41:23.160790Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.000000013425376240174738
2025-02-28T05:41:23.160845Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.000000030639422393934076
2025-02-28T05:41:23.160875Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.0004689789787526003

Events not pushed log

2025-02-28T05:44:35.430037Z DEBUG hyper::proto::h1::io: flushed 75 bytes
2025-02-28T05:44:36.739780Z DEBUG hyper::proto::h1::io: parsed 12 headers
2025-02-28T05:44:36.739831Z DEBUG hyper::proto::h1::conn: incoming body is content-length (103 bytes)
2025-02-28T05:44:36.739908Z DEBUG hyper::proto::h1::conn: incoming body completed
2025-02-28T05:44:36.739941Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: warp::filters::query: route was called without a query string, defaulting to empty
2025-02-28T05:44:36.739951Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::sources::util::http::prelude: Handling HTTP request. headers={"host": "vector.tld:8888", "user-agent": "curl/8.7.1", "content-length": "103", "accept": "*/*", "content-type": "application/x-ndjson", "x-forwarded-for": "10.42.12.0", "x-forwarded-host": "vector.tld:8888", "x-forwarded-port": "8888", "x-forwarded-proto": "http", "x-forwarded-server": "traefik-555c9fc894-r5ndq", "x-real-ip": "10.42.12.0", "accept-encoding": "gzip"}
{"hostname":"dev-test","kind":"LogEntry","test":1,"timestamp":"2025-02-28T05:44:36.740002731Z"}
2025-02-28T05:44:36.740467Z DEBUG transform{component_kind="transform" component_id=remapped_log_entries component_type=remap}: vector::utilization: utilization=0.000011138617542814264
{"hostname":"dev-test","kind":"LogEntry","test":2,"timestamp":"2025-02-28T05:44:36.740012928Z"}
2025-02-28T05:44:36.740891Z DEBUG hyper::proto::h1::io: flushed 75 bytes
2025-02-28T05:44:37.630637Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.0001600277932402594
2025-02-28T05:44:37.630689Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.0000009873672765187259
2025-02-28T05:44:37.630704Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.0006667413365345415
2025-02-28T05:44:38.161350Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.000000013894800369577474
2025-02-28T05:44:38.161422Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.00000004002634862257551
2025-02-28T05:44:38.161450Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.0005981025141590489
2025-02-28T05:44:39.440429Z DEBUG hyper::proto::h1::io: parsed 11 headers
2025-02-28T05:44:39.440461Z DEBUG hyper::proto::h1::conn: incoming body is content-length (31567 bytes)
2025-02-28T05:44:39.528568Z DEBUG hyper::proto::h1::conn: incoming body completed
2025-02-28T05:44:39.528663Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: warp::filters::query: route was called without a query string, defaulting to empty
2025-02-28T05:44:39.528681Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::sources::util::http::prelude: Handling HTTP request. headers={"host": "vector.tld:8888", "content-length": "31567", "accept": "*/*", "content-type": "application/x-ndjson", "x-forwarded-for": "10.42.12.0", "x-forwarded-host": "vector.tld:8888", "x-forwarded-port": "8888", "x-forwarded-proto": "http", "x-forwarded-server": "traefik-555c9fc894-r5ndq", "x-real-ip": "10.42.12.0", "accept-encoding": "gzip"}
2025-02-28T05:44:39.529613Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector::utilization: utilization=0.00018223963412680296
2025-02-28T05:44:39.529710Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] has been suppressed 74 times.
2025-02-28T05:44:39.529720Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector_common::internal_event::component_events_dropped: Events dropped intentional=true count=1 reason="Events matched filter condition." internal_log_rate_limit=true
2025-02-28T05:44:39.529802Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] is being suppressed to avoid flooding.
2025-02-28T05:44:39.529968Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector::utilization: utilization=0.00009423062548059668
2025-02-28T05:44:39.530003Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] has been suppressed 74 times.
2025-02-28T05:44:39.530007Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Events dropped intentional=true count=1 reason="Events matched filter condition." internal_log_rate_limit=true
2025-02-28T05:44:39.530018Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] is being suppressed to avoid flooding.
2025-02-28T05:44:39.530227Z DEBUG hyper::proto::h1::io: flushed 75 bytes
2025-02-28T05:44:40.424605Z DEBUG hyper::proto::h1::io: parsed 11 headers
2025-02-28T05:44:40.424646Z DEBUG hyper::proto::h1::conn: incoming body is content-length (21499 bytes)
2025-02-28T05:44:40.424694Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::internal_events::http: Internal log [Received HTTP request.] has been suppressed 2 times.
2025-02-28T05:44:40.424701Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::internal_events::http: Received HTTP request. internal_log_rate_limit=true
2025-02-28T05:44:40.427992Z DEBUG hyper::proto::h1::conn: incoming body completed
2025-02-28T05:44:40.428036Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: warp::filters::query: route was called without a query string, defaulting to empty
2025-02-28T05:44:40.428054Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::sources::util::http::prelude: Handling HTTP request. headers={"host": "vector.tld:8888", "content-length": "21499", "accept": "*/*", "content-type": "application/x-ndjson", "x-forwarded-for": "10.42.12.0", "x-forwarded-host": "vector.tld:8888", "x-forwarded-port": "8888", "x-forwarded-proto": "http", "x-forwarded-server": "traefik-555c9fc894-r5ndq", "x-real-ip": "10.42.12.0", "accept-encoding": "gzip"}
2025-02-28T05:44:40.428818Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector::utilization: utilization=0.00009354003536954741
2025-02-28T05:44:40.428907Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] has been suppressed 11 times.
2025-02-28T05:44:40.428921Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Events dropped intentional=true count=1 reason="Events matched filter condition." internal_log_rate_limit=true
2025-02-28T05:44:40.428936Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] is being suppressed to avoid flooding.
2025-02-28T05:44:40.429180Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector::utilization: utilization=0.00012923457231854725
2025-02-28T05:44:40.429228Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] has been suppressed 9 times.
2025-02-28T05:44:40.429232Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector_common::internal_event::component_events_dropped: Events dropped intentional=true count=1 reason="Events matched filter condition." internal_log_rate_limit=true
2025-02-28T05:44:40.429243Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector_common::internal_event::component_events_dropped: Internal log [Events dropped] is being suppressed to avoid flooding.
2025-02-28T05:44:40.429484Z DEBUG hyper::proto::h1::io: flushed 75 bytes
2025-02-28T05:44:42.630314Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.000016029421052249468
2025-02-28T05:44:42.630387Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.00000010773727136220833
2025-02-28T05:44:42.630404Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.0005253246939769689
2025-02-28T05:44:43.160794Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.000000011830641272565868
2025-02-28T05:44:43.160841Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.00000003532627154671248
2025-02-28T05:44:43.160881Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.0005017877832641637
2025-02-28T05:44:44.444661Z DEBUG hyper::proto::h1::io: parsed 11 headers
2025-02-28T05:44:44.444688Z DEBUG hyper::proto::h1::conn: incoming body is content-length (34650 bytes)
2025-02-28T05:44:44.444742Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::internal_events::http: Internal log [Received HTTP request.] has been suppressed 3 times.
2025-02-28T05:44:44.444749Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::internal_events::http: Received HTTP request. internal_log_rate_limit=true
2025-02-28T05:44:44.532597Z DEBUG hyper::proto::h1::conn: incoming body completed
2025-02-28T05:44:44.532671Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: warp::filters::query: route was called without a query string, defaulting to empty
2025-02-28T05:44:44.532693Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::sources::util::http::prelude: Handling HTTP request. headers={"host": "vector.tld:8888", "content-length": "34650", "accept": "*/*", "content-type": "application/x-ndjson", "x-forwarded-for": "10.42.12.0", "x-forwarded-host": "vector.tld:8888", "x-forwarded-port": "8888", "x-forwarded-proto": "http", "x-forwarded-server": "traefik-555c9fc894-r5ndq", "x-real-ip": "10.42.12.0", "accept-encoding": "gzip"}
2025-02-28T05:44:44.534050Z DEBUG transform{component_kind="transform" component_id=resource_usage component_type=filter}: vector::utilization: utilization=0.000059976753607589116
2025-02-28T05:44:44.534460Z DEBUG transform{component_kind="transform" component_id=log_entries component_type=filter}: vector::utilization: utilization=0.00013218918581022986
2025-02-28T05:44:44.534798Z DEBUG hyper::proto::h1::io: flushed 75 bytes
2025-02-28T05:44:47.631042Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.0000016355173507259895
2025-02-28T05:44:47.631094Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.00000003956965327979746
2025-02-28T05:44:47.631111Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.0005275496143201929
2025-02-28T05:44:48.160332Z DEBUG sink{component_kind="sink" component_id=es_data_stream component_type=elasticsearch}: vector::utilization: utilization=0.000000019184724789382417
2025-02-28T05:44:48.160437Z DEBUG sink{component_kind="sink" component_id=stdout component_type=console}: vector::utilization: utilization=0.000000026214464562949473
2025-02-28T05:44:48.161032Z DEBUG sink{component_kind="sink" component_id=prom_exporter component_type=prometheus_exporter}: vector::utilization: utilization=0.0006252906398818049
2025-02-28T05:44:49.444411Z DEBUG hyper::proto::h1::io: parsed 11 headers
2025-02-28T05:44:49.444470Z DEBUG hyper::proto::h1::conn: incoming body is content-length (36463 bytes)
2025-02-28T05:44:49.444519Z DEBUG source{component_kind="source" component_id=vector_http component_type=http_server}:http-request{method=POST path=/}: vector::internal_events::http: Internal log [Received HTTP request.] is being suppressed to avoid flooding.

But I wasn't able to figure out why the events weren't pushed based on the logs. All I can see is that when they were, the logs show that a connection is established with Elasticsearch and events are sent.

I'm not sure if this is expected behaviour or if there's some issue somewhere (in Vector or somewhere else).

0 replies

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Vector crashes on k8s if the sink goes down #22498

{{title}}

{{editor}}'s edit

{{editor}}'s edit

Replies: 1 comment

{{title}}

Select a reply

Vector crashes on k8s if the sink goes down #22498

rolandjitsu Feb 24, 2025

Replies: 1 comment

rolandjitsu Feb 28, 2025 Author

rolandjitsu
Feb 24, 2025

rolandjitsu
Feb 28, 2025
Author