OpenVPN Requires Log service to be restarted

OpenWrt 23.05.3
OpenVPN 2.6.11

My device uses remote logging via UDP so UCI system settings are:

system.@system[0]=system
system.@system[0].log_size='64'
system.@system[0].log_port='514'
system.@system[0].log_proto='udp'
system.@system[0].log_ip='<remote rlog server ip>'
system.@system[0].log_remote='1'

To reproduce:
Start the device
Log service starts as normal and commences remote logging as normal
OpenVPN starts and connects to remote server
Logger no longer logs to the remote server
Restart log service (service log restart)
Logger commences remote logging as normal

I suspected this was a firewall issue, but disabling the firewall doesn't change the behaviour at all.

I wondered if it was a routing issue but since UDP is connectionless I'd expect the route would be determined on each log send, so tat wouldn't make sense.

Before I start digging in to the code, I wondered if anyone else had this same experience.

As a workaround I made a hotplug script.

#!/bin/sh
#
# Place this file in /etc/hotplug.d/net/65-vpn-ifadd
#
vpn_interface="tun0"

if [ "$ACTION" = "add" -a "$INTERFACE" = "$vpn_interface" ]; then
        service log restart
fi

Most likely syslog doesn't like the change of the routing from the VPN.

  1. Is the remote syslog reachable over a different network than the ones that OpenWrt is? Meaning do you need to go through the internet to reach the syslog, or is it a server in the lan?
  2. Do you still see syslog packets leaving from OpenWrt or they stop? (with help from tcpdump).

@trendy Thanks for the reply. Before the VPN comes up the remote host is accessed via the external facing IP of my DMZ so it is not accessible via my LAN other than going out to the internet then back through my ISP to my external IP. I originally suspected the external IP was accessible via my LAN directly but traceroute shows me that is not the case. However even if this were the case, why would that effect a UDP since it's connectionless, so each new log request would presumably follow what ever routing was in place on each log request.

I can see that logger is sending packets via apcli0 with no VPN. When the VPN is up it switches to sending via tun0. This is expected behaviour. Restarting the log service doesn't change any of this.

Please run the following commands (copy-paste the whole block) and paste the output here, using the "Preformatted text </> " button:
grafik
Remember to redact passwords, MAC addresses and any public IP addresses you may have

ubus call system board; \
uci export network; uci export system; \
uci export dhcp; uci export firewall; \
ip -4 addr ; ip -4 ro li tab all ; ip -4 ru

Run the last 3 commands with VPN down and then up.

@trendy Requested info below. There is no firewall details included as it's disabled.

ubus call system board; 
{
        "kernel": "6.6.34",
        "hostname": "########",
        "system": "MediaTek MT7688 ver:1 eco:2",
        "model": "Onion Omega2Pro",
        "board_name": "onion,omega2pro",
        "rootfs_type": "squashfs",
        "release": {
                "distribution": "OpenWrt",
                "version": "SNAPSHOT",
                "revision": "r26749-403c77ffbe",
                "target": "ramips/mt76x8",
                "description": "OpenWrt SNAPSHOT r26749-403c77ffbe"
        }
}

// dhcp - not used.

//Network

config interface 'loopback'
        option device 'lo'
        option proto 'static'
        option ipaddr '127.0.0.1'
        option netmask '255.0.0.0'

config globals 'globals'
        option ula_prefix 'fdb2:2708:4969::/48'

config device
        option name 'br-lan'
        option type 'bridge'
        list ports 'eth0'

config interface 'lan'
        option device 'br-lan'
        option proto 'dhcp'
        option ip6assign '60'

config interface 'wwan'
        option proto 'dhcp'
        option hostname '############'
        option device 'apcli0'
        option macaddr '##:##:##:c3:20:58'

// System

config system
        option log_size '64'
        option urandom_seed '0'
        option cronloglevel '8'
        option timezone 'AEST-10AEDT,M10.1.0,M4.1.0/3'
        option zonename 'Canberra, Melbourne, Sydney'
        option log_port '5140'
        option log_proto 'udp'
        option ttylogin '1'
        option log_ip '124.###.###.###'
        option hostname '############'
        option log_remote '1'
        option compat_version '1.0'

config timeserver 'ntp'
        option enabled '1'
        option enable_server '0'
        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'


// ip -4 addr - with VPN

 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN qlen 1000
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
7: apcli0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP qlen 1000
    inet 192.168.1.128/24 brd 192.168.1.255 scope global apcli0
       valid_lft forever preferred_lft forever
8: tun0: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UNKNOWN qlen 500
    inet 10.96.0.8/16 scope global tun0
       valid_lft forever preferred_lft forever
       
       
// ip -4 addr - no VPN
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN qlen 1000
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
7: apcli0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP qlen 1000
    inet 192.168.1.128/24 brd 192.168.1.255 scope global apcli0
       valid_lft forever preferred_lft forever

       
       
//ip -4 ro li tab all - with VPN
0.0.0.0/1 via 10.96.0.1 dev tun0 
default via 192.168.1.1 dev apcli0  src 192.168.1.128 
10.96.0.0/16 dev tun0 scope link  src 10.96.0.8 
128.0.0.0/1 via 10.96.0.1 dev tun0 
185.159.###.### via 192.168.1.1 dev apcli0 
192.168.1.0/24 dev apcli0 scope link  src 192.168.1.128 
local 10.96.0.8 dev tun0 table local scope host  src 10.96.0.8 
broadcast 10.96.255.255 dev tun0 table local scope link  src 10.96.0.8 
local 127.0.0.0/8 dev lo table local scope host  src 127.0.0.1 
local 127.0.0.1 dev lo table local scope host  src 127.0.0.1 
broadcast 127.255.255.255 dev lo table local scope link  src 127.0.0.1 
local 192.168.1.128 dev apcli0 table local scope host  src 192.168.1.128 
broadcast 192.168.1.255 dev apcli0 table local scope link  src 192.168.1.128 
       
// ip -4 ro li tab all - no VPN
default via 192.168.1.1 dev apcli0  src 192.168.1.128 
192.168.1.0/24 dev apcli0 scope link  src 192.168.1.128 
local 127.0.0.0/8 dev lo table local scope host  src 127.0.0.1 
local 127.0.0.1 dev lo table local scope host  src 127.0.0.1 
broadcast 127.255.255.255 dev lo table local scope link  src 127.0.0.1 
local 192.168.1.128 dev apcli0 table local scope host  src 192.168.1.128 
broadcast 192.168.1.255 dev apcli0 table local scope link  src 192.168.1.128 
    
//ip -4 ru  - with VPN
0:      from all lookup local 
32766:  from all lookup main 
32767:  from all lookup default 

//ip -4 ru - no VPN
0:      from all lookup local 
32766:  from all lookup main 
32767:  from all lookup default 


But here is the firewall anyway and yes I have checked the firewall is disabled and not running.

firewall.@defaults[0]=defaults
firewall.@defaults[0].syn_flood='1'
firewall.@defaults[0].input='REJECT'
firewall.@defaults[0].output='ACCEPT'
firewall.@defaults[0].forward='REJECT'
firewall.@zone[0]=zone
firewall.@zone[0].name='lan'
firewall.@zone[0].network='lan'
firewall.@zone[0].input='ACCEPT'
firewall.@zone[0].output='ACCEPT'
firewall.@zone[0].forward='ACCEPT'
firewall.@zone[1]=zone
firewall.@zone[1].name='wan'
firewall.@zone[1].network='wan' 'wan6'
firewall.@zone[1].input='REJECT'
firewall.@zone[1].output='ACCEPT'
firewall.@zone[1].forward='REJECT'
firewall.@zone[1].masq='1'
firewall.@zone[1].mtu_fix='1'
firewall.@forwarding[0]=forwarding
firewall.@forwarding[0].src='lan'
firewall.@forwarding[0].dest='wan'
firewall.@rule[0]=rule
firewall.@rule[0].name='Allow-DHCP-Renew'
firewall.@rule[0].src='wan'
firewall.@rule[0].proto='udp'
firewall.@rule[0].dest_port='68'
firewall.@rule[0].target='ACCEPT'
firewall.@rule[0].family='ipv4'
firewall.@rule[1]=rule
firewall.@rule[1].name='Allow-Ping'
firewall.@rule[1].src='wan'
firewall.@rule[1].proto='icmp'
firewall.@rule[1].icmp_type='echo-request'
firewall.@rule[1].family='ipv4'
firewall.@rule[1].target='ACCEPT'
firewall.@rule[2]=rule
firewall.@rule[2].name='Allow-IGMP'
firewall.@rule[2].src='wan'
firewall.@rule[2].proto='igmp'
firewall.@rule[2].family='ipv4'
firewall.@rule[2].target='ACCEPT'
firewall.@rule[3]=rule
firewall.@rule[3].name='Allow-DHCPv6'
firewall.@rule[3].src='wan'
firewall.@rule[3].proto='udp'
firewall.@rule[3].dest_port='546'
firewall.@rule[3].family='ipv6'
firewall.@rule[3].target='ACCEPT'
firewall.@rule[4]=rule
firewall.@rule[4].name='Allow-MLD'
firewall.@rule[4].src='wan'
firewall.@rule[4].proto='icmp'
firewall.@rule[4].src_ip='fe80::/10'
firewall.@rule[4].icmp_type='130/0' '131/0' '132/0' '143/0'
firewall.@rule[4].family='ipv6'
firewall.@rule[4].target='ACCEPT'
firewall.@rule[5]=rule
firewall.@rule[5].name='Allow-ICMPv6-Input'
firewall.@rule[5].src='wan'
firewall.@rule[5].proto='icmp'
firewall.@rule[5].icmp_type='echo-request' 'echo-reply' 'destination-unreachable' 'packet-too-big' 'time-exceeded' 'bad-header' 'unknown-header-type' 'router-solicitation' 'neighbour-solici'
firewall.@rule[5].limit='1000/sec'
firewall.@rule[5].family='ipv6'
firewall.@rule[5].target='ACCEPT'
firewall.@rule[6]=rule
firewall.@rule[6].name='Allow-ICMPv6-Forward'
firewall.@rule[6].src='wan'
firewall.@rule[6].dest='*'
firewall.@rule[6].proto='icmp'
firewall.@rule[6].icmp_type='echo-request' 'echo-reply' 'destination-unreachable' 'packet-too-big' 'time-exceeded' 'bad-header' 'unknown-header-type'
firewall.@rule[6].limit='1000/sec'
firewall.@rule[6].family='ipv6'
firewall.@rule[6].target='ACCEPT'
firewall.@rule[7]=rule
firewall.@rule[7].name='Allow-IPSec-ESP'
firewall.@rule[7].src='wan'
firewall.@rule[7].dest='lan'
firewall.@rule[7].proto='esp'
firewall.@rule[7].target='ACCEPT'
firewall.@rule[8]=rule
firewall.@rule[8].name='Allow-ISAKMP'
firewall.@rule[8].src='wan'
firewall.@rule[8].dest='lan'
firewall.@rule[8].dest_port='500'
firewall.@rule[8].proto='udp'
firewall.@rule[8].target='ACCEPT'
firewall.@zone[2]=zone
firewall.@zone[2].name='wan'
firewall.@zone[2].input='ACCEPT'
firewall.@zone[2].output='ACCEPT'
firewall.@zone[2].forward='REJECT'
firewall.@zone[2].device='tun0'
firewall.@zone[3]=zone
firewall.@zone[3].name='wwan'
firewall.@zone[3].input='ACCEPT'
firewall.@zone[3].output='ACCEPT'
firewall.@zone[3].forward='REJECT'
firewall.@zone[3].network='wwan'
firewall.@zone[3].device='tun0'

In this case the simple workaround is to create a static route for the syslog server via the wwan interface so that it won't be redirected to the vpn when it comes up. As you mentioned, the packets of the syslog use vpn interface when the latter is up, hence you'd need to troubleshoot where are the packets lost.

Thanks @trendy but this brings me back to my original question. Why does restarting the log service after bringing the VPN up fix the issue, when UDP is connectionless.

I don't want a static route through wwan interface (apcli0) because I want logging to go through the VPN because it may contain sensitive information. Other service like ntp nd email are unaffected.

I'll take a look at the code, I wonder if the log service maybe stores the interface internally.

Thanks for looking at this for me, I'll report what I find.

1 Like