Incomplete transfer of logs from OpenWRT to an external server using an external log server (rsyslog)

Installing and Using OpenWrt
1

Welcome,
a few days ago, I used a function to upload the logs of the OpenWRT software to a remote server (Ubuntu using rsyslog). I needed this functionality because there were sometimes bugs in my network that I wanted to diagnose (my router is still being fine-tuned by the OpenWRT team), but unfortunately I peacock always had to reset the router. So I decided to use the function of sending logs to an external server (my public server).
After a few days I noticed that this function was not working properly - it was not forwarding all the logs from the router to the server, but only some (sometimes none). In this situation, when I access the OpenWRT router in the event log tab, I can see all the logs (DEBUG level including WiFi debugging), but on the server side (where the logs go) the logs are not identical (there are far fewer of them than on the OpenWRT router).

Some examples:
Example 1:

  • Logs on the router side:
Mon Jul 15 01:56:15 2024 daemon.info logread[1312]: Logread connected to 89.111.11.11:514 via tcp
Mon Jul 15 01:57:45 2024 daemon.notice hostapd: phy2-ap0: AP-STA-POLL-OK 7c:91:22:c4:0c:76
Mon Jul 15 02:14:18 2024 daemon.notice hostapd: phy2-ap0: AP-STA-POLL-OK 7c:91:22:c4:0c:76
Mon Jul 15 02:30:48 2024 daemon.info logread[1312]: Logread connected to 89.111.11.11:514 via tcp
Mon Jul 15 02:55:10 2024 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 10.0.0.72 78:17:be:cc:25:ff
Mon Jul 15 02:55:10 2024 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 10.0.0.72 78:17:be:cc:25:ff Huawei-Fotowoltaika
Mon Jul 15 03:11:41 2024 daemon.info logread[1312]: Logread connected to 89.111.11.11:514 via tcp
  • Logs on the external server side:
Jul 15 01:56:15 Xiaomi_AX3600 logread[1312]: Logread connected to 89.111.11.11:514 via tcp
Jul 15 01:57:45 Xiaomi_AX3600 hostapd: phy2-ap0: AP-STA-POLL-OK 7c:91:22:c4:0c:76
Jul 15 02:30:48 Xiaomi_AX3600 logread[1312]: Logread connected to 89.111.11.11:514 via tcp
Jul 15 03:11:41 Xiaomi_AX3600 logread[1312]: Logread connected to 89.111.11.11:514 via tcp

Example 2:

  • Logs on the router side:
Mon Jul 15 03:45:13 2024 daemon.info logread[1312]: Logread connected to 89.111.11.11:514 via tcp
Mon Jul 15 03:50:29 2024 daemon.notice hostapd: phy2-ap0: AP-STA-DISCONNECTED 40:31:3c:ad:00:82
Mon Jul 15 03:50:29 2024 daemon.debug hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 IEEE 802.11: authentication OK (open system)
Mon Jul 15 03:50:29 2024 daemon.debug hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 WPA: event 0 notification
Mon Jul 15 03:50:29 2024 daemon.debug hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 MLME: MLME-AUTHENTICATE.indication(40:31:3c:ad:00:82, OPEN_SYSTEM)
Mon Jul 15 03:50:29 2024 daemon.debug hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 MLME: MLME-DELETEKEYS.request(40:31:3c:ad:00:82)
Mon Jul 15 03:50:29 2024 daemon.info hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 IEEE 802.11: authenticated
Mon Jul 15 03:50:29 2024 daemon.debug hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 IEEE 802.11: association OK (aid 3)
Mon Jul 15 03:50:29 2024 daemon.info hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 IEEE 802.11: associated (aid 3)
Mon Jul 15 03:50:29 2024 daemon.debug hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 MLME: MLME-ASSOCIATE.indication(40:31:3c:ad:00:82)
Mon Jul 15 03:50:29 2024 daemon.debug hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 MLME: MLME-DELETEKEYS.request(40:31:3c:ad:00:82)
Mon Jul 15 03:50:29 2024 daemon.debug hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 IEEE 802.11: binding station to interface 'phy2-ap0'
Mon Jul 15 03:50:29 2024 daemon.debug hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 WPA: event 1 notification
Mon Jul 15 03:50:29 2024 daemon.debug hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 WPA: sending 1/4 msg of 4-Way Handshake
Mon Jul 15 03:50:29 2024 daemon.debug hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 WPA: received EAPOL-Key frame (2/4 Pairwise)
Mon Jul 15 03:50:29 2024 daemon.debug hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 WPA: sending 3/4 msg of 4-Way Handshake
Mon Jul 15 03:50:29 2024 daemon.debug hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 WPA: received EAPOL-Key frame (4/4 Pairwise)
Mon Jul 15 03:50:29 2024 daemon.notice hostapd: phy2-ap0: AP-STA-CONNECTED 40:31:3c:ad:00:82 auth_alg=open
Mon Jul 15 03:50:29 2024 daemon.debug hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 IEEE 802.1X: authorizing port
Mon Jul 15 03:50:29 2024 daemon.info hostapd: phy2-ap0: STA 40:31:3c:ad:00:82 WPA: pairwise key handshake completed (RSN)
Mon Jul 15 03:50:29 2024 daemon.notice hostapd: phy2-ap0: EAPOL-4WAY-HS-COMPLETED 40:31:3c:ad:00:82
Mon Jul 15 03:50:31 2024 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 40:31:3c:ad:00:82
Mon Jul 15 03:50:31 2024 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 10.0.0.71 40:31:3c:ad:00:82
Mon Jul 15 03:50:31 2024 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 10.0.0.71 40:31:3c:ad:00:82
Mon Jul 15 03:50:31 2024 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 10.0.0.71 40:31:3c:ad:00:82 Roborock-S55
  • Logs on the external server side:
Jul 15 03:45:13 Xiaomi_AX3600 logread[1312]: Logread connected to 89.111.11.11:514 via tcp
Jul 15 04:06:58 Xiaomi_AX3600 logread[1312]: Logread connected to 89.111.11.11:514 via tcp

Example 3:

  • Logs on the router side:
Mon Jul 15 04:06:58 2024 daemon.info logread[1312]: Logread connected to 89.111.11.11:514 via tcp
Mon Jul 15 04:11:14 2024 daemon.notice hostapd: phy2-ap0: AP-STA-POLL-OK 7c:91:22:c4:0c:76
Mon Jul 15 04:22:06 2024 daemon.notice hostapd: phy2-ap0: AP-STA-POLL-OK 7c:91:22:c4:0c:76
Mon Jul 15 04:27:43 2024 daemon.info logread[1312]: Logread connected to 89.111.11.11:514 via tcp
Mon Jul 15 04:38:03 2024 daemon.notice hostapd: phy2-ap0: AP-STA-POLL-OK 7c:91:22:c4:0c:76
Mon Jul 15 04:54:30 2024 daemon.info logread[1312]: Logread connected to 89.111.11.11:514 via tcp
Mon Jul 15 05:29:57 2024 daemon.err uhttpd[2886]: [info] luci: accepted login on /admin/status/logs for root from 10.0.0.112
Mon Jul 15 05:33:10 2024 daemon.info logread[1312]: Logread connected to 89.111.11.11:514 via tcp
Mon Jul 15 05:53:17 2024 daemon.notice hostapd: phy2-ap0: AP-STA-DISCONNECTED 48:74:12:6b:cb:9b
Mon Jul 15 05:53:17 2024 daemon.debug hostapd: phy2-ap0: STA 48:74:12:6b:cb:9b WPA: event 3 notification
Mon Jul 15 05:53:18 2024 daemon.debug hostapd: phy2-ap0: STA 48:74:12:6b:cb:9b IEEE 802.1X: unauthorizing port
Mon Jul 15 05:53:18 2024 daemon.debug hostapd: phy2-ap0: STA 48:74:12:6b:cb:9b IEEE 802.11: deauthenticated
Mon Jul 15 05:53:18 2024 daemon.debug hostapd: phy2-ap0: STA 48:74:12:6b:cb:9b MLME: MLME-DEAUTHENTICATE.indication(48:74:12:6b:cb:9b, 3)
Mon Jul 15 05:53:18 2024 daemon.debug hostapd: phy2-ap0: STA 48:74:12:6b:cb:9b MLME: MLME-DELETEKEYS.request(48:74:12:6b:cb:9b)
Mon Jul 15 06:23:03 2024 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) ec:d0:9f:04:b9:1c
Mon Jul 15 06:23:03 2024 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 10.0.0.204 ec:d0:9f:04:b9:1c
Mon Jul 15 06:23:03 2024 daemon.info logread[1312]: Failed to send log data to 89.111.11.11:514 via tcp
Mon Jul 15 06:23:03 2024 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) ec:d0:9f:04:b9:1c
Mon Jul 15 06:23:03 2024 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 10.0.0.204 ec:d0:9f:04:b9:1c
Mon Jul 15 06:23:04 2024 daemon.info logread[1312]: Logread connected to 89.111.11.11:514 via tcp
Mon Jul 15 06:23:05 2024 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) ec:d0:9f:04:b9:1c
Mon Jul 15 06:23:05 2024 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 10.0.0.204 ec:d0:9f:04:b9:1c
Mon Jul 15 06:23:12 2024 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) ec:d0:9f:04:b9:1c
Mon Jul 15 06:23:12 2024 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 10.0.0.204 ec:d0:9f:04:b9:1c
Mon Jul 15 06:23:34 2024 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) ec:d0:9f:04:b9:1c
Mon Jul 15 06:23:34 2024 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 10.0.0.204 ec:d0:9f:04:b9:1c
Mon Jul 15 06:31:09 2024 daemon.err uhttpd[2886]: [info] luci: accepted login on /admin/status/logs for root from 10.0.0.112
  • Logs on the external server side:
Jul 15 04:06:58 Xiaomi_AX3600 logread[1312]: Logread connected to 89.111.11.11:514 via tcp
Jul 15 06:23:04 Xiaomi_AX3600 logread[1312]: message repeated 4 times: [ Logread connected to 89.111.11.11:514 via tcp]
Jul 15 06:23:05 Xiaomi_AX3600 dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) ec:d0:9f:04:b9:1c
Jul 15 06:23:05 Xiaomi_AX3600 dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 10.0.0.204 ec:d0:9f:04:b9:1c
Jul 15 06:23:12 Xiaomi_AX3600 dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) ec:d0:9f:04:b9:1c
Jul 15 06:23:12 Xiaomi_AX3600 dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 10.0.0.204 ec:d0:9f:04:b9:1c
Jul 15 06:23:34 Xiaomi_AX3600 dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) ec:d0:9f:04:b9:1c
Jul 15 06:23:34 Xiaomi_AX3600 dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 10.0.0.204 ec:d0:9f:04:b9:1c
Jul 15 06:47:39 Xiaomi_AX3600 logread[1312]: Logread connected to 89.111.11.11:514 via tcp

Example 4:

  • Logs on the router side:
Sun Jul 15 00:33:13 2024 daemon.info logread[1312]: Logread connected to 89.111.11.11:514 via tcp
Mon Jul 15 00:33:42 2024 kern.info kernel: [   58.966791] nss-dp 3a001800.dp5 lan3: PHY Link up speed: 100
Mon Jul 15 00:33:42 2024 kern.info kernel: [   58.966879] br-lan: port 3(lan3) entered blocking state
Mon Jul 15 00:33:42 2024 kern.info kernel: [   58.971533] br-lan: port 3(lan3) entered forwarding state
Mon Jul 15 00:33:42 2024 daemon.notice netifd: Network device 'lan3' link is up
Mon Jul 15 00:33:43 2024 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 10.0.0.112 24:2f:d0:16:bc:ed
Mon Jul 15 00:33:43 2024 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 10.0.0.112 24:2f:d0:16:bc:ed Misiek-PC
Mon Jul 15 00:33:45 2024 daemon.notice netifd: Network device 'lan3' link is down
Mon Jul 15 00:33:45 2024 kern.info kernel: [   62.086729] nss-dp 3a001800.dp5 lan3: PHY Link is down
Mon Jul 15 00:33:45 2024 kern.info kernel: [   62.087022] br-lan: port 3(lan3) entered disabled state
Mon Jul 15 00:33:46 2024 kern.info kernel: [   63.126807] nss-dp 3a001800.dp5 lan3: PHY Link up speed: 100
Mon Jul 15 00:33:46 2024 kern.info kernel: [   63.126893] br-lan: port 3(lan3) entered blocking state
Mon Jul 15 00:33:46 2024 kern.info kernel: [   63.131554] br-lan: port 3(lan3) entered forwarding state
Mon Jul 15 00:33:46 2024 daemon.notice netifd: Network device 'lan3' link is up
Mon Jul 15 00:33:52 2024 daemon.notice netifd: Network device 'lan3' link is down
Mon Jul 15 00:33:52 2024 kern.info kernel: [   68.326803] nss-dp 3a001800.dp5 lan3: PHY Link is down
Mon Jul 15 00:33:52 2024 kern.info kernel: [   68.327098] br-lan: port 3(lan3) entered disabled state
Mon Jul 15 00:33:54 2024 kern.info kernel: [   70.406872] nss-dp 3a001800.dp5 lan3: PHY Link up speed: 100
Mon Jul 15 00:33:54 2024 kern.info kernel: [   70.406959] br-lan: port 3(lan3) entered blocking state
Mon Jul 15 00:33:54 2024 kern.info kernel: [   70.411622] br-lan: port 3(lan3) entered forwarding state
Mon Jul 15 00:33:54 2024 daemon.notice netifd: Network device 'lan3' link is up
Mon Jul 15 00:33:56 2024 daemon.notice netifd: Network device 'lan3' link is down
Mon Jul 15 00:33:56 2024 kern.info kernel: [   72.486832] nss-dp 3a001800.dp5 lan3: PHY Link is down
Mon Jul 15 00:33:56 2024 kern.info kernel: [   72.487127] br-lan: port 3(lan3) entered disabled state
Mon Jul 15 00:33:59 2024 kern.info kernel: [   75.606921] nss-dp 3a001800.dp5 lan3: PHY Link up speed: 100
Mon Jul 15 00:33:59 2024 kern.info kernel: [   75.607007] br-lan: port 3(lan3) entered blocking state
Mon Jul 15 00:33:59 2024 kern.info kernel: [   75.611662] br-lan: port 3(lan3) entered forwarding state
Mon Jul 15 00:33:59 2024 daemon.notice netifd: Network device 'lan3' link is up
Mon Jul 15 00:34:00 2024 daemon.notice netifd: Network device 'lan3' link is down
Mon Jul 15 00:34:00 2024 kern.info kernel: [   76.656765] nss-dp 3a001800.dp5 lan3: PHY Link is down
Mon Jul 15 00:34:00 2024 kern.info kernel: [   76.657091] br-lan: port 3(lan3) entered disabled state
Mon Jul 15 00:34:02 2024 kern.info kernel: [   78.726914] nss-dp 3a001800.dp5 lan3: PHY Link up speed: 100
Mon Jul 15 00:34:02 2024 kern.info kernel: [   78.726998] br-lan: port 3(lan3) entered blocking state
Mon Jul 15 00:34:02 2024 kern.info kernel: [   78.731663] br-lan: port 3(lan3) entered forwarding state
Mon Jul 15 00:34:02 2024 daemon.notice netifd: Network device 'lan3' link is up
Mon Jul 15 00:34:02 2024 daemon.err collectd[3277]: rrdtool plugin: rrd_update_r failed: /tmp/rrd/Xiaomi_AX3600/cpu-3/percent-softirq.rrd: Not enough arguments
Mon Jul 15 00:34:03 2024 daemon.err uhttpd[2886]: [info] luci: accepted login on / for root from 10.0.0.112
Mon Jul 15 00:34:04 2024 daemon.notice netifd: Network device 'lan3' link is down
Mon Jul 15 00:34:04 2024 kern.info kernel: [   80.806913] nss-dp 3a001800.dp5 lan3: PHY Link is down
Mon Jul 15 00:34:04 2024 kern.info kernel: [   80.807223] br-lan: port 3(lan3) entered disabled state
Mon Jul 15 00:34:07 2024 kern.info kernel: [   83.926929] nss-dp 3a001800.dp5 lan3: PHY Link up speed: 100
Mon Jul 15 00:34:07 2024 kern.info kernel: [   83.927017] br-lan: port 3(lan3) entered blocking state
Mon Jul 15 00:34:07 2024 kern.info kernel: [   83.931669] br-lan: port 3(lan3) entered forwarding state
Mon Jul 15 00:34:07 2024 daemon.notice netifd: Network device 'lan3' link is up
Mon Jul 15 01:02:42 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 IEEE 802.11: authentication OK (open system)
Mon Jul 15 01:02:42 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 MLME: MLME-AUTHENTICATE.indication(7c:91:22:c4:0c:76, OPEN_SYSTEM)
Mon Jul 15 01:02:42 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 MLME: MLME-DELETEKEYS.request(7c:91:22:c4:0c:76)
Mon Jul 15 01:02:42 2024 daemon.info hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 IEEE 802.11: authenticated
Mon Jul 15 01:02:42 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 IEEE 802.11: association OK (aid 11)
Mon Jul 15 01:02:42 2024 daemon.info hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 IEEE 802.11: associated (aid 11)
Mon Jul 15 01:02:42 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 MLME: MLME-ASSOCIATE.indication(7c:91:22:c4:0c:76)
Mon Jul 15 01:02:42 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 MLME: MLME-DELETEKEYS.request(7c:91:22:c4:0c:76)
Mon Jul 15 01:02:42 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 IEEE 802.11: binding station to interface 'phy2-ap0'
Mon Jul 15 01:02:42 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 WPA: event 1 notification
Mon Jul 15 01:02:42 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 WPA: start authentication
Mon Jul 15 01:02:42 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 IEEE 802.1X: unauthorizing port
Mon Jul 15 01:02:42 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 WPA: sending 1/4 msg of 4-Way Handshake
Mon Jul 15 01:02:43 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 WPA: received EAPOL-Key frame (2/4 Pairwise)
Mon Jul 15 01:02:43 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 WPA: sending 3/4 msg of 4-Way Handshake
Mon Jul 15 01:02:43 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 WPA: received EAPOL-Key frame (4/4 Pairwise)
Mon Jul 15 01:02:43 2024 daemon.notice hostapd: phy2-ap0: AP-STA-CONNECTED 7c:91:22:c4:0c:76 auth_alg=open
Mon Jul 15 01:02:43 2024 daemon.debug hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 IEEE 802.1X: authorizing port
Mon Jul 15 01:02:43 2024 daemon.info hostapd: phy2-ap0: STA 7c:91:22:c4:0c:76 WPA: pairwise key handshake completed (RSN)
Mon Jul 15 01:02:43 2024 daemon.notice hostapd: phy2-ap0: EAPOL-4WAY-HS-COMPLETED 7c:91:22:c4:0c:76
Mon Jul 15 01:02:43 2024 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 7c:91:22:c4:0c:76
Mon Jul 15 01:02:43 2024 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 10.0.0.115 7c:91:22:c4:0c:76
Mon Jul 15 01:02:43 2024 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 10.0.0.115 7c:91:22:c4:0c:76
Mon Jul 15 01:02:43 2024 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 10.0.0.115 7c:91:22:c4:0c:76 Galaxy-Tab-S2
Mon Jul 15 01:28:33 2024 daemon.notice hostapd: phy2-ap0: AP-STA-POLL-OK 7c:91:22:c4:0c:76
Mon Jul 15 01:28:33 2024 daemon.info logread[1312]: Failed to send log data to 89.111.11.11:514 via tcp
  • Logs on the external server side:
Jul 15 00:33:13 Xiaomi_AX3600 logread[1312]: Logread connected to 89.111.11.11:514 via tcp
Jul 15 00:33:42 Xiaomi_AX3600 kernel: [   58.966791] nss-dp 3a001800.dp5 lan3: PHY Link up speed: 100
Jul 15 00:33:42 Xiaomi_AX3600 kernel: [   58.966879] br-lan: port 3(lan3) entered blocking state
Jul 15 00:33:42 Xiaomi_AX3600 kernel: [   58.971533] br-lan: port 3(lan3) entered forwarding state
Jul 15 00:33:42 Xiaomi_AX3600 netifd: Network device 'lan3' link is up
Jul 15 00:33:43 Xiaomi_AX3600 dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 10.0.0.112 24:2f:d0:16:bc:ed
Jul 15 00:33:43 Xiaomi_AX3600 dnsmasq-dhcp[1]: DHCPACK(br-lan) 10.0.0.112 24:2f:d0:16:bc:ed Misiek-PC
Jul 15 00:33:45 Xiaomi_AX3600 netifd: Network device 'lan3' link is down
Jul 15 00:33:45 Xiaomi_AX3600 kernel: [   62.086729] nss-dp 3a001800.dp5 lan3: PHY Link is down
Jul 15 00:33:45 Xiaomi_AX3600 kernel: [   62.087022] br-lan: port 3(lan3) entered disabled state
Jul 15 00:33:46 Xiaomi_AX3600 kernel: [   63.126807] nss-dp 3a001800.dp5 lan3: PHY Link up speed: 100
Jul 15 00:33:46 Xiaomi_AX3600 kernel: [   63.126893] br-lan: port 3(lan3) entered blocking state
Jul 15 00:33:46 Xiaomi_AX3600 kernel: [   63.131554] br-lan: port 3(lan3) entered forwarding state
Jul 15 00:33:46 Xiaomi_AX3600 netifd: Network device 'lan3' link is up
Jul 15 00:33:52 Xiaomi_AX3600 netifd: Network device 'lan3' link is down
Jul 15 00:33:52 Xiaomi_AX3600 kernel: [   68.326803] nss-dp 3a001800.dp5 lan3: PHY Link is down
Jul 15 00:33:52 Xiaomi_AX3600 kernel: [   68.327098] br-lan: port 3(lan3) entered disabled state
Jul 15 00:33:54 Xiaomi_AX3600 kernel: [   70.406872] nss-dp 3a001800.dp5 lan3: PHY Link up speed: 100
Jul 15 00:33:54 Xiaomi_AX3600 kernel: [   70.406959] br-lan: port 3(lan3) entered blocking state
Jul 15 00:33:54 Xiaomi_AX3600 kernel: [   70.411622] br-lan: port 3(lan3) entered forwarding state
Jul 15 00:33:54 Xiaomi_AX3600 netifd: Network device 'lan3' link is up
Jul 15 00:33:56 Xiaomi_AX3600 netifd: Network device 'lan3' link is down
Jul 15 00:33:56 Xiaomi_AX3600 kernel: [   72.486832] nss-dp 3a001800.dp5 lan3: PHY Link is down
Jul 15 00:33:56 Xiaomi_AX3600 kernel: [   72.487127] br-lan: port 3(lan3) entered disabled state
Jul 15 00:33:59 Xiaomi_AX3600 kernel: [   75.606921] nss-dp 3a001800.dp5 lan3: PHY Link up speed: 100
Jul 15 00:33:59 Xiaomi_AX3600 kernel: [   75.607007] br-lan: port 3(lan3) entered blocking state
Jul 15 00:33:59 Xiaomi_AX3600 kernel: [   75.611662] br-lan: port 3(lan3) entered forwarding state
Jul 15 00:33:59 Xiaomi_AX3600 netifd: Network device 'lan3' link is up
Jul 15 00:34:00 Xiaomi_AX3600 netifd: Network device 'lan3' link is down
Jul 15 00:34:00 Xiaomi_AX3600 kernel: [   76.656765] nss-dp 3a001800.dp5 lan3: PHY Link is down
Jul 15 00:34:00 Xiaomi_AX3600 kernel: [   76.657091] br-lan: port 3(lan3) entered disabled state
Jul 15 00:34:02 Xiaomi_AX3600 kernel: [   78.726914] nss-dp 3a001800.dp5 lan3: PHY Link up speed: 100
Jul 15 00:34:02 Xiaomi_AX3600 kernel: [   78.726998] br-lan: port 3(lan3) entered blocking state
Jul 15 00:34:02 Xiaomi_AX3600 kernel: [   78.731663] br-lan: port 3(lan3) entered forwarding state
Jul 15 00:34:02 Xiaomi_AX3600 netifd: Network device 'lan3' link is up
Jul 15 00:34:02 Xiaomi_AX3600 collectd[3277]: rrdtool plugin: rrd_update_r failed: /tmp/rrd/Xiaomi_AX3600/cpu-3/percent-softirq.rrd: Not enough arguments
Jul 15 00:34:03 Xiaomi_AX3600 uhttpd[2886]: [info] luci: accepted login on / for root from 10.0.0.112
Jul 15 00:34:04 Xiaomi_AX3600 netifd: Network device 'lan3' link is down
Jul 15 00:34:04 Xiaomi_AX3600 kernel: [   80.806913] nss-dp 3a001800.dp5 lan3: PHY Link is down
Jul 15 00:34:04 Xiaomi_AX3600 kernel: [   80.807223] br-lan: port 3(lan3) entered disabled state
Jul 15 00:34:07 Xiaomi_AX3600 kernel: [   83.926929] nss-dp 3a001800.dp5 lan3: PHY Link up speed: 100
Jul 15 00:34:07 Xiaomi_AX3600 kernel: [   83.927017] br-lan: port 3(lan3) entered blocking state
Jul 15 00:34:07 Xiaomi_AX3600 kernel: [   83.931669] br-lan: port 3(lan3) entered forwarding state
Jul 15 00:34:07 Xiaomi_AX3600 netifd: Network device 'lan3' link is up
Jul 15 01:28:34 Xiaomi_AX3600 logread[1312]: Logread connected to 89.111.11.11:514 via tcp

As you can see from the examples above, there are often missing logs on the server side.
I will attach the configuration data on the server and OpenWRT below. If you need additional data, please write me and I will try to add it as soon as possible.

The address 89.111.11.11:514 is the converted address of my public server.

OpenWRT router:

  • /etc/config/system:
config system
	option hostname 'Xiaomi_AX3600'
	option ttylogin '0'
	option log_size '2000'
	option urandom_seed '0'
	option zonename 'Europe/Warsaw'
	option log_proto 'tcp'
	option conloglevel '8'
	option cronloglevel '5'
	option timezone 'CET-1CEST,M3.5.0,M10.5.0/3'
	option log_ip '89.111.11.11'
	option log_port '514'

config timeserver 'ntp'
	list server '0.openwrt.pool.ntp.org'
	list server '1.openwrt.pool.ntp.org'
	list server '2.openwrt.pool.ntp.org'
	list server '3.openwrt.pool.ntp.org'

My server:

  • /etc/rsyslog.conf:
# /etc/rsyslog.conf configuration file for rsyslog
#
# For more information install rsyslog-doc and see
# /usr/share/doc/rsyslog-doc/html/configuration/index.html
#
# Default logging rules can be found in /etc/rsyslog.d/50-default.conf


#################
#### MODULES ####
#################

module(load="imuxsock") # provides support for local system logging
#module(load="immark")  # provides --MARK-- message capability

# provides UDP syslog reception
module(load="imudp")
input(type="imudp" port="514")

# provides TCP syslog reception
module(load="imtcp")
input(type="imtcp" port="514")

# provides kernel logging support and enable non-kernel klog messages
module(load="imklog" permitnonkernelfacility="on")

###########################
#### GLOBAL DIRECTIVES ####
###########################

#
# Use traditional timestamp format.
# To enable high precision timestamps, comment out the following line.
#
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat

# Filter duplicated messages
$RepeatedMsgReduction on

#
# Set the default permissions for all log files.
#
$FileOwner syslog
$FileGroup adm
$FileCreateMode 0640
$DirCreateMode 0755
$Umask 0022
$PrivDropToUser syslog
$PrivDropToGroup syslog

#
# Where to place spool and state files
#
$WorkDirectory /var/spool/rsyslog

#
# Include all config files in /etc/rsyslog.d/
#
$IncludeConfig /etc/rsyslog.d/*.conf

###############################
#### CUSTOM LOGGING RULES #####
###############################

# Host Xiaomi_AX3600
template(name="CustomFile1" type="string" string="/!SambaOracleShare/log_Xiaomi_AX3600_(nasz_router).log")
if $hostname == 'Xiaomi_AX3600' then ?CustomFile1
& stop

# Dynamic file host creation (host name)
template(name="DynFile" type="string" string="/var/log/%HOSTNAME%.log")
*.* ?DynFile
& stop
  • /etc/rsyslog.d/21-cloudinit.conf:
# Log cloudinit generated log messages to file
:syslogtag, isequal, "[CLOUDINIT]" /var/log/cloud-init.log

# comment out the following line to allow CLOUDINIT messages through.
# Doing so means you'll also get CLOUDINIT messages in /var/log/syslog
& stop
  • /etc/rsyslog.d/50-default.conf:
#  Default rules for rsyslog.
#
#			For more information see rsyslog.conf(5) and /etc/rsyslog.conf

#
# First some standard log files.  Log by facility.
#
auth,authpriv.*			/var/log/auth.log
*.*;auth,authpriv.none		-/var/log/syslog
#cron.*				/var/log/cron.log
#daemon.*			-/var/log/daemon.log
kern.*				-/var/log/kern.log
#lpr.*				-/var/log/lpr.log
mail.*				-/var/log/mail.log
#user.*				-/var/log/user.log

#
# Logging for the mail system.  Split it up so that
# it is easy to write scripts to parse these files.
#
#mail.info			-/var/log/mail.info
#mail.warn			-/var/log/mail.warn
mail.err			/var/log/mail.err

#
# Some "catch-all" log files.
#
#*.=debug;\
#	auth,authpriv.none;\
#	news.none;mail.none	-/var/log/debug
#*.=info;*.=notice;*.=warn;\
#	auth,authpriv.none;\
#	cron,daemon.none;\
#	mail,news.none		-/var/log/messages

#
# Emergencies are sent to everybody logged in.
#
*.emerg				:omusrmsg:*

#
# I like to have messages displayed on the console, but only on a virtual
# console I usually leave idle.
#
#daemon,mail.*;\
#	news.=crit;news.=err;news.=notice;\
#	*.=debug;*.=info;\
#	*.=notice;*.=warn	/dev/tty8
  • /etc/rsyslog.d/20-ufw.conf:
# Log kernel generated UFW log messages to file
:msg,contains,"[UFW " /var/log/ufw.log

# Uncomment the following to stop logging anything that matches the last rule.
# Doing this will stop logging kernel generated UFW log messages to the file
# normally containing kern.* messages (eg, /var/log/kern.log)
#& stop

I would very much appreciate your guidance and help. Thank you in advance.

2

I'm using remote logs from openwrt to ubuntu very often, but with UDP, and to syslog-ng. Can not remember issue like yours. Thus, to investigate: Run tcpdump, both on your openwrt and ubuntu. To capture outgoing data from openwrt to server:514, and incoming on ubuntu. And then compare the captured data. Identical ? Outgoing matches lines from logread ?

3

Post output of

ubus call system board
4

Ofc, result here:

root@Xiaomi_AX3600:~# ubus call system board
{
        "kernel": "5.15.150",
        "hostname": "Xiaomi_AX3600",
        "system": "ARMv8 Processor rev 4",
        "model": "Xiaomi AX3600",
        "board_name": "xiaomi,ax3600",
        "rootfs_type": "squashfs",
        "release": {
                "distribution": "OpenWrt",
                "version": "23.05.3",
                "revision": "r23809-234f1a2efa",
                "target": "ipq807x/generic",
                "description": "OpenWrt 23.05.3 r23809-234f1a2efa"
        }
}
5

Guys, what do you think to try use syslog-ng instead of rsyslog? Wouldn't that repair the log transfer?

1 Like
6

Very unlikely, rsyslog is mature software and I wouldn't expect major issues on that end (misconfiguration is always possible though, remote syslogging is not exactly rocket science either).

7

Try to record tcpdump till some message is lost and check if it was on the wire.

8

@reinerotto @brada4 @slh guys, I changed protocol from TCP to UDP on OpenWRT and now it still looks good, all logs vere transfered correct but not always in the same order.
And unfortunately I also have no confirmation whether the logs have arrived or UDP.
Any further ideas?

As for tcpdump, I don't know how to use it and where I could save the tcp data.

9

Cannot make pcap for you

10

A first guess of mine is some type of overload or bug on the router, when using TCP for transmission of logs. Or some network issues, because of udp packets arriving out of order. Anyway, UDP works for you, too, so you might simply sort the received logs on the server. Yes, there is the risk of hidden loss of logs. Regarding tcpdump, you should educate yourself. Useful utility, anyway. In case, your router has USB port, use a memory stick to store logs. Also to catch logs generated, when network not available.

11

Or something with formatting like crlf or tab in whitespace, visible only in pcap.

12

I know that the best idea could be to save logs to file on USB storage but this router doesn't have a USB port.
I can try do a tcpdump I think but I am not sure where to store the data.
Another problem for me is that log fades over TCP happen intermittently and usually only a few hours after the router is up and running.
As for the status of the internet connection - the connection is there all the time.

13

You can store tcdump output to /tmp. cron job to stop tcpdump, compress output and restart tcpdump.

14

@brada4 @reinerotto
I took a packet dump for port 514 for both devices (OpenWRT router and Ubuntu server (rsyslog server)). I was worried that this file would grow in size much, much more, however it weighs less than 100 KB, so I am positively surprised.
I can also start to analyse the packages, but the question is what should I look for in them?
Furthermore, I would like to add that after stopping the packet dump on both systems during the same period of time, one can notice a certain discrepancy:

  • effect of stopping the tcpdump command on OpenWRT:
root@Xiaomi_AX3600:/tmp# tcpdump -i any port 514 -s 65535 -w tcpdumpXiaomiAX3600_17_07_2024__16_00
tcpdump: data link type LINUX_SLL2
tcpdump: listening on any, link-type LINUX_SLL2 (Linux cooked v2), snapshot length 65535 bytes
331 packets captured
333 packets received by filter
0 packets dropped by kernel
  • effect of stopping the tcpdump command on the Ubuntu server:
root@losalamosvps:~# sudo tcpdump -i any port 514 -s 65535 -w tcpdumpOracleVPS_17_07_2024__16_00
tcpdump: data link type LINUX_SLL2
tcpdump: listening on any, link-type LINUX_SLL2 (Linux cooked v2), snapshot length 65535 bytes
202 packets captured
202 packets received by filter
0 packets dropped by kernel

At first glance, it can be seen that some packages did not make it to the Ubuntu server at all.

Logs from the same time period (from the OpenWRT router and rsyslog server) are below al link.

Logs on OpenWRT router (tcpdump from 16.00 to 19.49)
Logs on Ubuntu server (rsyslog server) (tcpdump from 16.00 to 19.49)

15

Then, first of all you are on the wrong forum here, as openwrt not to blame :slight_smile: Packets sent, but not received ... network, your hoster for ubuntu, ubuntu firewall ...
You used tcp ?
You might compare the tcpdumps, which packets are lost. Large ones ? Sent with high frequency ? etc.

16

That not sounds good :confused:
But I certainly don't blame OpenWRT for this (by the way, I think the software is great and finally my network is functioning as it should!).
Perhaps someone will come up with an idea.

I'm using an Oracle VPS, and my list on it for port 514 looks like this:

image
image1232×491 16.2 KB

And when I enter sudo ufw status verbose on my server I got that the status is unactive so I think it should not block the tcp pockets.

And yea, for this test (tcpdump) I changed in OpenWRT to TCP.

17

Openwrt sent all packets. You obviously have to search to whatever modifies them on path.

18

On Wireshark I see that some TCP packets with data has "TCP Retransmission" status. So it looks like "unavailable destination IP adress"?

image
image1496×721 151 KB

19

There should be no loss of log messages with TCP.
It is still puzzliņg.

Check network stack(s} for dropped packets in predictable bottlenecks.

1 Like
20

Looks like incomplete TCP transactions cause loss of logged messages. Unknown reasons yet, only to speculate. I.e. some limits on your VPS, i.g. max no of connections, max no of connections per second etc. Or similar limits somewhere on the path from openwrt to VPS. Use UDP. Or try a more powerful VPS, in closer location. Or another ISP. I'm out now.

1 Like