error initializing stream - i/o timeout

[silveraignacio]

Describe the bug
I have promtail configured to use syslog module. Syslog module is configured to listen on port 1514 and syslog-ng pod is sending information to promtail. It has the following config:

  - job_name: syslog
    syslog:
      listen_address: 0.0.0.0:1514
      idle_timeout: 180s
      label_structured_data: yes
      labels:
        job: "syslog"
    relabel_configs:
      - source_labels: ['__syslog_message_hostname']
        target_label: 'host'
      - source_labels: ['__syslog_connection_ip_address']
        target_label: 'remote_ip'
      - source_labels: ['__syslog_connection_hostname']
        target_label: 'conn_host'
      - source_labels: ['__syslog_message_severity']
        target_label: 'msg_sev'
      - source_labels: ['__syslog_message_facility']
        target_label: 'facility'
      - source_labels: ['__syslog_message_app_name']
        target_label: 'app'
      - source_labels: ['__syslog_message_proc_id']
        target_label: 'proc_id'
      - source_labels: ['__syslog_message_msg_id']
        target_label: 'msg_id'

I'm getting the following error in the logs sporadically:

level=warn ts=2022-09-27T09:10:39.138664007Z caller=transport.go:285 msg="error initializing syslog stream" err="read tcp 10.233.124.134:1514->10.233.124.133:36183: i/o timeout"
level=warn ts=2022-09-27T09:27:09.692325767Z caller=transport.go:285 msg="error initializing syslog stream" err="read tcp 10.233.124.134:1514->10.233.73.91:37417: i/o timeout"
level=warn ts=2022-09-27T09:34:15.781156207Z caller=transport.go:285 msg="error initializing syslog stream" err="read tcp 10.233.124.134:1514->10.233.112.231:45903: i/o timeout"
level=warn ts=2022-09-27T09:45:06.505257631Z caller=transport.go:285 msg="error initializing syslog stream" err="read tcp 10.233.124.134:1514->10.233.113.125:43885: i/o timeout"
level=warn ts=2022-09-27T09:54:13.843961214Z caller=transport.go:285 msg="error initializing syslog stream" err="read tcp 10.233.124.134:1514->10.233.123.66:37445: i/o timeout"
level=warn ts=2022-09-27T10:02:40.601312Z caller=transport.go:285 msg="error initializing syslog stream" err="read tcp 10.233.124.134:1514->10.233.124.133:34735: i/o timeout"
level=warn ts=2022-09-27T10:34:31.751182729Z caller=transport.go:285 msg="error initializing syslog stream" err="read tcp 10.233.124.134:1514->10.233.112.231:45699: i/o timeout"
level=warn ts=2022-09-27T10:35:00.137274397Z caller=transport.go:285 msg="error initializing syslog stream" err="read tcp 10.233.124.134:1514->10.233.73.91:34443: i/o timeout"
level=warn ts=2022-09-27T10:41:08.500277216Z caller=transport.go:285 msg="error initializing syslog stream" err="read tcp 10.233.124.134:1514->10.233.113.125:38549: i/o timeout"

I have it deployed on 8 worker nodes, and all of them are showing the same issue (of course varying the IP). The IP after the "->" corresponds to some syslog pod. I do not understand why promtail want to reach syslog pod if is syslog who should initiate the traffic

To Reproduce
Steps to reproduce the behavior:

1. Deploy syslog-ng on K8s cluster and configure to send logs to promtail
2. Configure promtail to receive syslog messages
3. Once the connection is done, wait for the error

Expected behavior
No timeout should be found

Environment:

• Infrastructure: Kubernetes cluster on VMs and Minikube
• Deployment tool: helm

Screenshots, Promtail config, or terminal output
If applicable, add any output to help explain your problem.

[cstyan]

@silveraignacio is this still an issue for you? unfortunately I don't know much about the syslog setup for promtail but from https://grafana.com/docs/loki/latest/send-data/promtail/configuration/#syslog it looks like promtail establishes a TCP connection to the forwarder.

[Shnooter]

I've been experiencing this issue as well. It used to work, although Tereform updated the components (all docker containers) and now it's generating this same issue.

Initially there was an issue with the syslog-ng configuration as it now has a requirement for including @Version and @include at the top of the config. That was resolved and it's configured to send to my Promtail container.

Then I found Grafana couldn't connect to Loki, I identified I wasn't pulling from the same docker provider for both, so changed them to both use Grafana/. That now works, so I know I can connect to Loki.

Promtail itself is listening, from testing the following from my PC;

level=warn ts=2023-12-19T17:06:15.542078722Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.17.0.6:1514->172.17.0.1:38246: i/o timeout"
level=warn ts=2023-12-19T17:08:28.043069294Z caller=transport.go:286 msg="error initializing syslog stream" err=EOF
level=warn ts=2023-12-19T17:11:45.785062329Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.17.0.6:1514->172.17.0.1:38250: i/o timeout"
level=warn ts=2023-12-19T17:14:10.998020923Z caller=transport.go:286 msg="error initializing syslog stream" err=EOF
level=warn ts=2023-12-19T17:14:45.813667699Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.17.0.6:1514->172.17.0.1:38252: i/o timeout"
level=warn ts=2023-12-19T17:17:45.857437777Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.17.0.6:1514->172.17.0.1:38256: i/o timeout"
level=warn ts=2023-12-19T17:20:45.931532802Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.17.0.6:1514->172.17.0.1:38258: i/o timeout"
level=warn ts=2023-12-19T17:23:46.005312567Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.17.0.6:1514->172.17.0.1:38260: i/o timeout"
level=warn ts=2023-12-19T17:26:46.059183564Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.17.0.6:1514->172.17.0.1:38262: i/o timeout"
level=warn ts=2023-12-19T17:29:46.074689392Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.17.0.6:1514->172.17.0.1:38264: i/o timeout"

I believe it should go, device -> syslog-ng -> promtail -> loki. If I stop the syslog-ng container then promtail stops presenting the i/o timeouts, so it looks like syslog-ng is communicating with promtail. I'm just not sure if the errors relate to inbound to promtail from syslog-ng or if it's outbound from promtail to loki.

Both are configured to use the latest build;

UPDATE RESOLVED:
I got this working (user error), syslog-ng needed the correct port (514) for the internal on the container and also the container by default was bound using TCP, however the syslogs were being sent to syslog-ng via UDP. Changing the container protocol resolved that. So the error above being seen was between Promtail and Syslog-ng (hopefully that helps anyone else that comes across this!)

[cstyan]

Thanks for the update with the config fix 👍

[virtualistic]

@Shnooter Can you please share some more detail on how/where you set the port 514 for syslog-ng and what you mean by: Also the container by default was bound using TCP, however the syslogs were being sent to syslog-ng via UDP. Changing the container protocol resolved that. ?
From what I read, we don't want the internal port syslog-ng running on 514 because it requires root privileges in docker if my understanding is correct.
I'm also trying to get a syslog-ng ->promtail-> loki <-grafana up and running:
Grafana v10.4.0
loki 2.8.8
promtail 2.8.8
https://grafana.com/grafana/dashboards/13766-loki-syslog-aio-overview/
and while the syslogs of my switches and APs are coming in on UDP and being locally stored, it seems that promtail has an issue sending them to Loki which has yet to be resolved 🤔: #6772

(although if I can query the logs using the explore option in Grafana:

docker logs of the promtail container showing these warnings:

level=info ts=2024-03-24T14:50:07.942370118Z caller=promtail.go:133 msg="Reloading configuration file" md5sum=a51501eec3865c696872c5551f2b8a52
level=info ts=2024-03-24T14:50:07.942669079Z caller=transport.go:188 msg="syslog listening on address" address=[::]:1514 protocol=tcp tls=false
level=info ts=2024-03-24T14:50:07.943047005Z caller=server.go:334 http=[::]:9080 grpc=[::]:45385 msg="server listening on addresses"
level=info ts=2024-03-24T14:50:07.943275304Z caller=main.go:174 msg="Starting Promtail" version="(version=2.8.8, branch=HEAD, revision=126e6d38c)"
level=warn ts=2024-03-24T14:50:07.943379283Z caller=promtail.go:265 msg="enable watchConfig"
level=warn ts=2024-03-24T15:05:21.97436082Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:46455: i/o timeout"
level=warn ts=2024-03-24T15:15:33.990743278Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:35171: i/o timeout"
level=warn ts=2024-03-24T15:30:55.890838659Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:36951: i/o timeout"
level=warn ts=2024-03-24T15:37:03.605411057Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:37687: i/o timeout"
level=warn ts=2024-03-24T15:56:22.165514758Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:33445: i/o timeout"
level=warn ts=2024-03-24T16:26:58.191374885Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:44121: i/o timeout"
level=warn ts=2024-03-24T16:32:58.268863244Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:43911: i/o timeout"
level=warn ts=2024-03-24T16:42:16.361182647Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:37567: i/o timeout"
level=warn ts=2024-03-24T16:44:16.369796273Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:41929: i/o timeout"
level=warn ts=2024-03-24T16:57:34.309871432Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:46323: i/o timeout"
level=warn ts=2024-03-24T16:59:34.335765044Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:43127: i/o timeout"
level=warn ts=2024-03-24T17:03:34.374080857Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:40655: i/o timeout"
level=warn ts=2024-03-24T19:16:55.336887155Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:38225: i/o timeout"
level=warn ts=2024-03-24T19:27:28.613761546Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:40631: i/o timeout"
level=warn ts=2024-03-24T20:11:36.335731309Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:46765: i/o timeout"
level=warn ts=2024-03-24T20:21:45.694796577Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:41309: i/o timeout"
level=warn ts=2024-03-24T20:26:40.750231527Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:44705: i/o timeout"
level=warn ts=2024-03-24T20:36:52.744208162Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:37967: i/o timeout"
level=warn ts=2024-03-24T20:38:52.782948607Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:46701: i/o timeout"
level=warn ts=2024-03-24T20:52:10.766247113Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:43025: i/o timeout"
level=warn ts=2024-03-24T20:54:10.814689078Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:37305: i/o timeout"
level=warn ts=2024-03-24T21:04:23.821311641Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:44569: i/o timeout"
level=warn ts=2024-03-24T21:22:47.091223403Z caller=transport.go:286 msg="error initializing syslog stream" err="read tcp 172.19.0.2:1514->172.19.0.5:37361: i/o timeout"

(172.19.0.2 being the promtail docker container and 172.19.0.5 being the syslog-ng container)
The first panel in grafana is being populated while the other two are saying No Data

[Shnooter]

@virtualistic so in my terraform I basically have it defined like this;
ports = [ { ip = <replace with device ip> internal = 514 external = 5514 port = udp } ]

I believe to do the same when running docker as a command it's in the -p parameter and should look something like this;

docker run -p <host-port>:<container-port>/udp

I am using this in a lab setup at home, so there could a chance I'm not using best practice for different parts ;)
Hopefully that helps

[virtualistic]

@virtualistic so in my terraform I basically have it defined like this; ports = [ { ip = <replace with device ip> internal = 514 external = 5514 port = udp } ]

I believe to do the same when running docker as a command it's in the -p parameter and should look something like this;

docker run -p <host-port>:<container-port>/udp

I am using this in a lab setup at home, so there could a chance I'm not using best practice for different parts ;) Hopefully that helps

Thanks for your quick reply @Shnooter !
I have the same setup with syslog-ng port 514 on the outside, port 5514 on the inside and I'm still seeing those messages.
This is my syslog-ng.conf

@version: 4.5
@include "scl.conf"

#source s_sys { system(); internal();};
#destination d_mesg { file("/var/log/messages"); };
#log { source(s_sys); destination(d_mesg); };

source s_udp { udp(port(5514)); };

destination d_file {
  file("/var/log/${YEAR}.${MONTH}-${HOST}.log");
};

destination d_loki {
        syslog("promtail" transport("tcp") port("1514"));
};

log {
  source(s_udp);
  destination(d_file);
  destination(d_loki);
};

Can you perhaps share your promtail-config.yaml so we can compare?
This is mine:

server:
  http_listen_port: 9080
  grpc_listen_port: 0

positions:
  filename: /tmp/positions.yaml

clients:
  - url: http://loki:3100/loki/api/v1/push

scrape_configs:

- job_name: syslog
  syslog:
    listen_address: 0.0.0.0:1514
    idle_timeout: 60s
    label_structured_data: yes
    labels:
      job: "syslog"
  relabel_configs:
    - source_labels: ['__syslog_message_hostname']
      target_label: 'host'

[Shnooter]

I've compared configs and it's looks the same bar your syslog-ng.

You have the udp port as 5514, I have mine as 514 as that's what my container will use for it's internal port.

Network device -> udp 514 docker host -> udp 5514 syslog-ng -> promtail