Hotplug events with ACTION=ifdown fail to set the DEVICE parameter.
Username: David Ell
Origin: https://bugs.openwrt.org/index.php?do=details&task_id=1741
Device: TP-Link Archer C7 V2
OpenWRT Version: 18.06 r7204-8be3af93
Description:
The scripts in /etc/hotplug.d/iface/ are called during ifdown/ifup events, setting
the environment variables ACTION, INTERFACE and DEVICE.
The problem is the DEVICE variable is not being set for ACTION=ifdown.
In my case this causes a problem for the /etc/hotplug.d/iface/11-sqm script, because if
the DEVICE variable is blank, ALL configured SQM devices are brought down on ACTION=ifdown.
I created a DEBUG version of 11-sqm to show the problem and fix the DEVICE variable, but the
underlying source of the problem remains.
Debug version of /etc/hotplug.d/iface/11-sqm
#!/bin/sh
dell modified this file
if [ "${DEVICE}" = "" ]; then
if [ "${INTERFACE}" = "" ]; then
logger -t SQM-DEBUG /etc/hotplug.d/iface/11-sqm Called with ACTION={ACTION} INTERFACE=
{INTERFACE} DEVICE=${DEVICE} ... EXITING
exit 0
else
logger -t SQM-DEBUG /etc/hotplug.d/iface/11-sqm Called with ACTION={ACTION} INTERFACE=
{INTERFACE} DEVICE=${DEVICE}
if [ "(uci -q get network.
{INTERFACE}.type)" = "bridge" ]; then
DEVICE="br-${INTERFACE}"
else
DEVICE="(uci -q get network.
{INTERFACE}.ifname)"
fi
if [ "${DEVICE}" = "" ]; then
logger -t SQM-DEBUG /etc/hotplug.d/iface/11-sqm Unable to determine DEVICE ... exiting
exit 0
fi
logger -t SQM-DEBUG /etc/hotplug.d/iface/11-sqm MODIFIED CALLING WITH ACTION={ACTION} INTERFACE=
{INTERFACE} DEVICE=${DEVICE}
fi
else
logger -t SQM-DEBUG /etc/hotplug.d/iface/11-sqm Called with ACTION={ACTION} INTERFACE=
{INTERFACE} DEVICE=${DEVICE}
fi
restart_sqm() { /usr/lib/sqm/run.sh stop ${DEVICE} /usr/lib/sqm/run.sh start ${DEVICE} }
[ "$ACTION" = ifup ] && /etc/init.d/sqm enabled && restart_sqm
[ "$ACTION" = ifdown ] && /usr/lib/sqm/run.sh stop ${DEVICE}
OpenWRT Log showing the problem when different interfaces are brought down and up.
**** Log showing hotplug events with ACTION=ifdown called on scripts in /etc/hotplug.d/iface/ do not specify the DEVICE parameter. **** One effect is this causes ALL SQM configured interfaces to be brought down.
**** Look for SQM-DEBUG lines (my 11-sqm debug script), and SQM lines (system) to see what is happeining. **** My debug script inserts the proper DEVICE parameter ( see MODIFIED lines) so only the appropriate SQM interface is brouht down.
Sun Aug 5 21:50:57 2018 authpriv.info dropbear[19118]: Child connection from fd07:fb0e:52ba::db8:52120 Sun Aug 5 21:50:57 2018 authpriv.notice dropbear[19118]: Pubkey auth succeeded for 'root' with key sha1!! 11:f6:dc:6c:09:61:37:1d:9a:45:97:86:e5:c7:3a:b7:fa:d5:dc:7f from fd07:fb0e:52ba::db8:52120 Sun Aug 5 21:51:26 2018 daemon.err uhttpd[1763]: luci: accepted login on / for root from 192.168.1.167
**** Restart WAN interface from Luci
**** Note the hotplug event with ACTION=ifdown does not specify DEVICE (my debug script recreates the proper device).
Sun Aug 5 21:52:00 2018 user.notice SQM-DEBUG: /etc/hotplug.d/iface/11-sqm Called with ACTION=ifdown INTERFACE=wan DEVICE= Sun Aug 5 21:52:00 2018 user.notice SQM-DEBUG: /etc/hotplug.d/iface/11-sqm MODIFIED CALLING WITH ACTION=ifdown INTERFACE=wan DEVICE=eth0.2 Sun Aug 5 21:52:00 2018 daemon.notice netifd: wan (16000): udhcpc: received SIGTERM Sun Aug 5 21:52:00 2018 daemon.notice netifd: Interface 'wan' is now down Sun Aug 5 21:52:00 2018 daemon.notice netifd: Interface 'wan' is setting up now Sun Aug 5 21:52:00 2018 daemon.warn dnsmasq[15577]: no servers found in /tmp/resolv.conf.auto, will retry Sun Aug 5 21:52:01 2018 user.notice SQM: Stopping SQM on eth0.2 Sun Aug 5 21:52:01 2018 daemon.notice netifd: wan (19350): udhcpc: started, v1.28.3 Sun Aug 5 21:52:01 2018 daemon.notice netifd: wan (19350): udhcpc: sending discover Sun Aug 5 21:52:01 2018 daemon.err openvpn(torguard_client)[14487]: write UDP: Network unreachable (code=128) Sun Aug 5 21:52:02 2018 daemon.notice netifd: wan (19350): udhcpc: sending select for 206.212.230.237 Sun Aug 5 21:52:02 2018 daemon.notice netifd: wan (19350): udhcpc: lease of 206.212.230.237 obtained, lease time 86400 Sun Aug 5 21:52:02 2018 daemon.notice netifd: Interface 'wan' is now up Sun Aug 5 21:52:02 2018 daemon.info dnsmasq[15577]: reading /tmp/resolv.conf.auto Sun Aug 5 21:52:02 2018 daemon.info dnsmasq[15577]: using local addresses only for domain test Sun Aug 5 21:52:02 2018 daemon.info dnsmasq[15577]: using local addresses only for domain onion Sun Aug 5 21:52:02 2018 daemon.info dnsmasq[15577]: using local addresses only for domain localhost Sun Aug 5 21:52:02 2018 daemon.info dnsmasq[15577]: using local addresses only for domain local Sun Aug 5 21:52:02 2018 daemon.info dnsmasq[15577]: using local addresses only for domain invalid Sun Aug 5 21:52:02 2018 daemon.info dnsmasq[15577]: using local addresses only for domain bind Sun Aug 5 21:52:02 2018 daemon.info dnsmasq[15577]: using local addresses only for domain lan Sun Aug 5 21:52:02 2018 daemon.info dnsmasq[15577]: using nameserver 208.67.222.222#53 Sun Aug 5 21:52:02 2018 daemon.info dnsmasq[15577]: using nameserver 208.67.220.220#53
**** Note that hotplug event with ACTION=ifup correctly specifies the DEVICE parameter.
Sun Aug 5 21:52:02 2018 user.notice SQM-DEBUG: /etc/hotplug.d/iface/11-sqm Called with ACTION=ifup INTERFACE=wan DEVICE=eth0.2 Sun Aug 5 21:52:02 2018 user.notice SQM: Starting SQM script: layer_cake.qos on eth0.2, in: 9600 Kbps, out: 2000 Kbps Sun Aug 5 21:52:02 2018 daemon.err insmod: module is already loaded - sch_cake Sun Aug 5 21:52:02 2018 daemon.err insmod: module is already loaded - sch_ingress Sun Aug 5 21:52:02 2018 daemon.err insmod: module is already loaded - act_mirred Sun Aug 5 21:52:02 2018 daemon.err insmod: module is already loaded - cls_fw Sun Aug 5 21:52:02 2018 daemon.err insmod: module is already loaded - cls_flow Sun Aug 5 21:52:02 2018 daemon.err insmod: module is already loaded - cls_u32 Sun Aug 5 21:52:02 2018 daemon.err insmod: module is already loaded - sch_htb Sun Aug 5 21:52:02 2018 daemon.err insmod: module is already loaded - sch_hfsc Sun Aug 5 21:52:03 2018 user.notice SQM: layer_cake.qos was started on eth0.2 successfully Sun Aug 5 21:52:03 2018 user.notice firewall: Reloading firewall due to ifup of wan (eth0.2) Sun Aug 5 21:52:06 2018 user.notice ddns-scripts[19866]: myddns_ipv4: PID '19866' started at 2018-08-05 21:52 Sun Aug 5 21:52:08 2018 user.warn ddns-scripts[19866]: myddns_ipv4: Service section disabled! - TERMINATE Sun Aug 5 21:52:09 2018 user.warn ddns-scripts[19866]: myddns_ipv4: PID '19866' exit WITH ERROR '1' at 2018-08-05 21:52
**** Restarting the LAN interface from Luci
Sun Aug 5 21:52:32 2018 daemon.notice netifd: Interface 'lan' is now down Sun Aug 5 21:52:32 2018 kern.info kernel: [71559.952265] br-lan: port 2(wlan1) entered disabled state Sun Aug 5 21:52:32 2018 kern.info kernel: [71559.957785] br-lan: port 1(eth1.1) entered disabled state Sun Aug 5 21:52:32 2018 kern.info kernel: [71559.983346] device eth1.1 left promiscuous mode Sun Aug 5 21:52:32 2018 kern.info kernel: [71559.987984] device eth1 left promiscuous mode Sun Aug 5 21:52:32 2018 kern.info kernel: [71559.992556] br-lan: port 1(eth1.1) entered disabled state Sun Aug 5 21:52:32 2018 kern.info kernel: [71560.027381] IPv6: ADDRCONF(NETDEV_UP): eth1.1: link is not ready
**** Note the hotplug event with ACTION=ifdown does not include DEVICE parameter
Sun Aug 5 21:52:32 2018 user.notice SQM-DEBUG: /etc/hotplug.d/iface/11-sqm Called with ACTION=ifdown INTERFACE=lan DEVICE= Sun Aug 5 21:52:32 2018 kern.info kernel: [71560.059335] eth1: link down Sun Aug 5 21:52:32 2018 user.notice SQM-DEBUG: /etc/hotplug.d/iface/11-sqm MODIFIED CALLING WITH ACTION=ifdown INTERFACE=lan DEVICE=br-lan Sun Aug 5 21:52:32 2018 kern.info kernel: [71560.081604] device wlan1 left promiscuous mode Sun Aug 5 21:52:32 2018 kern.info kernel: [71560.086211] br-lan: port 2(wlan1) entered disabled state Sun Aug 5 21:52:32 2018 daemon.notice netifd: Interface 'lan' is disabled Sun Aug 5 21:52:32 2018 daemon.err odhcpd[1308]: setsockopt(IPV6_ADD_MEMBERSHIP): No such device Sun Aug 5 21:52:32 2018 daemon.err odhcpd[1308]: setsockopt(SO_BINDTODEVICE): No such device Sun Aug 5 21:52:32 2018 daemon.notice netifd: VLAN 'eth1.1' link is down Sun Aug 5 21:52:32 2018 daemon.notice netifd: bridge 'br-lan' link is down Sun Aug 5 21:52:32 2018 daemon.notice netifd: Interface 'lan' has link connectivity loss Sun Aug 5 21:52:32 2018 daemon.notice netifd: Network device 'eth1' link is down Sun Aug 5 21:52:33 2018 kern.info kernel: [71560.176382] eth1: link up (1000Mbps/Full duplex) Sun Aug 5 21:52:33 2018 kern.info kernel: [71560.214139] br-lan: port 1(eth1.1) entered blocking state Sun Aug 5 21:52:33 2018 kern.info kernel: [71560.219686] br-lan: port 1(eth1.1) entered disabled state Sun Aug 5 21:52:33 2018 kern.info kernel: [71560.225526] device eth1.1 entered promiscuous mode Sun Aug 5 21:52:33 2018 kern.info kernel: [71560.230424] device eth1 entered promiscuous mode Sun Aug 5 21:52:33 2018 daemon.info dnsmasq[15577]: read /etc/hosts - 4 addresses Sun Aug 5 21:52:33 2018 daemon.info dnsmasq[15577]: read /tmp/hosts/odhcpd - 0 addresses Sun Aug 5 21:52:33 2018 daemon.info dnsmasq[15577]: read /tmp/hosts/dhcp.cfg01411c - 7 addresses Sun Aug 5 21:52:33 2018 daemon.info dnsmasq-dhcp[15577]: read /etc/ethers - 0 addresses Sun Aug 5 21:52:33 2018 kern.info kernel: [71560.310085] br-lan: port 2(wlan1) entered blocking state Sun Aug 5 21:52:33 2018 kern.info kernel: [71560.315572] br-lan: port 2(wlan1) entered disabled state Sun Aug 5 21:52:33 2018 kern.info kernel: [71560.321326] device wlan1 entered promiscuous mode Sun Aug 5 21:52:33 2018 kern.info kernel: [71560.367445] br-lan: port 2(wlan1) entered blocking state Sun Aug 5 21:52:33 2018 kern.info kernel: [71560.372845] br-lan: port 2(wlan1) entered forwarding state Sun Aug 5 21:52:33 2018 kern.info kernel: [71560.378527] br-lan: port 1(eth1.1) entered blocking state Sun Aug 5 21:52:33 2018 kern.info kernel: [71560.384004] br-lan: port 1(eth1.1) entered forwarding state Sun Aug 5 21:52:33 2018 daemon.notice netifd: Interface 'lan' is enabled Sun Aug 5 21:52:33 2018 daemon.notice netifd: Interface 'lan' is setting up now Sun Aug 5 21:52:33 2018 daemon.notice netifd: Interface 'lan' is now up Sun Aug 5 21:52:33 2018 daemon.notice netifd: bridge 'br-lan' link is up Sun Aug 5 21:52:33 2018 daemon.notice netifd: Interface 'lan' has link connectivity Sun Aug 5 21:52:33 2018 daemon.notice netifd: Network device 'eth1' link is up Sun Aug 5 21:52:33 2018 daemon.notice netifd: VLAN 'eth1.1' link is up Sun Aug 5 21:52:34 2018 daemon.notice hostapd: wlan1: interface state ENABLED->DISABLED Sun Aug 5 21:52:34 2018 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED 94:65:2d:6c:f7:34 Sun Aug 5 21:52:34 2018 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED dc:bf:e9:af:8a:9a Sun Aug 5 21:52:34 2018 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED ac:22:0b:5d:b5:cf Sun Aug 5 21:52:34 2018 daemon.notice hostapd: wlan1: AP-DISABLED Sun Aug 5 21:52:34 2018 daemon.notice hostapd: wlan1: CTRL-EVENT-TERMINATING Sun Aug 5 21:52:34 2018 daemon.notice hostapd: nl80211: deinit ifname=wlan1 disabled_11b_rates=0 Sun Aug 5 21:52:34 2018 kern.info kernel: [71561.433522] device wlan1 left promiscuous mode Sun Aug 5 21:52:34 2018 kern.info kernel: [71561.438190] br-lan: port 2(wlan1) entered disabled state
**** Note the hotplug event with ACTION=ifup correctly specifies DEVICE
Sun Aug 5 21:52:34 2018 user.notice SQM-DEBUG: /etc/hotplug.d/iface/11-sqm Called with ACTION=ifup INTERFACE=lan DEVICE=br-lan Sun Aug 5 21:52:34 2018 daemon.notice netifd: Network device 'wlan1' link is down Sun Aug 5 21:52:35 2018 user.notice firewall: Reloading firewall due to ifup of lan (br-lan) Sun Aug 5 21:52:35 2018 daemon.info dnsmasq[15577]: read /etc/hosts - 4 addresses Sun Aug 5 21:52:35 2018 daemon.info dnsmasq[15577]: read /tmp/hosts/odhcpd - 2 addresses Sun Aug 5 21:52:35 2018 daemon.info dnsmasq[15577]: read /tmp/hosts/dhcp.cfg01411c - 7 addresses Sun Aug 5 21:52:35 2018 daemon.info dnsmasq-dhcp[15577]: read /etc/ethers - 0 addresses Sun Aug 5 21:52:36 2018 daemon.err hostapd: Configuration file: /var/run/hostapd-phy1.conf Sun Aug 5 21:52:36 2018 kern.info kernel: [71563.789521] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready Sun Aug 5 21:52:36 2018 kern.info kernel: [71563.994859] br-lan: port 2(wlan1) entered blocking state Sun Aug 5 21:52:36 2018 kern.info kernel: [71564.000337] br-lan: port 2(wlan1) entered disabled state Sun Aug 5 21:52:36 2018 kern.info kernel: [71564.006051] device wlan1 entered promiscuous mode Sun Aug 5 21:52:36 2018 daemon.notice hostapd: wlan1: interface state UNINITIALIZED->COUNTRY_UPDATE Sun Aug 5 21:52:36 2018 daemon.notice hostapd: wlan1: interface state COUNTRY_UPDATE->HT_SCAN Sun Aug 5 21:52:38 2018 daemon.notice hostapd: handle_probe_req: send failed Sun Aug 5 21:52:38 2018 daemon.notice hostapd: handle_probe_req: send failed Sun Aug 5 21:52:38 2018 daemon.notice hostapd: handle_probe_req: send failed Sun Aug 5 21:52:38 2018 daemon.notice hostapd: handle_probe_req: send failed Sun Aug 5 21:52:38 2018 daemon.notice hostapd: handle_probe_req: send failed Sun Aug 5 21:52:38 2018 daemon.notice hostapd: handle_probe_req: send failed Sun Aug 5 21:52:38 2018 daemon.notice hostapd: handle_probe_req: send failed Sun Aug 5 21:52:38 2018 daemon.notice hostapd: handle_probe_req: send failed Sun Aug 5 21:52:38 2018 daemon.notice hostapd: handle_probe_req: send failed Sun Aug 5 21:52:38 2018 daemon.notice hostapd: handle_probe_req: send failed Sun Aug 5 21:52:38 2018 daemon.notice hostapd: handle_probe_req: send failed Sun Aug 5 21:52:38 2018 daemon.notice hostapd: handle_probe_req: send failed Sun Aug 5 21:52:38 2018 daemon.notice hostapd: 20/40 MHz operation not permitted on channel pri=6 sec=10 based on overlapping BSSes Sun Aug 5 21:52:38 2018 daemon.err hostapd: Using interface wlan1 with hwaddr 30:b5:c2:96:70:c9 and ssid "CatDen-router" Sun Aug 5 21:52:38 2018 daemon.info dnsmasq[15577]: read /etc/hosts - 4 addresses Sun Aug 5 21:52:38 2018 daemon.info dnsmasq[15577]: read /tmp/hosts/odhcpd - 2 addresses Sun Aug 5 21:52:38 2018 daemon.info dnsmasq[15577]: read /tmp/hosts/dhcp.cfg01411c - 7 addresses Sun Aug 5 21:52:38 2018 daemon.info dnsmasq-dhcp[15577]: read /etc/ethers - 0 addresses Sun Aug 5 21:52:38 2018 kern.info kernel: [71566.021420] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready Sun Aug 5 21:52:38 2018 kern.info kernel: [71566.028048] br-lan: port 2(wlan1) entered blocking state Sun Aug 5 21:52:38 2018 kern.info kernel: [71566.033444] br-lan: port 2(wlan1) entered forwarding state Sun Aug 5 21:52:38 2018 daemon.notice hostapd: wlan1: interface state HT_SCAN->ENABLED Sun Aug 5 21:52:38 2018 daemon.notice hostapd: wlan1: AP-ENABLED Sun Aug 5 21:52:38 2018 daemon.notice netifd: Network device 'wlan1' link is up Sun Aug 5 21:52:41 2018 daemon.info hostapd: wlan1: STA 94:65:2d:6c:f7:34 IEEE 802.11: authenticated Sun Aug 5 21:52:41 2018 daemon.info hostapd: wlan1: STA 94:65:2d:6c:f7:34 IEEE 802.11: associated (aid 1) Sun Aug 5 21:52:41 2018 daemon.notice hostapd: wlan1: AP-STA-CONNECTED 94:65:2d:6c:f7:34 Sun Aug 5 21:52:41 2018 daemon.info hostapd: wlan1: STA 94:65:2d:6c:f7:34 WPA: pairwise key handshake completed (RSN) Sun Aug 5 21:52:41 2018 daemon.info dnsmasq-dhcp[15577]: DHCPDISCOVER(br-lan) 94:65:2d:6c:f7:34 Sun Aug 5 21:52:41 2018 daemon.info dnsmasq-dhcp[15577]: DHCPOFFER(br-lan) 192.168.1.169 94:65:2d:6c:f7:34 Sun Aug 5 21:52:41 2018 daemon.info dnsmasq-dhcp[15577]: DHCPREQUEST(br-lan) 192.168.1.169 94:65:2d:6c:f7:34 Sun Aug 5 21:52:41 2018 daemon.info dnsmasq-dhcp[15577]: DHCPACK(br-lan) 192.168.1.169 94:65:2d:6c:f7:34 OnePlus_5 Sun Aug 5 21:52:42 2018 daemon.info hostapd: wlan1: STA dc:bf:e9:af:8a:9a IEEE 802.11: authenticated Sun Aug 5 21:52:42 2018 daemon.info hostapd: wlan1: STA dc:bf:e9:af:8a:9a IEEE 802.11: associated (aid 2) Sun Aug 5 21:52:42 2018 daemon.notice hostapd: wlan1: AP-STA-CONNECTED dc:bf:e9:af:8a:9a Sun Aug 5 21:52:42 2018 daemon.info hostapd: wlan1: STA dc:bf:e9:af:8a:9a WPA: pairwise key handshake completed (RSN) Sun Aug 5 21:52:43 2018 daemon.info dnsmasq-dhcp[15577]: DHCPDISCOVER(br-lan) dc:bf:e9:af:8a:9a Sun Aug 5 21:52:43 2018 daemon.info dnsmasq-dhcp[15577]: DHCPOFFER(br-lan) 192.168.1.125 dc:bf:e9:af:8a:9a Sun Aug 5 21:52:43 2018 daemon.info dnsmasq-dhcp[15577]: DHCPREQUEST(br-lan) 192.168.1.125 dc:bf:e9:af:8a:9a Sun Aug 5 21:52:43 2018 daemon.info dnsmasq-dhcp[15577]: DHCPACK(br-lan) 192.168.1.125 dc:bf:e9:af:8a:9a android-e91ad6b278c61985 Sun Aug 5 21:52:49 2018 daemon.info hostapd: wlan1: STA ac:22:0b:5d:b5:cf IEEE 802.11: authenticated Sun Aug 5 21:52:49 2018 daemon.info hostapd: wlan1: STA ac:22:0b:5d:b5:cf IEEE 802.11: associated (aid 3) Sun Aug 5 21:52:49 2018 daemon.notice hostapd: wlan1: AP-STA-CONNECTED ac:22:0b:5d:b5:cf Sun Aug 5 21:52:49 2018 daemon.info hostapd: wlan1: STA ac:22:0b:5d:b5:cf WPA: pairwise key handshake completed (RSN) Sun Aug 5 21:52:50 2018 daemon.info dnsmasq-dhcp[15577]: DHCPDISCOVER(br-lan) ac:22:0b:5d:b5:cf Sun Aug 5 21:52:50 2018 daemon.info dnsmasq-dhcp[15577]: DHCPOFFER(br-lan) 192.168.1.142 ac:22:0b:5d:b5:cf Sun Aug 5 21:52:50 2018 daemon.info dnsmasq-dhcp[15577]: DHCPREQUEST(br-lan) 192.168.1.142 ac:22:0b:5d:b5:cf Sun Aug 5 21:52:50 2018 daemon.info dnsmasq-dhcp[15577]: DHCPACK(br-lan) 192.168.1.142 ac:22:0b:5d:b5:cf android-41e25fe580fa511f
**** openvpn is restarted using /etc/init.d/openvpn restart
Sun Aug 5 21:53:03 2018 daemon.err openvpn(torguard_client)[14487]: event_wait : Interrupted system call (code=4) Sun Aug 5 21:53:03 2018 daemon.notice openvpn(torguard_client)[14487]: /sbin/ifconfig tun0 0.0.0.0 Sun Aug 5 21:53:03 2018 daemon.notice netifd: Network device 'tun0' link is down Sun Aug 5 21:53:03 2018 daemon.notice netifd: Interface 'vpn' has link connectivity loss Sun Aug 5 21:53:03 2018 daemon.notice netifd: Interface 'vpn' is now down Sun Aug 5 21:53:03 2018 daemon.notice openvpn(torguard_client)[14487]: /etc/openvpn/down.sh tun0 1500 1585 10.9.0.6 10.9.0.5 init Sun Aug 5 21:53:03 2018 daemon.notice openvpn(torguard_client)[14487]: SIGTERM[hard,] received, process exiting
**** Note hotplug called with ACTION=ifdown and no DEVICE specified
Sun Aug 5 21:53:03 2018 user.notice SQM-DEBUG: /etc/hotplug.d/iface/11-sqm Called with ACTION=ifdown INTERFACE=vpn DEVICE= Sun Aug 5 21:53:03 2018 user.notice SQM-DEBUG: /etc/hotplug.d/iface/11-sqm MODIFIED CALLING WITH ACTION=ifdown INTERFACE=vpn DEVICE=tun0 Sun Aug 5 21:53:03 2018 daemon.notice netifd: Interface 'vpn' is disabled Sun Aug 5 21:53:03 2018 user.notice SQM: Stopping SQM on tun0 Sun Aug 5 21:53:04 2018 daemon.notice openvpn(torguard_client)[21573]: OpenVPN 2.4.5 mips-openwrt-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] Sun Aug 5 21:53:04 2018 daemon.notice openvpn(torguard_client)[21573]: library versions: OpenSSL 1.0.2o 27 Mar 2018, LZO 2.10 Sun Aug 5 21:53:04 2018 daemon.warn openvpn(torguard_client)[21573]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts Sun Aug 5 21:53:04 2018 daemon.notice openvpn(torguard_client)[21573]: TCP/UDP: Preserving recently used remote address: [AF_INET]204.44.121.194:443 Sun Aug 5 21:53:04 2018 daemon.notice openvpn(torguard_client)[21573]: UDP link local: (not bound) Sun Aug 5 21:53:04 2018 daemon.notice openvpn(torguard_client)[21573]: UDP link remote: [AF_INET]204.44.121.194:443 Sun Aug 5 21:53:04 2018 daemon.warn openvpn(torguard_client)[21573]: WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this Sun Aug 5 21:53:04 2018 daemon.warn openvpn(torguard_client)[21573]: WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1574', remote='link-mtu 1542' Sun Aug 5 21:53:04 2018 daemon.warn openvpn(torguard_client)[21573]: WARNING: 'tun-mtu' is used inconsistently, local='tun-mtu 1532', remote='tun-mtu 1500' Sun Aug 5 21:53:04 2018 daemon.notice openvpn(torguard_client)[21573]: [TG-OVPN-CA] Peer Connection Initiated with [AF_INET]204.44.121.194:443 Sun Aug 5 21:53:05 2018 daemon.err openvpn(torguard_client)[21573]: Options error: option 'redirect-gateway' cannot be used in this context ([PUSH-OPTIONS]) Sun Aug 5 21:53:05 2018 daemon.err openvpn(torguard_client)[21573]: Options error: option 'dhcp-option' cannot be used in this context ([PUSH-OPTIONS]) Sun Aug 5 21:53:05 2018 daemon.err openvpn(torguard_client)[21573]: Options error: option 'dhcp-option' cannot be used in this context ([PUSH-OPTIONS]) Sun Aug 5 21:53:05 2018 daemon.err openvpn(torguard_client)[21573]: Options error: option 'route' cannot be used in this context ([PUSH-OPTIONS]) Sun Aug 5 21:53:05 2018 daemon.notice netifd: Interface 'vpn' is enabled Sun Aug 5 21:53:05 2018 daemon.notice netifd: Network device 'tun0' link is up Sun Aug 5 21:53:05 2018 daemon.notice netifd: Interface 'vpn' has link connectivity Sun Aug 5 21:53:05 2018 daemon.notice netifd: Interface 'vpn' is setting up now Sun Aug 5 21:53:05 2018 daemon.notice netifd: Interface 'vpn' is now up Sun Aug 5 21:53:05 2018 daemon.notice openvpn(torguard_client)[21573]: TUN/TAP device tun0 opened Sun Aug 5 21:53:05 2018 daemon.notice openvpn(torguard_client)[21573]: do_ifconfig, tt->did_ifconfig_ipv6_setup=0 Sun Aug 5 21:53:05 2018 daemon.notice openvpn(torguard_client)[21573]: /sbin/ifconfig tun0 10.9.0.6 pointopoint 10.9.0.5 mtu 1500 Sun Aug 5 21:53:05 2018 daemon.notice openvpn(torguard_client)[21573]: /etc/openvpn/up.sh tun0 1500 1585 10.9.0.6 10.9.0.5 init
**** Note hotplug called with ACTION=ifup and correct DEVICE
Sun Aug 5 21:53:05 2018 user.notice SQM-DEBUG: /etc/hotplug.d/iface/11-sqm Called with ACTION=ifup INTERFACE=vpn DEVICE=tun0 Sun Aug 5 21:53:06 2018 user.notice SQM: Starting SQM script: piece_of_cake.qos on tun0, in: 8000 Kbps, out: 1700 Kbps Sun Aug 5 21:53:06 2018 daemon.err insmod: module is already loaded - sch_cake Sun Aug 5 21:53:06 2018 daemon.err insmod: module is already loaded - sch_ingress Sun Aug 5 21:53:06 2018 daemon.err insmod: module is already loaded - act_mirred Sun Aug 5 21:53:06 2018 daemon.err insmod: module is already loaded - cls_fw Sun Aug 5 21:53:06 2018 daemon.err insmod: module is already loaded - cls_flow Sun Aug 5 21:53:06 2018 daemon.err insmod: module is already loaded - cls_u32 Sun Aug 5 21:53:06 2018 daemon.err insmod: module is already loaded - sch_htb Sun Aug 5 21:53:06 2018 daemon.err insmod: module is already loaded - sch_hfsc Sun Aug 5 21:53:07 2018 user.notice SQM: piece_of_cake.qos was started on tun0 successfully Sun Aug 5 21:53:07 2018 user.notice firewall: Reloading firewall due to ifup of vpn (tun0) Sun Aug 5 21:53:07 2018 daemon.notice openvpn(torguard_client)[21573]: Initialization Sequence Completed