Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We鈥檒l occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Unifi syslogs to Loki using Vector gives a no details 400 error #20485

Open
tom-dell opened this issue May 13, 2024 · 4 comments
Open

Unifi syslogs to Loki using Vector gives a no details 400 error #20485

tom-dell opened this issue May 13, 2024 · 4 comments
Labels
domain: observability Anything related to monitoring/observing Vector meta: awaiting author Pull requests that are awaiting their author. sink: loki Anything `loki` sink related type: bug A code related bug.

Comments

@tom-dell
Copy link

A note for the community

  • Please vote on this issue by adding a 馃憤 reaction to the original issue to help the community and maintainers prioritize this request
  • If you are interested in working on this issue or have submitted a pull request, please leave a comment

Problem

Hello, I'm getting some weird 400 errors from Loki when I'm trying to push my unifi logs through using Vector

you can see a syslog come in on line 59, then Vector gets a 400 from Loki, and drops the request, I cannot find any additional logs with anymore details.

Configuration

sources:
  unifi:
    type: syslog
    address: 0.0.0.0:514
    mode: udp
    path: /tmp/unifi_syslog_udp

sinks:
  loki_unifi:
    type: loki
    inputs:
      - unifi
    endpoint: "http://192.168.1.21:3100"
    encoding:
      codec: "json"
    labels:
      table: "unifi"
    out_of_order_action: rewrite_timestamp

  console_unifi:
    type: console
    inputs:
      - unifi
    encoding:
      codec: "json"

Version

timberio/vector:0.38.0-debian

Debug Output

2024-05-12T22:59:30.278529Z DEBUG vector::app: Internal log rate limit configured. internal_log_rate_secs=10
2024-05-12T22:59:30.317719Z  INFO vector::app: Log level is enabled. level="trace"
2024-05-12T22:59:30.318034Z DEBUG vector::app: messaged="Building runtime." worker_threads=4
2024-05-12T22:59:30.318177Z TRACE mio::poll: registering event source with poller: token=Token(1), interests=READABLE
2024-05-12T22:59:30.415262Z  INFO vector::app: Loading configs. paths=["/etc/vector/vector.yaml"]
2024-05-12T22:59:30.459035Z DEBUG vector::config::loading: No secret placeholder found, skipping secret resolution.
2024-05-12T22:59:30.476658Z DEBUG vector::topology::builder: Building new source. component=unifi
2024-05-12T22:59:30.476943Z DEBUG vector::topology::builder: Building new sink. component=console_unifi
2024-05-12T22:59:30.477114Z DEBUG vector::topology::builder: Building new sink. component=loki_unifi
2024-05-12T22:59:30.689341Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector_core::tls::settings: Fetching system root certs.
2024-05-12T22:59:30.703195Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector_core::tls::settings: Fetching system root certs.
2024-05-12T22:59:30.717611Z  INFO vector::topology::running: Running healthchecks.
2024-05-12T22:59:30.717644Z DEBUG vector::topology::running: Connecting changed/added component(s).
2024-05-12T22:59:30.717657Z DEBUG vector::topology::running: Configuring outputs for source. component=unifi
2024-05-12T22:59:30.717670Z DEBUG vector::topology::running: Configuring output for component. component=unifi output_id=None
2024-05-12T22:59:30.717681Z DEBUG vector::topology::running: Connecting inputs for sink. component=loki_unifi
2024-05-12T22:59:30.717737Z DEBUG vector::topology::running: Adding component input to fanout. component=console_unifi fanout_id=unifi
2024-05-12T22:59:30.717761Z DEBUG vector::topology::running: Spawning new source. key=unifi
2024-05-12T22:59:30.717805Z TRACE vector::topology::running: Spawning new sink. key=loki_unifi
2024-05-12T22:59:30.717832Z TRACE vector::topology::running: Spawning new sink. key=console_unifi
2024-05-12T22:59:30.717903Z  INFO vector: Vector has started. debug="false" version="0.38.0" arch="x86_64" revision="ea0ec6f 2024-05-07 14:34:39.794027186"
2024-05-12T22:59:30.718081Z TRACE http: hyper::client::pool: checkout waiting for idle connection: ("http", 192.168.1.21:3100)
2024-05-12T22:59:30.718139Z TRACE http: hyper::client::connect::http: Http::connect; scheme=Some("http"), host=Some("192.168.1.21"), port=Some(Port(3100))
2024-05-12T22:59:30.718174Z DEBUG http: hyper::client::connect::http: connecting to 192.168.1.21:3100
2024-05-12T22:59:30.718352Z TRACE http: mio::poll: registering event source with poller: token=Token(140483457188224), interests=READABLE | WRITABLE
2024-05-12T22:59:30.718399Z  INFO vector::topology::builder: Healthcheck passed.
2024-05-12T22:59:30.718417Z DEBUG source{component_kind="source" component_id=unifi component_type=syslog}: vector::topology::builder: Source pump supervisor starting.
2024-05-12T22:59:30.718446Z DEBUG source{component_kind="source" component_id=unifi component_type=syslog}: vector::topology::builder: Source pump starting.
2024-05-12T22:59:30.718563Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: mio::poll: registering event source with poller: token=Token(140483457188480), interests=READABLE | WRITABLE
2024-05-12T22:59:30.718577Z  INFO source{component_kind="source" component_id=unifi component_type=syslog}: vector::sources::syslog: Listening. addr=0.0.0.0:514 type="udp"
2024-05-12T22:59:30.718633Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector::topology::builder: Sink starting.
2024-05-12T22:59:30.718836Z DEBUG sink{component_kind="sink" component_id=console_unifi component_type=console}: vector::topology::builder: Sink starting.
2024-05-12T22:59:30.719022Z DEBUG http: hyper::client::connect::http: connected to 192.168.1.21:3100
2024-05-12T22:59:30.719137Z TRACE http: hyper::client::conn: client handshake Http1
2024-05-12T22:59:30.719193Z TRACE http: hyper::client::client: handshake complete, spawning background dispatcher task
2024-05-12T22:59:30.719256Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Busy }
2024-05-12T22:59:30.719294Z TRACE http: hyper::client::pool: checkout dropped for ("http", 192.168.1.21:3100)
2024-05-12T22:59:30.719397Z TRACE encode_headers: hyper::proto::h1::role: Client::encode method=GET, body=None
2024-05-12T22:59:30.719527Z DEBUG hyper::proto::h1::io: flushed 167 bytes
2024-05-12T22:59:30.719577Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Init, writing: KeepAlive, keep_alive: Busy }
2024-05-12T22:59:30.720057Z TRACE vector: Beep.
2024-05-12T22:59:30.720090Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector::utilization: utilization=0.05356751781818381
2024-05-12T22:59:30.720143Z TRACE hyper::proto::h1::conn: Conn::read_head
2024-05-12T22:59:30.720247Z TRACE hyper::proto::h1::conn: maybe_notify; read_from_io blocked
2024-05-12T22:59:30.720254Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Idle }
2024-05-12T22:59:30.721478Z TRACE hyper::client::pool: idle interval checking for expired
2024-05-12T22:59:31.719805Z TRACE vector: Beep.
2024-05-12T22:59:32.720138Z TRACE vector: Beep.
2024-05-12T22:59:33.719503Z TRACE vector: Beep.
2024-05-12T22:59:34.720107Z TRACE vector: Beep.
2024-05-12T22:59:35.720103Z TRACE vector: Beep.
2024-05-12T22:59:35.720144Z DEBUG sink{component_kind="sink" component_id=console_unifi component_type=console}: vector::utilization: utilization=0.0012365200366178826
2024-05-12T22:59:35.720170Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector::utilization: utilization=0.005356785981275246
2024-05-12T22:59:36.720528Z TRACE vector: Beep.
2024-05-12T22:59:37.719599Z TRACE vector: Beep.
2024-05-12T22:59:37.797343Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector::sources::syslog: Processing one event. event=Log(LogEvent { inner: Inner { fields: Object({KeyString("appname"): Bytes(b"e43883e2c9a4,U6+-6.6.65+15248"), KeyString("facility"): Bytes(b"daemon"), KeyString("host"): Bytes(b"AccessPointWiFi6-Plus"), KeyString("hostname"): Bytes(b"AccessPointWiFi6-Plus"), KeyString("message"): Bytes(b"stahtd: stahtd[2831]: [STA-TRACKER].stahtd_dump_event(): {\"message_type\":\"STA_ASSOC_TRACKER\",\"mac\":\"14:c1:4e:bf:15:b8\",\"vap\":\"ra0\",\"event_type\":\"fixup\",\"assoc_status\":\"0\",\"event_id\":\"5\",\"arp_reply_gw_seen\":\"yes\",\"dns_resp_seen\":\"yes\",\"avg_rssi\":\"-79\"}"), KeyString("severity"): Bytes(b"info"), KeyString("source_ip"): Bytes(b"172.23.0.1"), KeyString("source_type"): Bytes(b"syslog"), KeyString("timestamp"): Timestamp(2024-05-13T08:59:37Z)}), size_cache: AtomicCell { value: None }, json_encoded_size_cache: AtomicCell { value: None } }, metadata: EventMetadata { value: Object({}), secrets: {}, finalizers: EventFinalizers([]), source_id: None, source_type: None, upstream_id: None, schema_definition: Definition { event_kind: Kind { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), undefined: Some(()), array: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }), object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, metadata_kind: Kind { bytes: None, integer: None, float: None, boolean: None, timestamp: None, regex: None, null: None, undefined: None, array: None, object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, meaning: {}, log_namespaces: {Vector, Legacy} }, dropped_fields: {}, datadog_origin_metadata: None } })
2024-05-12T22:59:37.797506Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector_buffers::topology::channel::limited_queue: Sent item.
2024-05-12T22:59:37.797519Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector_common::internal_event::events_sent: Events sent. count=1 byte_size=496 output=_default
{"appname":"e43883e2c9a4,U6+-6.6.65+15248","facility":"daemon","host":"AccessPointWiFi6-Plus","hostname":"AccessPointWiFi6-Plus","message":"stahtd: stahtd[2831]: [STA-TRACKER].stahtd_dump_event(): {\"message_type\":\"STA_ASSOC_TRACKER\",\"mac\":\"14:c8\",\"vap\":\"ra0\",\"event_type\":\"fixup\",\"assoc_status\":\"0\",\"event_id\":\"5\",\"arp_reply_gw_seen\":\"yes\",\"dns_resp_seen\":\"yes\",\"avg_rssi\":\"-79\"}","severity":"info","source_ip":"172.23.0.1","source_type":"syslog","timestamp":"2024-05-13T08:59:37Z"}
2024-05-12T22:59:38.719590Z TRACE vector: Beep.
2024-05-12T22:59:38.800006Z TRACE sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector_stream::driver: Submitting service request. in_flight_requests=0 request_id=1
2024-05-12T22:59:38.800105Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=1}:http: vector::internal_events::http_client: Sending HTTP request. uri=http://192.168.1.21:3100/loki/api/v1/push method=POST version=HTTP/1.1 headers={"content-type": "application/x-protobuf", "content-encoding": "snappy", "user-agent": "Vector/0.38.0 (x86_64-unknown-linux-gnu ea0ec6f 2024-05-07 14:34:39.794027186)", "accept-encoding": "identity"} body=[424 bytes]
2024-05-12T22:59:38.800185Z TRACE sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=1}:http: hyper::client::pool: take? ("http", 192.168.1.21:3100): expiration = Some(90s)
2024-05-12T22:59:38.801836Z ERROR sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=1}: vector::sinks::util::retries: Non-retriable error; dropping the request. error=Server responded with an error: 400 Bad Request internal_log_rate_limit=true
2024-05-12T22:59:38.801869Z ERROR sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=1}: vector_common::internal_event::service: Service call failed. No retries or retries exhausted. error=Some(ServerError { code: 400 }) request_id=1 error_type="request_failed" stage="sending" internal_log_rate_limit=true
2024-05-12T22:59:38.801888Z ERROR sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=1}: vector_common::internal_event::component_events_dropped: Events dropped intentional=false count=1 reason="Service call failed. No retries or retries exhausted." internal_log_rate_limit=true
2024-05-12T22:59:38.801915Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Idle }
2024-05-12T22:59:39.719945Z TRACE vector: Beep.
2024-05-12T22:59:40.720312Z TRACE vector: Beep.
2024-05-12T22:59:40.720357Z DEBUG sink{component_kind="sink" component_id=console_unifi component_type=console}: vector::utilization: utilization=0.00017260668958881558
2024-05-12T22:59:41.719700Z TRACE vector: Beep.
2024-05-12T22:59:42.719647Z TRACE vector: Beep.
2024-05-12T22:59:43.719569Z TRACE vector: Beep.
2024-05-12T22:59:44.719496Z TRACE vector: Beep.
2024-05-12T22:59:45.719817Z TRACE vector: Beep.
2024-05-12T22:59:45.719916Z DEBUG sink{component_kind="sink" component_id=console_unifi component_type=console}: vector::utilization: utilization=0.000017324754649835506
2024-05-12T22:59:45.719982Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector::utilization: utilization=0.00005549931272132256
2024-05-12T22:59:46.719572Z TRACE vector: Beep.
2024-05-12T22:59:47.720296Z TRACE vector: Beep.
2024-05-12T22:59:48.720026Z TRACE vector: Beep.
2024-05-12T22:59:49.720285Z TRACE vector: Beep.
2024-05-12T22:59:50.720116Z TRACE vector: Beep.
2024-05-12T22:59:50.720166Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector::utilization: utilization=0.000005644966883212962
2024-05-12T22:59:50.720211Z DEBUG sink{component_kind="sink" component_id=console_unifi component_type=console}: vector::utilization: utilization=0.0000017666734061624207
2024-05-12T22:59:51.719634Z TRACE vector: Beep.
2024-05-12T22:59:52.719414Z TRACE vector: Beep.
2024-05-12T22:59:53.720004Z TRACE vector: Beep.
2024-05-12T22:59:54.719370Z TRACE vector: Beep.
2024-05-12T22:59:55.719511Z TRACE vector: Beep.
2024-05-12T22:59:55.719596Z DEBUG sink{component_kind="sink" component_id=console_unifi component_type=console}: vector::utilization: utilization=0.00000021231202741841407
2024-05-12T22:59:55.719553Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector::utilization: utilization=0.0000006210236251526321
2024-05-12T22:59:56.719763Z TRACE vector: Beep.
2024-05-12T22:59:57.720051Z TRACE vector: Beep.
2024-05-12T22:59:58.720318Z TRACE vector: Beep.
2024-05-12T22:59:59.719633Z TRACE vector: Beep.
2024-05-12T23:00:00.720045Z TRACE vector: Beep.
2024-05-12T23:00:00.720086Z DEBUG sink{component_kind="sink" component_id=console_unifi component_type=console}: vector::utilization: utilization=0.00000010024281709304015
2024-05-12T23:00:00.720150Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector::utilization: utilization=0.00000015047177540252017
2024-05-12T23:00:01.719402Z TRACE vector: Beep.
2024-05-12T23:00:02.719502Z TRACE vector: Beep.
2024-05-12T23:00:03.679146Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector::sources::syslog: Processing one event. event=Log(LogEvent { inner: Inner { fields: Object({KeyString("appname"): Bytes(b"e43883e2c9a4,U6+-6.6.65+15248"), KeyString("facility"): Bytes(b"kern"), KeyString("host"): Bytes(b"AccessPointWiFi6-Plus"), KeyString("hostname"): Bytes(b"AccessPointWiFi6-Plus"), KeyString("message"): Bytes(b"kernel: [365762.786399] [keep-alive]: ca:62:c6:6e:aa:a1 slient for 60-sec, Enqueue NULL pkt for AID=17, STA_PS Mode=1"), KeyString("severity"): Bytes(b"debug"), KeyString("source_ip"): Bytes(b"172.23.0.1"), KeyString("source_type"): Bytes(b"syslog"), KeyString("timestamp"): Timestamp(2024-05-13T09:00:03Z)}), size_cache: AtomicCell { value: None }, json_encoded_size_cache: AtomicCell { value: None } }, metadata: EventMetadata { value: Object({}), secrets: {}, finalizers: EventFinalizers([]), source_id: None, source_type: None, upstream_id: None, schema_definition: Definition { event_kind: Kind { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), undefined: Some(()), array: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }), object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, metadata_kind: Kind { bytes: None, integer: None, float: None, boolean: None, timestamp: None, regex: None, null: None, undefined: None, array: None, object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, meaning: {}, log_namespaces: {Vector, Legacy} }, dropped_fields: {}, datadog_origin_metadata: None } })
2024-05-12T23:00:03.679253Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector_buffers::topology::channel::limited_queue: Sent item.
2024-05-12T23:00:03.679285Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector_common::internal_event::events_sent: Events sent. count=1 byte_size=361 output=_default
{"appname":"e43883e2c9a4,U6+-6.6.65+15248","facility":"kern","host":"AccessPointWiFi6-Plus","hostname":"AccessPointWiFi6-Plus","message":"kernel: [365762.786399] [keep-alive]: ca:62:c6:6e:aa:a1 slient for 60-sec, Enqueue NULL pkt for AID=17, STA_PS Mode=1","severity":"debug","source_ip":"172.23.0.1","source_type":"syslog","timestamp":"2024-05-13T09:00:03Z"}
2024-05-12T23:00:03.679336Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector_buffers::topology::channel::limited_queue: Sent item.
2024-05-12T23:00:03.679354Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector_buffers::topology::channel::limited_queue: Sent item.
2024-05-12T23:00:03.719641Z TRACE vector: Beep.
2024-05-12T23:00:04.681060Z TRACE sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector_stream::driver: Submitting service request. in_flight_requests=0 request_id=2
2024-05-12T23:00:04.681143Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=2}:http: vector::internal_events::http_client: Sending HTTP request. uri=http://192.168.1.21:3100/loki/api/v1/push method=POST version=HTTP/1.1 headers={"content-type": "application/x-protobuf", "content-encoding": "snappy", "user-agent": "Vector/0.38.0 (x86_64-unknown-linux-gnu ea0ec6f 2024-05-07 14:34:39.794027186)", "accept-encoding": "identity"} body=[325 bytes]
2024-05-12T23:00:04.681198Z TRACE sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=2}:http: hyper::client::pool: take? ("http", 192.168.1.21:3100): expiration = Some(90s)
2024-05-12T23:00:04.682924Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Idle }
2024-05-12T23:00:04.682962Z TRACE sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=2}:http: hyper::client::pool: put; add idle connection for ("http", 192.168.1.21:3100)
2024-05-12T23:00:04.682976Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=2}:http: hyper::client::pool: pooling idle connection for ("http", 192.168.1.21:3100)
2024-05-12T23:00:04.682988Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=2}:http: vector::internal_events::http_client: HTTP response. status=400 Bad Request version=HTTP/1.1 headers={"content-type": "text/plain; charset=utf-8", "x-content-type-options": "nosniff", "date": "Sun, 12 May 2024 23:00:04 GMT", "content-length": "79"} body=[79 bytes]
2024-05-12T23:00:04.683045Z ERROR sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=2}: vector::sinks::util::retries: Non-retriable error; dropping the request. error=Server responded with an error: 400 Bad Request internal_log_rate_limit=true
2024-05-12T23:00:04.683065Z ERROR sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=2}: vector_common::internal_event::service: Service call failed. No retries or retries exhausted. error=Some(ServerError { code: 400 }) request_id=2 error_type="request_failed" stage="sending" internal_log_rate_limit=true
2024-05-12T23:00:04.683083Z ERROR sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=2}: vector_common::internal_event::component_events_dropped: Events dropped intentional=false count=1 reason="Service call failed. No retries or retries exhausted." internal_log_rate_limit=true
2024-05-12T23:00:04.683110Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Idle }
2024-05-12T23:00:04.720263Z TRACE vector: Beep.
2024-05-12T23:00:05.719622Z TRACE vector: Beep.
2024-05-12T23:00:05.719663Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector::utilization: utilization=0.000008972898717277301
2024-05-12T23:00:05.719663Z DEBUG sink{component_kind="sink" component_id=console_unifi component_type=console}: vector::utilization: utilization=0.000018790475057233343
2024-05-12T23:00:06.719973Z TRACE vector: Beep.
2024-05-12T23:00:07.719422Z TRACE vector: Beep.
2024-05-12T23:00:08.719887Z TRACE vector: Beep.
2024-05-12T23:00:09.719398Z TRACE vector: Beep.
2024-05-12T23:00:10.060202Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector::sources::syslog: Processing one event. event=Log(LogEvent { inner: Inner { fields: Object({KeyString("appname"): Bytes(b"DreamMachinePro"), KeyString("facility"): Bytes(b"syslog"), KeyString("host"): Bytes(b"DreamMachinePro"), KeyString("hostname"): Bytes(b"DreamMachinePro"), KeyString("message"): Bytes(b"syslog-ng[3140281]: Syslog connection broken; fd='12', server='AF_INET(192.168.1.21:514)', time_reopen='60'"), KeyString("severity"): Bytes(b"notice"), KeyString("source_ip"): Bytes(b"172.23.0.1"), KeyString("source_type"): Bytes(b"syslog"), KeyString("timestamp"): Timestamp(2024-05-13T08:59:10Z)}), size_cache: AtomicCell { value: None }, json_encoded_size_cache: AtomicCell { value: None } }, metadata: EventMetadata { value: Object({}), secrets: {}, finalizers: EventFinalizers([]), source_id: None, source_type: None, upstream_id: None, schema_definition: Definition { event_kind: Kind { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), undefined: Some(()), array: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }), object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, metadata_kind: Kind { bytes: None, integer: None, float: None, boolean: None, timestamp: None, regex: None, null: None, undefined: None, array: None, object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, meaning: {}, log_namespaces: {Vector, Legacy} }, dropped_fields: {}, datadog_origin_metadata: None } })
2024-05-12T23:00:10.060324Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector::sources::syslog: Processing one event. event=Log(LogEvent { inner: Inner { fields: Object({KeyString("appname"): Bytes(b"DreamMachinePro"), KeyString("facility"): Bytes(b"daemon"), KeyString("host"): Bytes(b"DreamMachinePro"), KeyString("hostname"): Bytes(b"DreamMachinePro"), KeyString("message"): Bytes(b"earlyoom[1575]: mem avail:  1043 of  3946 MiB (26.45%), swap free: 3648 of 4095 MiB (89.09%)"), KeyString("severity"): Bytes(b"info"), KeyString("source_ip"): Bytes(b"172.23.0.1"), KeyString("source_type"): Bytes(b"syslog"), KeyString("timestamp"): Timestamp(2024-05-13T08:59:40Z)}), size_cache: AtomicCell { value: None }, json_encoded_size_cache: AtomicCell { value: None } }, metadata: EventMetadata { value: Object({}), secrets: {}, finalizers: EventFinalizers([]), source_id: None, source_type: None, upstream_id: None, schema_definition: Definition { event_kind: Kind { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), undefined: Some(()), array: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }), object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, metadata_kind: Kind { bytes: None, integer: None, float: None, boolean: None, timestamp: None, regex: None, null: None, undefined: None, array: None, object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, meaning: {}, log_namespaces: {Vector, Legacy} }, dropped_fields: {}, datadog_origin_metadata: None } })
{"appname":"DreamMachinePro","facility":"syslog","host":"DreamMachinePro","hostname":"DreamMachinePro","message":"syslog-ng[3140281]: Syslog connection broken; fd='12', server='AF_INET(192.168.1.21:514)', time_reopen='60'","severity":"notice","source_ip":"172.23.0.1","source_type":"syslog","timestamp":"2024-05-13T08:59:10Z"}
{"appname":"DreamMachinePro","facility":"daemon","host":"DreamMachinePro","hostname":"DreamMachinePro","message":"earlyoom[1575]: mem avail:  1043 of  3946 MiB (26.45%), swap free: 3648 of 4095 MiB (89.09%)","severity":"info","source_ip":"172.23.0.1","source_type":"syslog","timestamp":"2024-05-13T08:59:40Z"}
{"appname":"DreamMachinePro","facility":"daemon","host":"DreamMachinePro","hostname":"DreamMachinePro","message":"systemd[1]: Starting system activity accounting tool...","severity":"info","source_ip":"172.23.0.1","source_type":"syslog","timestamp":"2024-05-13T09:00:00Z"}
{"appname":"DreamMachinePro","facility":"daemon","host":"DreamMachinePro","hostname":"DreamMachinePro","message":"systemd[1]: sysstat-collect.service: Succeeded.","severity":"info","source_ip":"172.23.0.1","source_type":"syslog","timestamp":"2024-05-13T09:00:00Z"}
{"appname":"DreamMachinePro","facility":"daemon","host":"DreamMachinePro","hostname":"DreamMachinePro","message":"systemd[1]: Finished system activity accounting tool.","severity":"info","source_ip":"172.23.0.1","source_type":"syslog","timestamp":"2024-05-13T09:00:00Z"}
{"appname":"","facility":"user","host":"DreamMachinePro","hostname":"DreamMachinePro","message":"DESCR=\"PortForward DNAT [NginxProxyManager\" IN=eth8 OUT= MAC=e42:08:00 SRC=179.43.188.110 DST=1444 LEN=40 TOS=00 PREC=0x00 TTL=241 ID=54321 PROTO=TCP SPT=57094 DPT=80 SEQ=3851167188 ACK=0 WINDOW=65535 SYN URGP=0 MARK=1a0000","procid":"PREROUTING-DNAT-3","severity":"notice","source_ip":"172.23.0.1","source_type":"syslog","timestamp":"2024-05-13T09:00:00Z"}
{"appname":"","facility":"user","host":"DreamMachinePro","hostname":"DreamMachinePro","message":"DESCR=\"[WAN_IN]Allow Port Forward {NginxPro\" IN=eth8 OUT=br0 MAC=e4::c2:08:00 SRC=1710 DST=192.168.1.21 LEN=40 TOS=00 PREC=0x00 TTL=240 ID=54321 PROTO=TCP SPT=57094 DPT=8081 SEQ=3851167188 ACK=0 WINDOW=65535 SYN URGP=0 MARK=1a0000","procid":"WAN_IN-RET-30005","severity":"notice","source_ip":"172.23.0.1","source_type":"syslog","timestamp":"2024-05-13T09:00:00Z"}
{"appname":"DreamMachinePro","facility":"syslog","host":"DreamMachinePro","hostname":"DreamMachinePro","message":"syslog-ng[3140281]: Syslog connection established; fd='24', server='AF_INET(192.168.1.21:514)', local='AF_INET(0.0.0.0:0)'","severity":"notice","source_ip":"172.23.0.1","source_type":"syslog","timestamp":"2024-05-13T09:00:10Z"}
2024-05-12T23:00:10.060366Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector::sources::syslog: Processing one event. event=Log(LogEvent { inner: Inner { fields: Object({KeyString("appname"): Bytes(b"DreamMachinePro"), KeyString("facility"): Bytes(b"daemon"), KeyString("host"): Bytes(b"DreamMachinePro"), KeyString("hostname"): Bytes(b"DreamMachinePro"), KeyString("message"): Bytes(b"systemd[1]: Starting system activity accounting tool..."), KeyString("severity"): Bytes(b"info"), KeyString("source_ip"): Bytes(b"172.23.0.1"), KeyString("source_type"): Bytes(b"syslog"), KeyString("timestamp"): Timestamp(2024-05-13T09:00:00Z)}), size_cache: AtomicCell { value: None }, json_encoded_size_cache: AtomicCell { value: None } }, metadata: EventMetadata { value: Object({}), secrets: {}, finalizers: EventFinalizers([]), source_id: None, source_type: None, upstream_id: None, schema_definition: Definition { event_kind: Kind { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), undefined: Some(()), array: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }), object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, metadata_kind: Kind { bytes: None, integer: None, float: None, boolean: None, timestamp: None, regex: None, null: None, undefined: None, array: None, object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, meaning: {}, log_namespaces: {Vector, Legacy} }, dropped_fields: {}, datadog_origin_metadata: None } })
2024-05-12T23:00:10.060428Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector::sources::syslog: Processing one event. event=Log(LogEvent { inner: Inner { fields: Object({KeyString("appname"): Bytes(b"DreamMachinePro"), KeyString("facility"): Bytes(b"daemon"), KeyString("host"): Bytes(b"DreamMachinePro"), KeyString("hostname"): Bytes(b"DreamMachinePro"), KeyString("message"): Bytes(b"systemd[1]: sysstat-collect.service: Succeeded."), KeyString("severity"): Bytes(b"info"), KeyString("source_ip"): Bytes(b"172.23.0.1"), KeyString("source_type"): Bytes(b"syslog"), KeyString("timestamp"): Timestamp(2024-05-13T09:00:00Z)}), size_cache: AtomicCell { value: None }, json_encoded_size_cache: AtomicCell { value: None } }, metadata: EventMetadata { value: Object({}), secrets: {}, finalizers: EventFinalizers([]), source_id: None, source_type: None, upstream_id: None, schema_definition: Definition { event_kind: Kind { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), undefined: Some(()), array: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }), object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, metadata_kind: Kind { bytes: None, integer: None, float: None, boolean: None, timestamp: None, regex: None, null: None, undefined: None, array: None, object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, meaning: {}, log_namespaces: {Vector, Legacy} }, dropped_fields: {}, datadog_origin_metadata: None } })
2024-05-12T23:00:10.060475Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector::sources::syslog: Processing one event. event=Log(LogEvent { inner: Inner { fields: Object({KeyString("appname"): Bytes(b"DreamMachinePro"), KeyString("facility"): Bytes(b"daemon"), KeyString("host"): Bytes(b"DreamMachinePro"), KeyString("hostname"): Bytes(b"DreamMachinePro"), KeyString("message"): Bytes(b"systemd[1]: Finished system activity accounting tool."), KeyString("severity"): Bytes(b"info"), KeyString("source_ip"): Bytes(b"172.23.0.1"), KeyString("source_type"): Bytes(b"syslog"), KeyString("timestamp"): Timestamp(2024-05-13T09:00:00Z)}), size_cache: AtomicCell { value: None }, json_encoded_size_cache: AtomicCell { value: None } }, metadata: EventMetadata { value: Object({}), secrets: {}, finalizers: EventFinalizers([]), source_id: None, source_type: None, upstream_id: None, schema_definition: Definition { event_kind: Kind { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), undefined: Some(()), array: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }), object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, metadata_kind: Kind { bytes: None, integer: None, float: None, boolean: None, timestamp: None, regex: None, null: None, undefined: None, array: None, object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, meaning: {}, log_namespaces: {Vector, Legacy} }, dropped_fields: {}, datadog_origin_metadata: None } })
2024-05-12T23:00:10.060522Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector::sources::syslog: Processing one event. event=Log(LogEvent { inner: Inner { fields: Object({KeyString("appname"): Bytes(b""), KeyString("facility"): Bytes(b"user"), KeyString("host"): Bytes(b"DreamMachinePro"), KeyString("hostname"): Bytes(b"DreamMachinePro"), KeyString("message"): Bytes(b"DESCR=\"PortForward DNAT [NginxProxyManager\" IN=eth8 OUT= MAC=e4:38c2:08:00 SRC=179.43.188.110 DST=144.6.74.244 LEN=40 TOS=00 PREC=0x00 TTL=241 ID=54321 PROTO=TCP SPT=57094 DPT=80 SEQ=3851167188 ACK=0 WINDOW=65535 SYN URGP=0 MARK=1a0000"), KeyString("procid"): Bytes(b"PREROUTING-DNAT-3"), KeyString("severity"): Bytes(b"notice"), KeyString("source_ip"): Bytes(b"172.23.0.1"), KeyString("source_type"): Bytes(b"syslog"), KeyString("timestamp"): Timestamp(2024-05-13T09:00:00Z)}), size_cache: AtomicCell { value: None }, json_encoded_size_cache: AtomicCell { value: None } }, metadata: EventMetadata { value: Object({}), secrets: {}, finalizers: EventFinalizers([]), source_id: None, source_type: None, upstream_id: None, schema_definition: Definition { event_kind: Kind { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), undefined: Some(()), array: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }), object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, metadata_kind: Kind { bytes: None, integer: None, float: None, boolean: None, timestamp: None, regex: None, null: None, undefined: None, array: None, object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, meaning: {}, log_namespaces: {Vector, Legacy} }, dropped_fields: {}, datadog_origin_metadata: None } })
2024-05-12T23:00:10.060571Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector::sources::syslog: Processing one event. event=Log(LogEvent { inner: Inner { fields: Object({KeyString("appname"): Bytes(b""), KeyString("facility"): Bytes(b"user"), KeyString("host"): Bytes(b"DreamMachinePro"), KeyString("hostname"): Bytes(b"DreamMachinePro"), KeyString("message"): Bytes(b"DESCR=\"[WAN_IN]Allow Port Forward {NginxPro\" IN=eth8 OUT=br0 MAC=e4:8:00 SRC=179.43.188.110 DST=192.168.1.21 LEN=40 TOS=00 PREC=0x00 TTL=240 ID=54321 PROTO=TCP SPT=57094 DPT=8081 SEQ=3851167188 ACK=0 WINDOW=65535 SYN URGP=0 MARK=1a0000"), KeyString("procid"): Bytes(b"WAN_IN-RET-30005"), KeyString("severity"): Bytes(b"notice"), KeyString("source_ip"): Bytes(b"172.23.0.1"), KeyString("source_type"): Bytes(b"syslog"), KeyString("timestamp"): Timestamp(2024-05-13T09:00:00Z)}), size_cache: AtomicCell { value: None }, json_encoded_size_cache: AtomicCell { value: None } }, metadata: EventMetadata { value: Object({}), secrets: {}, finalizers: EventFinalizers([]), source_id: None, source_type: None, upstream_id: None, schema_definition: Definition { event_kind: Kind { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), undefined: Some(()), array: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }), object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, metadata_kind: Kind { bytes: None, integer: None, float: None, boolean: None, timestamp: None, regex: None, null: None, undefined: None, array: None, object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, meaning: {}, log_namespaces: {Vector, Legacy} }, dropped_fields: {}, datadog_origin_metadata: None } })
2024-05-12T23:00:10.060617Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector::sources::syslog: Processing one event. event=Log(LogEvent { inner: Inner { fields: Object({KeyString("appname"): Bytes(b"DreamMachinePro"), KeyString("facility"): Bytes(b"syslog"), KeyString("host"): Bytes(b"DreamMachinePro"), KeyString("hostname"): Bytes(b"DreamMachinePro"), KeyString("message"): Bytes(b"syslog-ng[3140281]: Syslog connection established; fd='24', server='AF_INET(192.168.1.21:514)', local='AF_INET(0.0.0.0:0)'"), KeyString("severity"): Bytes(b"notice"), KeyString("source_ip"): Bytes(b"172.23.0.1"), KeyString("source_type"): Bytes(b"syslog"), KeyString("timestamp"): Timestamp(2024-05-13T09:00:10Z)}), size_cache: AtomicCell { value: None }, json_encoded_size_cache: AtomicCell { value: None } }, metadata: EventMetadata { value: Object({}), secrets: {}, finalizers: EventFinalizers([]), source_id: None, source_type: None, upstream_id: None, schema_definition: Definition { event_kind: Kind { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), undefined: Some(()), array: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }), object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, metadata_kind: Kind { bytes: None, integer: None, float: None, boolean: None, timestamp: None, regex: None, null: None, undefined: None, array: None, object: Some(Collection { known: {}, unknown: Unknown(Infinite(Infinite { bytes: Some(()), integer: Some(()), float: Some(()), boolean: Some(()), timestamp: Some(()), regex: Some(()), null: Some(()), array: Some(()), object: Some(()) })) }) }, meaning: {}, log_namespaces: {Vector, Legacy} }, dropped_fields: {}, datadog_origin_metadata: None } })
2024-05-12T23:00:10.060693Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector_buffers::topology::channel::limited_queue: Sent item.
2024-05-12T23:00:10.060704Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector_common::internal_event::events_sent: Events sent. count=8 byte_size=2784 output=_default
2024-05-12T23:00:10.060754Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector_buffers::topology::channel::limited_queue: Sent item.
2024-05-12T23:00:10.060774Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector_buffers::topology::channel::limited_queue: Sent item.
2024-05-12T23:00:10.060783Z TRACE source{component_kind="source" component_id=unifi component_type=syslog}: vector_core::fanout: Sent item to fanout.
2024-05-12T23:00:10.060808Z TRACE sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector_common::internal_event::events_received: Events received. count=8 byte_size=2784
2024-05-12T23:00:10.061044Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::events_received: Events received. count=8 byte_size=2784
2024-05-12T23:00:10.061076Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::events_sent: Events sent. count=1 byte_size=326
2024-05-12T23:00:10.061083Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::bytes_sent: Bytes sent. byte_size=327 protocol=console
2024-05-12T23:00:10.061102Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::events_sent: Events sent. count=1 byte_size=309
2024-05-12T23:00:10.061107Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::bytes_sent: Bytes sent. byte_size=310 protocol=console
2024-05-12T23:00:10.061256Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::events_sent: Events sent. count=1 byte_size=272
2024-05-12T23:00:10.061266Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::bytes_sent: Bytes sent. byte_size=273 protocol=console
2024-05-12T23:00:10.061281Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::events_sent: Events sent. count=1 byte_size=264
2024-05-12T23:00:10.061287Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::bytes_sent: Bytes sent. byte_size=265 protocol=console
2024-05-12T23:00:10.061334Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::events_sent: Events sent. count=1 byte_size=270
2024-05-12T23:00:10.061343Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::bytes_sent: Bytes sent. byte_size=271 protocol=console
2024-05-12T23:00:10.061389Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::events_sent: Events sent. count=1 byte_size=494
2024-05-12T23:00:10.061398Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::bytes_sent: Bytes sent. byte_size=497 protocol=console
2024-05-12T23:00:10.061415Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::events_sent: Events sent. count=1 byte_size=499
2024-05-12T23:00:10.061454Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::bytes_sent: Bytes sent. byte_size=502 protocol=console
2024-05-12T23:00:10.061487Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::events_sent: Events sent. count=1 byte_size=341
2024-05-12T23:00:10.061493Z TRACE sink{component_kind="sink" component_id=console_unifi component_type=console}: vector_common::internal_event::bytes_sent: Bytes sent. byte_size=342 protocol=console
2024-05-12T23:00:10.719494Z TRACE vector: Beep.
2024-05-12T23:00:10.719529Z DEBUG sink{component_kind="sink" component_id=console_unifi component_type=console}: vector::utilization: utilization=0.00008385913931916169
2024-05-12T23:00:10.719525Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector::utilization: utilization=0.000041012317200352105
2024-05-12T23:00:11.063030Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector::internal_events::loki: Timestamps rewritten. count=7 reason="out_of_order" internal_log_rate_limit=true
2024-05-12T23:00:11.063218Z TRACE sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector_stream::driver: Submitting service request. in_flight_requests=0 request_id=3
2024-05-12T23:00:11.063271Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=3}:http: vector::internal_events::http_client: Sending HTTP request. uri=http://192.168.1.21:3100/loki/api/v1/push method=POST version=HTTP/1.1 headers={"content-type": "application/x-protobuf", "content-encoding": "snappy", "user-agent": "Vector/0.38.0 (x86_64-unknown-linux-gnu ea0ec6f 2024-05-07 14:34:39.794027186)", "accept-encoding": "identity"} body=[1074 bytes]
2024-05-12T23:00:11.063307Z TRACE sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=3}:http: hyper::client::pool: take? ("http", 192.168.1.21:3100): expiration = Some(90s)
2024-05-12T23:00:11.063320Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=3}:http: hyper::client::pool: reuse idle connection for ("http", 192.168.1.21:3100)
2024-05-12T23:00:11.063359Z TRACE encode_headers: hyper::proto::h1::role: Client::encode method=POST, body=Some(Known(1074))
2024-05-12T23:00:11.063379Z TRACE hyper::proto::h1::io: buffer.flatten self.len=265 buf.len=1074
2024-05-12T23:00:11.064619Z DEBUG hyper::proto::h1::io: flushed 1339 bytes
2024-05-12T23:00:11.064633Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Init, writing: KeepAlive, keep_alive: Busy }
2024-05-12T23:00:11.064674Z TRACE hyper::proto::h1::io: received 349 bytes
2024-05-12T23:00:11.064686Z TRACE parse_headers: hyper::proto::h1::role: Response.parse bytes=349
2024-05-12T23:00:11.064914Z ERROR sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=3}: vector::sinks::util::retries: Internal log [Non-retriable error; dropping the request.] is being suppressed to avoid flooding.
2024-05-12T23:00:11.064933Z ERROR sink{component_kind="sink" component_id=loki_unifi component_type=loki}:request{request_id=3}: vector_common::internal_event::service: Internal log [Service call failed. No retries or retries exhausted.] is being suppressed to avoid flooding.
2024-05-12T23:00:11.719410Z TRACE vector: Beep.
2024-05-12T23:00:12.720124Z TRACE vector: Beep.
2024-05-12T23:00:13.719414Z TRACE vector: Beep.
2024-05-12T23:00:14.720058Z TRACE vector: Beep.
2024-05-12T23:00:15.719995Z TRACE vector: Beep.
2024-05-12T23:00:15.720017Z DEBUG sink{component_kind="sink" component_id=console_unifi component_type=console}: vector::utilization: utilization=0.00000842119050777661
2024-05-12T23:00:15.720034Z DEBUG sink{component_kind="sink" component_id=loki_unifi component_type=loki}: vector::utilization: utilization=0.000004143887361654082
2024-05-12T23:00:16.720000Z TRACE vector: Beep.
2024-05-12T23:00:17.719643Z TRACE vector: Beep.

Example Data

No response

Additional Context

Vector, Loki, and Grafana are all running in docker, all on the same docker network.

References

No response
@tom-dell tom-dell added the type: bug A code related bug. label May 13, 2024
@jszwedko
Copy link
Member

Hi @tom-dell! I would check your Loki logs for more details about why the request was considered a bad request. I'm not sure if the Loki response would include more details but unfortunately Vector doesn't have a way to log the HTTP response bodies at the moment (there was some work started towards this in #15911 but we never completed it). As a workaround you could have Vector forward through a HTTP proxy where you could inspect the requests.

@jszwedko jszwedko added sink: loki Anything `loki` sink related domain: observability Anything related to monitoring/observing Vector meta: awaiting author Pull requests that are awaiting their author. labels May 20, 2024
@j4mbob
Copy link

j4mbob commented May 31, 2024

Seeing a similar issue - #20590

Did you find what the cause of your issue was @tom-dell ?

@tamer-hassan
Copy link

Having similar issue #20593 (comment)

Any updates @tom-dell ?

I also notice that after the exact same messages you get re 400 Bad Request, Loki is receiving messages from vector for about 8-9 minutes continuously, but right after that it stops receiving messages.

@tamer-hassan
Copy link

Update: I used Fiddler classic to debug, and found that Loki was returning 400 Bad request with reason about timestamp too new, because of timezone differences between what is being sent and what is expected.
After properly using parse_timestamp, by adding the correct timezone to the date/time in log, I am no longer getting 400 bad requests.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
domain: observability Anything related to monitoring/observing Vector meta: awaiting author Pull requests that are awaiting their author. sink: loki Anything `loki` sink related type: bug A code related bug.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@jszwedko @tamer-hassan @tom-dell @j4mbob