Routing problem when setting up shared access point

Ankan · November 12, 2021, 10:49pm

Sometimes routing doesn’t work or stop working after some time.

My Balena device have connection to internet and can connect to Balena Cloud. Wifi clients are connected to my Balena device AP and can connect to server running in container but not always connect to internet even if Balena device have internet access.

I don’t know how to troubleshoot this.

This is my Wifi AP settings:

[connection]
id=balena-hotspot
uuid=36060c57-aebd-4ccf-aba4-ef75121b5f77
type=wifi
autoconnect=true
interface-name=wlan0
permissions=
secondaries=

[wifi]
band=bg
mac-address-blacklist=
mac-address-randomization=0
mode=ap
seen-bssids=
ssid=PLACE_SSID_HERE

[wifi-security]
group=
key-mgmt=wpa-psk
pairwise=
proto=rsn
psk=PLACE_YOUR_PASSWORD_HERE

[ipv4]
address1=192.168.1.1/24
dns-search=
#method=auto
method=shared

[ipv6]
addr-gen-mode=stable-privacy
dns-search=
method=ignore

Cellular settings:

[connection]
id=cellular
type=gsm
autoconnect=true
autoconnect-retries=0

[gsm]
auto-config=true
apn=online.telia.se

[serial]
baud=115200

[ipv4]
method=auto

[ipv6]
addr-gen-mode=stable-privacy
method=auto

ip route output

default via 100.95.135.50 dev wwan0  metric 700
10.114.101.0/24 dev balena0 scope link  src 10.114.101.1
10.114.102.0/24 dev resin-dns scope link  src 10.114.102.1
10.114.104.0/25 dev supervisor0 scope link  src 10.114.104.1
52.4.252.97 dev resin-vpn scope link  src 10.240.71.229
100.95.135.48/30 dev wwan0 scope link  src 100.95.135.49  metric 700
172.17.0.0/16 dev br-90b27d41c0f5 scope link  src 172.17.0.1
192.168.1.0/24 dev wlan0 scope link  src 192.168.1.1  metric 600

Ankan · November 18, 2021, 8:37am

I get this routing problem on first start and from time to time after reboot. I feels like there is a racing condition where I get this problem if wifi client connect to fast before something is not ready.

Because if I restart wifi with

nmcli con up id balena-hotspot

… it start working.

How do I troubleshoot this? Route table does not differ. I will check client ip information next time before and after but I haven’t seen anything strange there before when it is not working.

mpous · November 18, 2021, 12:05pm

Hello @Ankan thanks for your message and apologizes that we didn’t reply your first message.

Let me understand your problem. You have a device with WiFi and cellular connectivity and then only cellular connectivity is working, right?

Could you please share what device are you using and what balenaOS + supervisor version?

Could you please also share ip a logs?

Ankan · November 18, 2021, 12:23pm

Hi,

I have a device with Wifi and Cellular. Wifi and Cellular is working. I can access internet from device and I can access device from wifi client but I can’t access internet from wifi client in some cases.

Maybe it’s a firewall problem if there is one. Else I don’t understand why wifi client can connect to internet sometimes and sometimes it can’t.

By restarting wifi AP it start working.

I’am running balenaOS 2.84.5, Supervisor 12.10.3 on a STM32MP (https://github.com/srednak/balena-st-stm32mp)

ip a when it is working:

1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host
       valid_lft forever preferred_lft forever
2: wwan0: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1430 qdisc fq_codel qlen 1000
    link/[65534]
    inet 100.99.125.191/25 brd 100.99.125.255 scope global wwan0
       valid_lft forever preferred_lft forever
3: wlan0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq qlen 1000
    link/ether 00:15:61:52:b5:16 brd ff:ff:ff:ff:ff:ff
    inet 192.168.1.1/24 brd 192.168.1.255 scope global wlan0
       valid_lft forever preferred_lft forever
    inet6 fe80::215:61ff:fe52:b516/64 scope link
       valid_lft forever preferred_lft forever
4: resin-dns: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue qlen 1000
    link/ether 42:b1:a1:d4:a6:e8 brd ff:ff:ff:ff:ff:ff
    inet 10.114.102.1/24 scope global resin-dns
       valid_lft forever preferred_lft forever
5: supervisor0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue
    link/ether 02:42:65:cd:14:24 brd ff:ff:ff:ff:ff:ff
    inet 10.114.104.1/25 brd 10.114.104.127 scope global supervisor0
       valid_lft forever preferred_lft forever
6: balena0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue
    link/ether 02:42:15:e8:f6:af brd ff:ff:ff:ff:ff:ff
    inet 10.114.101.1/24 brd 10.114.101.255 scope global balena0
       valid_lft forever preferred_lft forever
7: br-ef9d72b71313: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue
    link/ether 02:42:43:0f:ec:79 brd ff:ff:ff:ff:ff:ff
    inet 172.17.0.1/16 brd 172.17.255.255 scope global br-ef9d72b71313
       valid_lft forever preferred_lft forever
8: resin-vpn: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1500 qdisc fq_codel qlen 100
    link/[65534]
    inet 10.240.39.4 peer 52.4.252.97/32 scope global resin-vpn
       valid_lft forever preferred_lft forever
    inet6 fe80::18de:5d90:92af:5d17/64 scope link
       valid_lft forever preferred_lft forever

mpous · November 18, 2021, 12:35pm

Thanks @Ankan could you please share more logs when this is not working?

How many devices have this problem? or this is the only case?

Thanks

Ankan · November 18, 2021, 2:02pm

We only have one prototype and one development device right now and both have this problem.

mpous · November 18, 2021, 4:18pm

@Ankan could you please share nmcli d?

Ankan · November 18, 2021, 4:34pm

This is when it is working as it only happen sometimes.

DEVICE           TYPE      STATE                   CONNECTION
wlan0            wifi      connected               balena-hotspot
cdc-wdm0         gsm       connected               cellular
supervisor0      bridge    connected (externally)  supervisor0
balena0          bridge    unmanaged               --
br-1fd0d567cdf0  bridge    unmanaged               --
resin-dns        bridge    unmanaged               --
lo               loopback  unmanaged               --
resin-vpn        tun       unmanaged               --

Ankan · November 19, 2021, 7:39am

Hi,

I got into the situation where it doesn’t work and can keep it like this if I only know how to troubleshoot.

nmcli d

DEVICE           TYPE      STATE                   CONNECTION
wlan0            wifi      connected               balena-hotspot
cdc-wdm0         gsm       connected               cellular
supervisor0      bridge    connected (externally)  supervisor0
balena0          bridge    unmanaged               --
br-1fd0d567cdf0  bridge    unmanaged               --
resin-dns        bridge    unmanaged               --
lo               loopback  unmanaged               --
resin-vpn        tun       unmanaged               --

ip a

1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host
       valid_lft forever preferred_lft forever
2: wwan0: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1430 qdisc fq_codel qlen 1000
    link/[65534]
    inet 100.97.130.85/30 brd 100.97.130.87 scope global wwan0
       valid_lft forever preferred_lft forever
3: wlan0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq qlen 1000
    link/ether 00:15:61:52:b5:16 brd ff:ff:ff:ff:ff:ff
    inet 192.168.1.1/24 brd 192.168.1.255 scope global wlan0
       valid_lft forever preferred_lft forever
    inet6 fe80::215:61ff:fe52:b516/64 scope link
       valid_lft forever preferred_lft forever
4: resin-dns: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue qlen 1000
    link/ether 42:b1:a1:d4:a6:e8 brd ff:ff:ff:ff:ff:ff
    inet 10.114.102.1/24 scope global resin-dns
       valid_lft forever preferred_lft forever
6: br-1fd0d567cdf0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue
    link/ether 02:42:b6:ac:87:23 brd ff:ff:ff:ff:ff:ff
    inet 172.18.0.1/16 brd 172.18.255.255 scope global br-1fd0d567cdf0
       valid_lft forever preferred_lft forever
7: supervisor0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue
    link/ether 02:42:b1:70:6b:f3 brd ff:ff:ff:ff:ff:ff
    inet 10.114.104.1/25 brd 10.114.104.127 scope global supervisor0
       valid_lft forever preferred_lft forever
8: balena0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue
    link/ether 02:42:2c:fc:80:46 brd ff:ff:ff:ff:ff:ff
    inet 10.114.101.1/24 brd 10.114.101.255 scope global balena0
       valid_lft forever preferred_lft forever
9: resin-vpn: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1500 qdisc fq_codel qlen 100
    link/[65534]
    inet 10.240.49.242 peer 52.4.252.97/32 scope global resin-vpn
       valid_lft forever preferred_lft forever
    inet6 fe80::e1b6:5e8f:1d3a:b155/64 scope link
       valid_lft forever preferred_lft forever

Client info:
IP Address: 192.168.1.164
Subnet Mask: 255.255.255.0
Default Gateway IP: 192.168.1.1
DNS Server IP: 192.168.1.1

Can ping 192.168.1.1 but not anything on internet like Google DNS 8.8.8.8
Portscan on 192.168.1.1 give me only port 53 open.
Can do DNS queries to 192.168.1.1 and get correct answers.

Ankan · November 19, 2021, 12:29pm

I get this problem on first boot in the morning. Maybe it’s how long it takes for the cellular to connect that matters?

Ankan · November 23, 2021, 4:25pm

Now I get this problem every time on boot. It help to restart wifi module connection from NetworkManager by running:

nmcli con up balena-hotspot

How can I track what happen when running that command to troubleshoot what fix the problem?

Is there a default firewall that can be the problem? How to check that?

Ankan · November 23, 2021, 7:20pm

Below log is from this command.

journalctl -u NetworkManager

At 19:15:57 i run:

nmcli con up balena-hotspot

and it start working.

Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.3552] NetworkManager (version 1.28.0) is starting... (for the first time)
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.3565] Read config: /etc/NetworkManager/NetworkManager.conf (etc: os-networkmanager.conf)
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.4294] bus-manager: acquired D-Bus service "org.freedesktop.NetworkManager"
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.5365] manager[0x73b028]: monitoring kernel firmware directory '/lib/firmware'.
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.5831] hostname: hostname: using hostnamed
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.5835] hostname: hostname changed from (none) to "66221d6"
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.6105] dns-mgr[0x741000]: init: dns=default,systemd-resolved rc-manager=resolvconf (auto)
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.6725] rfkill1: found Wi-Fi radio killswitch (at /sys/devices/platform/soc/5800d000.usbh-ehci/usb2/2-1/2-1:1.2/ieee80211/phy0/rfkill1) (driver rtl88x2bu)
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.7097] manager[0x73b028]: rfkill: Wi-Fi hardware radio set enabled
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.7101] manager[0x73b028]: rfkill: WWAN hardware radio set enabled
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.7982] Loaded device plugin: NMWifiFactory (/usr/lib/NetworkManager/1.28.0/libnm-device-plugin-wifi.so)
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.9009] Loaded device plugin: NMBluezManager (/usr/lib/NetworkManager/1.28.0/libnm-device-plugin-bluetooth.so)
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.9160] Loaded device plugin: NMAtmManager (/usr/lib/NetworkManager/1.28.0/libnm-device-plugin-adsl.so)
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.9416] Loaded device plugin: NMWwanFactory (/usr/lib/NetworkManager/1.28.0/libnm-device-plugin-wwan.so)
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.9726] manager: rfkill: Wi-Fi enabled by radio killswitch; enabled by state file
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.9858] manager: rfkill: WWAN enabled by radio killswitch; enabled by state file
Nov 23 19:09:50 localhost NetworkManager[931]: <info>  [1637694590.9920] manager: Networking is enabled by state file
Nov 23 19:09:51 localhost NetworkManager[931]: <info>  [1637694591.0061] dhcp-init: Using DHCP client 'internal'
Nov 23 19:09:51 localhost NetworkManager[931]: <info>  [1637694591.0119] settings: Loaded settings plugin: keyfile (internal)
Nov 23 19:09:51 localhost NetworkManager[931]: <info>  [1637694591.2406] device (lo): carrier: link connected
Nov 23 19:09:51 localhost NetworkManager[931]: <info>  [1637694591.2621] manager: (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/1)
Nov 23 19:09:51 localhost NetworkManager[931]: <info>  [1637694591.3614] manager: (resin-dns): new Bridge device (/org/freedesktop/NetworkManager/Devices/2)
Nov 23 19:09:51 localhost NetworkManager[931]: <info>  [1637694591.4323] device (wlan0): driver supports Access Point (AP) mode
Nov 23 19:09:51 localhost NetworkManager[931]: <info>  [1637694591.4959] manager: (wlan0): new 802.11 Wi-Fi device (/org/freedesktop/NetworkManager/Devices/3)
Nov 23 19:09:51 localhost NetworkManager[931]: <info>  [1637694591.6403] device (wlan0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Nov 23 19:09:53 localhost NetworkManager[931]: <info>  [1637694593.7255] device (wlan0): set-hw-addr: set MAC address to 62:9C:B7:D1:7B:94 (scanning)
Nov 23 19:09:54 localhost NetworkManager[931]: <info>  [1637694594.1199] modem-manager: ModemManager available
Nov 23 19:09:54 localhost NetworkManager[931]: <info>  [1637694594.1808] modem["cdc-wdm0"]: modem state changed, 'disabled' --> 'enabling' (reason: user preference)
Nov 23 19:09:54 localhost NetworkManager[931]: <info>  [1637694594.1997] manager: (cdc-wdm0): new Broadband device (/org/freedesktop/NetworkManager/Devices/4)
Nov 23 19:09:54 localhost NetworkManager[931]: <info>  [1637694594.2576] device (cdc-wdm0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Nov 23 19:09:54 localhost NetworkManager[931]: <info>  [1637694594.3417] device (cdc-wdm0): modem state 'enabling'
Nov 23 19:09:54 localhost NetworkManager[931]: <info>  [1637694594.4657] device (cdc-wdm0): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
Nov 23 19:09:54 localhost NetworkManager[931]: <info>  [1637694594.5104] policy: auto-activating connection 'cellular' (d811a35a-70fc-3716-84e1-a3578d10cc1e)
Nov 23 19:09:54 localhost NetworkManager[931]: <info>  [1637694594.5508] device (cdc-wdm0): Activation: starting connection 'cellular' (d811a35a-70fc-3716-84e1-a3578d10cc1e)
Nov 23 19:09:54 localhost NetworkManager[931]: <info>  [1637694594.5742] device (cdc-wdm0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Nov 23 19:09:54 localhost NetworkManager[931]: <info>  [1637694594.6399] manager: NetworkManager state is now CONNECTING
Nov 23 19:09:54 localhost NetworkManager[931]: <info>  [1637694594.7472] device (wlan0): supplicant interface state: internal-starting -> disconnected
Nov 23 19:09:54 localhost NetworkManager[931]: <info>  [1637694594.7479] device (wlan0): state change: unavailable -> disconnected (reason 'supplicant-available', sys-iface-state: 'managed')
Nov 23 19:09:55 localhost NetworkManager[931]: <info>  [1637694595.0939] modem["cdc-wdm0"]: modem state changed, 'enabling' --> 'enabled' (reason: user-requested)
Nov 23 19:09:55 localhost NetworkManager[931]: <info>  [1637694595.1525] modem["cdc-wdm0"]: modem state changed, 'enabled' --> 'connecting' (reason: user-requested)
Nov 23 19:09:55 localhost NetworkManager[931]: <info>  [1637694595.2682] modem["cdc-wdm0"]: modem state changed, 'connecting' --> 'registered' (reason: unknown)
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.0386] modem["cdc-wdm0"]: modem state changed, 'registered' --> 'connected' (reason: user-requested)
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.1244] device (cdc-wdm0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.1293] device (cdc-wdm0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.1766] modem["cdc-wdm0"]: IPv6 configuration disabled
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.1771] modem-broadband[cdc-wdm0]: IPv4 static configuration:
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.1775] modem-broadband[cdc-wdm0]:   address 100.103.63.159/26
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.1777] modem-broadband[cdc-wdm0]:   gateway 100.103.63.160
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.1779] modem-broadband[cdc-wdm0]:   DNS 2.248.248.101
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.1780] modem-broadband[cdc-wdm0]:   DNS 2.248.248.100
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.1781] modem-broadband[cdc-wdm0]:   MTU 1430
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.2635] device (cdc-wdm0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.3722] device (cdc-wdm0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.3867] device (cdc-wdm0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.4162] manager: NetworkManager state is now CONNECTED_LOCAL
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.5135] manager: NetworkManager state is now CONNECTED_SITE
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.5319] policy: set 'cellular' (wwan0) as default for IPv4 routing and DNS
Nov 23 19:09:56 localhost NetworkManager[931]: <info>  [1637694596.5636] dns-mgr: Writing DNS information to /sbin/resolvconf
Nov 23 19:09:57 66221d6 NetworkManager[931]: <info>  [1637694597.0499] device (cdc-wdm0): Activation: successful, device activated.
Nov 23 19:09:58 66221d6 NetworkManager[931]: <info>  [1637694598.9481] manager: NetworkManager state is now CONNECTED_GLOBAL
Nov 23 19:10:00 66221d6 NetworkManager[931]: <info>  [1637694600.7323] policy: auto-activating connection 'balena-hotspot' (36060c57-aebd-4ccf-aba4-ef75121b5f77)
Nov 23 19:10:00 66221d6 NetworkManager[931]: <info>  [1637694600.7380] device (wlan0): Activation: starting connection 'balena-hotspot' (36060c57-aebd-4ccf-aba4-ef75121b5f77)
Nov 23 19:10:00 66221d6 NetworkManager[931]: <info>  [1637694600.7539] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Nov 23 19:10:01 66221d6 NetworkManager[931]: <info>  [1637694601.6495] device (wlan0): set-hw-addr: reset MAC address to 00:15:61:52:B5:16 (preserve)
Nov 23 19:10:01 66221d6 NetworkManager[931]: <info>  [1637694601.6726] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Nov 23 19:10:01 66221d6 NetworkManager[931]: <info>  [1637694601.6763] device (wlan0): Activation: (wifi) access point 'balena-hotspot' has security, but secrets are required.
Nov 23 19:10:01 66221d6 NetworkManager[931]: <info>  [1637694601.7040] device (wlan0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
Nov 23 19:10:01 66221d6 NetworkManager[931]: <info>  [1637694601.7391] device (wlan0): supplicant interface state: disconnected -> interface_disabled
Nov 23 19:10:01 66221d6 NetworkManager[931]: <info>  [1637694601.8191] manager: (resin-vpn): new Tun device (/org/freedesktop/NetworkManager/Devices/5)
Nov 23 19:10:01 66221d6 NetworkManager[931]: <info>  [1637694601.9334] device (wlan0): supplicant interface state: interface_disabled -> inactive
Nov 23 19:10:02 66221d6 NetworkManager[931]: <info>  [1637694602.0339] device (wlan0): supplicant interface state: inactive -> disconnected
Nov 23 19:10:02 66221d6 NetworkManager[931]: <info>  [1637694602.3650] device (wlan0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Nov 23 19:10:02 66221d6 NetworkManager[931]: <info>  [1637694602.5400] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Nov 23 19:10:02 66221d6 NetworkManager[931]: <info>  [1637694602.5547] device (wlan0): Activation: (wifi) connection 'balena-hotspot' has security, and secrets exist.  No new secrets needed.
Nov 23 19:10:02 66221d6 NetworkManager[931]: <info>  [1637694602.5578] Config: added 'ssid' value 'WIFI'
Nov 23 19:10:02 66221d6 NetworkManager[931]: <info>  [1637694602.5581] Config: added 'mode' value '2'
Nov 23 19:10:02 66221d6 NetworkManager[931]: <info>  [1637694602.5583] Config: added 'frequency' value '2412'
Nov 23 19:10:02 66221d6 NetworkManager[931]: <info>  [1637694602.5586] Config: added 'key_mgmt' value 'WPA-PSK'
Nov 23 19:10:02 66221d6 NetworkManager[931]: <info>  [1637694602.5587] Config: added 'psk' value '<hidden>'
Nov 23 19:10:02 66221d6 NetworkManager[931]: <info>  [1637694602.5589] Config: added 'proto' value 'RSN'
Nov 23 19:10:02 66221d6 NetworkManager[931]: <info>  [1637694602.5888] manager: (balena0): new Bridge device (/org/freedesktop/NetworkManager/Devices/6)
Nov 23 19:10:04 66221d6 NetworkManager[931]: <info>  [1637694604.5333] manager: (br-a8483e87e992): new Bridge device (/org/freedesktop/NetworkManager/Devices/7)
Nov 23 19:10:04 66221d6 NetworkManager[931]: <info>  [1637694604.5897] device (wlan0): supplicant interface state: disconnected -> completed
Nov 23 19:10:04 66221d6 NetworkManager[931]: <info>  [1637694604.6024] device (wlan0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Started Wi-Fi Hotspot "WIFI"
Nov 23 19:10:04 66221d6 NetworkManager[931]: <info>  [1637694604.6140] device (wlan0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Nov 23 19:10:05 66221d6 NetworkManager[931]: <info>  [1637694605.2599] Executing: /usr/sbin/iptables --table filter --insert INPUT --in-interface wlan0 --protocol tcp --destination-port 53 --jump ACCEPT
Nov 23 19:10:05 66221d6 NetworkManager[931]: <warn>  [1637694605.3477] ** Command returned exit status 4.
Nov 23 19:10:05 66221d6 NetworkManager[931]: <info>  [1637694605.3482] Executing: /usr/sbin/iptables --table filter --insert INPUT --in-interface wlan0 --protocol udp --destination-port 53 --jump ACCEPT
Nov 23 19:10:05 66221d6 NetworkManager[931]: <info>  [1637694605.4128] Executing: /usr/sbin/iptables --table filter --insert INPUT --in-interface wlan0 --protocol tcp --destination-port 67 --jump ACCEPT
Nov 23 19:10:05 66221d6 NetworkManager[931]: <info>  [1637694605.5025] Executing: /usr/sbin/iptables --table filter --insert INPUT --in-interface wlan0 --protocol udp --destination-port 67 --jump ACCEPT
Nov 23 19:10:05 66221d6 NetworkManager[931]: <info>  [1637694605.6424] Executing: /usr/sbin/iptables --table filter --insert FORWARD --in-interface wlan0 --jump REJECT
Nov 23 19:10:05 66221d6 NetworkManager[931]: <info>  [1637694605.7958] Executing: /usr/sbin/iptables --table filter --insert FORWARD --out-interface wlan0 --jump REJECT
Nov 23 19:10:05 66221d6 NetworkManager[931]: <info>  [1637694605.8823] Executing: /usr/sbin/iptables --table filter --insert FORWARD --in-interface wlan0 --out-interface wlan0 --jump ACCEPT
Nov 23 19:10:05 66221d6 NetworkManager[931]: <info>  [1637694605.9617] Executing: /usr/sbin/iptables --table filter --insert FORWARD --source 192.168.1.0/255.255.255.0 --in-interface wlan0 --jump ACCEPT
Nov 23 19:10:05 66221d6 NetworkManager[931]: <warn>  [1637694605.9949] ** Command returned exit status 4.
Nov 23 19:10:05 66221d6 NetworkManager[931]: <info>  [1637694605.9953] Executing: /usr/sbin/iptables --table filter --insert FORWARD --destination 192.168.1.0/255.255.255.0 --out-interface wlan0 --match state --state ESTABLISHED,RELATED --jump ACCEPT
Nov 23 19:10:06 66221d6 NetworkManager[931]: <info>  [1637694606.1245] Executing: /usr/sbin/iptables --table nat --insert POSTROUTING --source 192.168.1.0/255.255.255.0 ! --destination 192.168.1.0/255.255.255.0 --jump MASQUERADE
Nov 23 19:10:06 66221d6 NetworkManager[931]: <info>  [1637694606.2529] dnsmasq-manager: starting dnsmasq...
Nov 23 19:10:06 66221d6 NetworkManager[931]: <info>  [1637694606.2960] device (wlan0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Nov 23 19:10:06 66221d6 dnsmasq[1164]: started, version 2.84rc2 cachesize 150
Nov 23 19:10:06 66221d6 dnsmasq[1164]: compile time options: IPv6 GNU-getopt DBus no-UBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth no-cryptohash no-DNSSEC loop-detect inotify dumpfile
Nov 23 19:10:06 66221d6 dnsmasq[1164]: chown of PID file /var/run/nm-dnsmasq-wlan0.pid failed: Operation not permitted
Nov 23 19:10:06 66221d6 dnsmasq-dhcp[1164]: DHCP, IP range 192.168.1.10 -- 192.168.1.254, lease time 1h
Nov 23 19:10:06 66221d6 dnsmasq[1164]: reading /etc/resolv.conf
Nov 23 19:10:06 66221d6 dnsmasq[1164]: using nameserver 127.0.0.2#53
Nov 23 19:10:06 66221d6 dnsmasq[1164]: cleared cache
Nov 23 19:10:06 66221d6 NetworkManager[931]: <info>  [1637694606.4321] manager: (supervisor0): new Bridge device (/org/freedesktop/NetworkManager/Devices/8)
Nov 23 19:10:06 66221d6 NetworkManager[931]: <info>  [1637694606.4620] device (wlan0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Nov 23 19:10:06 66221d6 NetworkManager[931]: <info>  [1637694606.5039] device (wlan0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Nov 23 19:10:06 66221d6 NetworkManager[931]: <info>  [1637694606.5996] device (wlan0): Activation: successful, device activated.
Nov 23 19:10:06 66221d6 NetworkManager[931]: <info>  [1637694606.6789] manager: startup complete
Nov 23 19:10:07 66221d6 NetworkManager[931]: <info>  [1637694607.7831] device (supervisor0): state change: unmanaged -> unavailable (reason 'connection-assumed', sys-iface-state: 'external')
Nov 23 19:10:07 66221d6 NetworkManager[931]: <warn>  [1637694607.8400] device (supervisor0): failed to read bridge setting 'vlan_protocol'
Nov 23 19:10:07 66221d6 NetworkManager[931]: <warn>  [1637694607.8510] device (supervisor0): failed to read bridge setting 'vlan_stats_enabled'
Nov 23 19:10:07 66221d6 NetworkManager[931]: <info>  [1637694607.9058] device (supervisor0): state change: unavailable -> disconnected (reason 'connection-assumed', sys-iface-state: 'external')
Nov 23 19:10:07 66221d6 NetworkManager[931]: <info>  [1637694607.9420] device (supervisor0): Activation: starting connection 'supervisor0' (5b7da66c-2639-4dfd-96bd-78591463a809)
Nov 23 19:10:07 66221d6 NetworkManager[931]: <info>  [1637694607.9612] device (supervisor0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'external')
Nov 23 19:10:07 66221d6 NetworkManager[931]: <info>  [1637694607.9972] device (supervisor0): state change: prepare -> config (reason 'none', sys-iface-state: 'external')
Nov 23 19:10:08 66221d6 NetworkManager[931]: <info>  [1637694608.0189] device (supervisor0): state change: config -> ip-config (reason 'none', sys-iface-state: 'external')
Nov 23 19:10:08 66221d6 NetworkManager[931]: <info>  [1637694608.0286] device (supervisor0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'external')
Nov 23 19:10:08 66221d6 NetworkManager[931]: <info>  [1637694608.0957] device (supervisor0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'external')
Nov 23 19:10:08 66221d6 NetworkManager[931]: <info>  [1637694608.1069] device (supervisor0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'external')
Nov 23 19:10:08 66221d6 NetworkManager[931]: <info>  [1637694608.1668] device (supervisor0): Activation: successful, device activated.
Nov 23 19:10:14 66221d6 systemd[1]: NetworkManager.service: Failed to set 'blkio.weight' attribute on '/system.slice/NetworkManager.service' to '500': No such file or directory
Nov 23 19:10:17 66221d6 dnsmasq-dhcp[1164]: DHCPREQUEST(wlan0) 192.168.1.118 00:9a:cd:5f:9e:30
Nov 23 19:10:17 66221d6 dnsmasq-dhcp[1164]: DHCPACK(wlan0) 192.168.1.118 00:9a:cd:5f:9e:30 T1_7
Nov 23 19:10:17 66221d6 dnsmasq-dhcp[1164]: DHCPREQUEST(wlan0) 192.168.1.118 00:9a:cd:5f:9e:30
Nov 23 19:10:17 66221d6 dnsmasq-dhcp[1164]: DHCPACK(wlan0) 192.168.1.118 00:9a:cd:5f:9e:30 T1_7
Nov 23 19:15:57 66221d6 NetworkManager[931]: <info>  [1637694957.2063] agent-manager: agent[04a0d835d9c492d7,:1.60/nmcli-connect/0]: agent registered
Nov 23 19:15:57 66221d6 NetworkManager[931]: <info>  [1637694957.2194] device (wlan0): state change: activated -> deactivating (reason 'new-activation', sys-iface-state: 'managed')
Nov 23 19:15:57 66221d6 NetworkManager[931]: <info>  [1637694957.2527] device (wlan0): disconnecting for new activation request.
Nov 23 19:15:57 66221d6 NetworkManager[931]: <info>  [1637694957.2550] audit: op="connection-activate" uuid="36060c57-aebd-4ccf-aba4-ef75121b5f77" name="balena-hotspot" pid=2368 uid=0 result="success"
Nov 23 19:15:57 66221d6 NetworkManager[931]: <info>  [1637694957.5621] device (wlan0): supplicant interface state: completed -> disconnected
Nov 23 19:15:57 66221d6 NetworkManager[931]: <info>  [1637694957.5699] device (wlan0): state change: deactivating -> disconnected (reason 'new-activation', sys-iface-state: 'managed')
Nov 23 19:15:57 66221d6 dnsmasq[1164]: exiting on receipt of SIGTERM
Nov 23 19:15:57 66221d6 NetworkManager[931]: <info>  [1637694957.6795] device (wlan0): set-hw-addr: set MAC address to 76:BB:70:C2:FF:1D (scanning)
Nov 23 19:15:57 66221d6 NetworkManager[931]: <info>  [1637694957.8088] device (wlan0): Activation: starting connection 'balena-hotspot' (36060c57-aebd-4ccf-aba4-ef75121b5f77)
Nov 23 19:15:57 66221d6 NetworkManager[931]: <info>  [1637694957.8267] device (wlan0): supplicant interface state: disconnected -> interface_disabled
Nov 23 19:15:57 66221d6 NetworkManager[931]: <info>  [1637694957.8300] device (wlan0): supplicant interface state: interface_disabled -> disconnected
Nov 23 19:15:57 66221d6 NetworkManager[931]: <info>  [1637694957.8736] Executing: /usr/sbin/iptables --table nat --delete POSTROUTING --source 192.168.1.0/255.255.255.0 ! --destination 192.168.1.0/255.255.255.0 --jump MASQUERADE
Nov 23 19:15:57 66221d6 NetworkManager[931]: <info>  [1637694957.9527] Executing: /usr/sbin/iptables --table filter --delete FORWARD --destination 192.168.1.0/255.255.255.0 --out-interface wlan0 --match state --state ESTABLISHED,RELATED --jump ACCEPT
Nov 23 19:15:58 66221d6 NetworkManager[931]: <info>  [1637694958.0218] Executing: /usr/sbin/iptables --table filter --delete FORWARD --source 192.168.1.0/255.255.255.0 --in-interface wlan0 --jump ACCEPT
Nov 23 19:15:58 66221d6 NetworkManager[931]: <warn>  [1637694958.0778] ** Command returned exit status 1.
Nov 23 19:15:58 66221d6 NetworkManager[931]: <info>  [1637694958.0820] Executing: /usr/sbin/iptables --table filter --delete FORWARD --in-interface wlan0 --out-interface wlan0 --jump ACCEPT
Nov 23 19:15:58 66221d6 NetworkManager[931]: <info>  [1637694958.1719] Executing: /usr/sbin/iptables --table filter --delete FORWARD --out-interface wlan0 --jump REJECT
Nov 23 19:15:58 66221d6 NetworkManager[931]: <info>  [1637694958.2435] Executing: /usr/sbin/iptables --table filter --delete FORWARD --in-interface wlan0 --jump REJECT
Nov 23 19:15:58 66221d6 NetworkManager[931]: <info>  [1637694958.3444] Executing: /usr/sbin/iptables --table filter --delete INPUT --in-interface wlan0 --protocol udp --destination-port 67 --jump ACCEPT
Nov 23 19:15:58 66221d6 NetworkManager[931]: <warn>  [1637694958.4186] ** Command returned exit status 1.
Nov 23 19:15:58 66221d6 NetworkManager[931]: <info>  [1637694958.4191] Executing: /usr/sbin/iptables --table filter --delete INPUT --in-interface wlan0 --protocol tcp --destination-port 67 --jump ACCEPT
Nov 23 19:15:58 66221d6 NetworkManager[931]: <warn>  [1637694958.4740] ** Command returned exit status 1.
Nov 23 19:15:58 66221d6 NetworkManager[931]: <info>  [1637694958.4755] Executing: /usr/sbin/iptables --table filter --delete INPUT --in-interface wlan0 --protocol udp --destination-port 53 --jump ACCEPT
Nov 23 19:15:58 66221d6 NetworkManager[931]: <warn>  [1637694958.5139] ** Command returned exit status 1.
Nov 23 19:15:58 66221d6 NetworkManager[931]: <info>  [1637694958.5164] Executing: /usr/sbin/iptables --table filter --delete INPUT --in-interface wlan0 --protocol tcp --destination-port 53 --jump ACCEPT
Nov 23 19:15:58 66221d6 NetworkManager[931]: <warn>  [1637694958.6477] ** Command returned exit status 1.
Nov 23 19:15:58 66221d6 NetworkManager[931]: <info>  [1637694958.6664] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Nov 23 19:15:58 66221d6 NetworkManager[931]: <info>  [1637694958.9172] device (wlan0): set-hw-addr: reset MAC address to 00:15:61:52:B5:16 (preserve)
Nov 23 19:15:58 66221d6 NetworkManager[931]: <info>  [1637694958.9491] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Nov 23 19:15:58 66221d6 NetworkManager[931]: <info>  [1637694958.9681] device (wlan0): Activation: (wifi) access point 'balena-hotspot' has security, but secrets are required.
Nov 23 19:15:58 66221d6 NetworkManager[931]: <info>  [1637694958.9693] device (wlan0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
Nov 23 19:15:59 66221d6 NetworkManager[931]: <info>  [1637694959.0194] device (wlan0): supplicant interface state: disconnected -> interface_disabled
Nov 23 19:15:59 66221d6 NetworkManager[931]: <info>  [1637694959.0239] device (wlan0): supplicant interface state: interface_disabled -> disconnected
Nov 23 19:15:59 66221d6 NetworkManager[931]: <info>  [1637694959.1003] device (wlan0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Nov 23 19:15:59 66221d6 NetworkManager[931]: <info>  [1637694959.1545] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Nov 23 19:15:59 66221d6 NetworkManager[931]: <info>  [1637694959.1723] device (wlan0): Activation: (wifi) connection 'balena-hotspot' has security, and secrets exist.  No new secrets needed.
Nov 23 19:15:59 66221d6 NetworkManager[931]: <info>  [1637694959.1794] Config: added 'ssid' value 'WIFI'
Nov 23 19:15:59 66221d6 NetworkManager[931]: <info>  [1637694959.1818] Config: added 'mode' value '2'
Nov 23 19:15:59 66221d6 NetworkManager[931]: <info>  [1637694959.1830] Config: added 'frequency' value '2412'
Nov 23 19:15:59 66221d6 NetworkManager[931]: <info>  [1637694959.1855] Config: added 'key_mgmt' value 'WPA-PSK'
Nov 23 19:15:59 66221d6 NetworkManager[931]: <info>  [1637694959.1867] Config: added 'psk' value '<hidden>'
Nov 23 19:15:59 66221d6 NetworkManager[931]: <info>  [1637694959.1891] Config: added 'proto' value 'RSN'
Nov 23 19:16:00 66221d6 NetworkManager[931]: <info>  [1637694960.9753] device (wlan0): supplicant interface state: disconnected -> completed
Nov 23 19:16:00 66221d6 NetworkManager[931]: <info>  [1637694960.9787] device (wlan0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Started Wi-Fi Hotspot "WIFI"
Nov 23 19:16:00 66221d6 NetworkManager[931]: <info>  [1637694960.9846] device (wlan0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Nov 23 19:16:01 66221d6 NetworkManager[931]: <info>  [1637694961.2248] Executing: /usr/sbin/iptables --table filter --insert INPUT --in-interface wlan0 --protocol tcp --destination-port 53 --jump ACCEPT
Nov 23 19:16:01 66221d6 NetworkManager[931]: <info>  [1637694961.3217] Executing: /usr/sbin/iptables --table filter --insert INPUT --in-interface wlan0 --protocol udp --destination-port 53 --jump ACCEPT
Nov 23 19:16:01 66221d6 NetworkManager[931]: <info>  [1637694961.4020] Executing: /usr/sbin/iptables --table filter --insert INPUT --in-interface wlan0 --protocol tcp --destination-port 67 --jump ACCEPT
Nov 23 19:16:01 66221d6 NetworkManager[931]: <info>  [1637694961.4628] Executing: /usr/sbin/iptables --table filter --insert INPUT --in-interface wlan0 --protocol udp --destination-port 67 --jump ACCEPT
Nov 23 19:16:01 66221d6 NetworkManager[931]: <info>  [1637694961.5423] Executing: /usr/sbin/iptables --table filter --insert FORWARD --in-interface wlan0 --jump REJECT
Nov 23 19:16:01 66221d6 NetworkManager[931]: <info>  [1637694961.5920] Executing: /usr/sbin/iptables --table filter --insert FORWARD --out-interface wlan0 --jump REJECT
Nov 23 19:16:01 66221d6 NetworkManager[931]: <info>  [1637694961.6621] Executing: /usr/sbin/iptables --table filter --insert FORWARD --in-interface wlan0 --out-interface wlan0 --jump ACCEPT
Nov 23 19:16:01 66221d6 NetworkManager[931]: <info>  [1637694961.7216] Executing: /usr/sbin/iptables --table filter --insert FORWARD --source 192.168.1.0/255.255.255.0 --in-interface wlan0 --jump ACCEPT
Nov 23 19:16:01 66221d6 NetworkManager[931]: <info>  [1637694961.7719] Executing: /usr/sbin/iptables --table filter --insert FORWARD --destination 192.168.1.0/255.255.255.0 --out-interface wlan0 --match state --state ESTABLISHED,RELATED --jump ACCEPT
Nov 23 19:16:01 66221d6 NetworkManager[931]: <info>  [1637694961.8317] Executing: /usr/sbin/iptables --table nat --insert POSTROUTING --source 192.168.1.0/255.255.255.0 ! --destination 192.168.1.0/255.255.255.0 --jump MASQUERADE
Nov 23 19:16:01 66221d6 NetworkManager[931]: <info>  [1637694961.8920] dnsmasq-manager: starting dnsmasq...
Nov 23 19:16:01 66221d6 NetworkManager[931]: <info>  [1637694961.9164] device (wlan0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Nov 23 19:16:01 66221d6 dnsmasq[2452]: started, version 2.84rc2 cachesize 150
Nov 23 19:16:01 66221d6 dnsmasq[2452]: compile time options: IPv6 GNU-getopt DBus no-UBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth no-cryptohash no-DNSSEC loop-detect inotify dumpfile
Nov 23 19:16:01 66221d6 dnsmasq[2452]: chown of PID file /var/run/nm-dnsmasq-wlan0.pid failed: Operation not permitted
Nov 23 19:16:01 66221d6 dnsmasq-dhcp[2452]: DHCP, IP range 192.168.1.10 -- 192.168.1.254, lease time 1h
Nov 23 19:16:01 66221d6 dnsmasq[2452]: reading /etc/resolv.conf
Nov 23 19:16:01 66221d6 dnsmasq[2452]: using nameserver 127.0.0.2#53
Nov 23 19:16:01 66221d6 dnsmasq[2452]: cleared cache
Nov 23 19:16:02 66221d6 NetworkManager[931]: <info>  [1637694962.0332] device (wlan0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Nov 23 19:16:02 66221d6 NetworkManager[931]: <info>  [1637694962.0608] device (wlan0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Nov 23 19:16:02 66221d6 NetworkManager[931]: <info>  [1637694962.1814] device (wlan0): Activation: successful, device activated.
Nov 23 19:16:06 66221d6 dnsmasq-dhcp[2452]: DHCPREQUEST(wlan0) 192.168.1.118 00:9a:cd:5f:9e:30
Nov 23 19:16:06 66221d6 dnsmasq-dhcp[2452]: DHCPACK(wlan0) 192.168.1.118 00:9a:cd:5f:9e:30 T1_7
Nov 23 19:16:06 66221d6 dnsmasq-dhcp[2452]: DHCPREQUEST(wlan0) 192.168.1.118 00:9a:cd:5f:9e:30
Nov 23 19:16:06 66221d6 dnsmasq-dhcp[2452]: DHCPACK(wlan0) 192.168.1.118 00:9a:cd:5f:9e:30 T1_7

Ankan · November 24, 2021, 4:30pm

At last I found the problem. The problem is when NetworkManager add those iptables roules it get a warning with:

** Command returned exit status 4.

This may occur when iptables fail to get the file lock. I read that you can add the -w flag to the iptables command to let it wait x seconds for the lock to be released. But how do I force NetworkManager to do this?

Is this possible to fix with NetworkManager configurations or should I just run a script that check iptables and add missing iptables rules?

What is locking those files that prevent iptables to add those rules?

Nov 24 16:10:07 66221d6 NetworkManager[928]: <info>  [1637770207.0766] Executing: /usr/sbin/iptables --table filter --insert INPUT --in-interface wlan0 --protocol tcp --destination-port 53 --jump ACCEPT
Nov 24 16:10:07 66221d6 NetworkManager[928]: <info>  [1637770207.1920] Executing: /usr/sbin/iptables --table filter --insert INPUT --in-interface wlan0 --protocol udp --destination-port 53 --jump ACCEPT
Nov 24 16:10:07 66221d6 NetworkManager[928]: <info>  [1637770207.2917] Executing: /usr/sbin/iptables --table filter --insert INPUT --in-interface wlan0 --protocol tcp --destination-port 67 --jump ACCEPT
Nov 24 16:10:07 66221d6 NetworkManager[928]: <info>  [1637770207.3918] Executing: /usr/sbin/iptables --table filter --insert INPUT --in-interface wlan0 --protocol udp --destination-port 67 --jump ACCEPT
Nov 24 16:10:07 66221d6 NetworkManager[928]: <info>  [1637770207.4618] Executing: /usr/sbin/iptables --table filter --insert FORWARD --in-interface wlan0 --jump REJECT
Nov 24 16:10:07 66221d6 NetworkManager[928]: <warn>  [1637770207.5627] ** Command returned exit status 4.
Nov 24 16:10:07 66221d6 NetworkManager[928]: <info>  [1637770207.5631] Executing: /usr/sbin/iptables --table filter --insert FORWARD --out-interface wlan0 --jump REJECT
Nov 24 16:10:07 66221d6 NetworkManager[928]: <warn>  [1637770207.6616] ** Command returned exit status 4.
Nov 24 16:10:07 66221d6 NetworkManager[928]: <info>  [1637770207.6620] Executing: /usr/sbin/iptables --table filter --insert FORWARD --in-interface wlan0 --out-interface wlan0 --jump ACCEPT
Nov 24 16:10:07 66221d6 NetworkManager[928]: <info>  [1637770207.7416] Executing: /usr/sbin/iptables --table filter --insert FORWARD --source 192.168.1.0/255.255.255.0 --in-interface wlan0 --jump ACCEPT
Nov 24 16:10:07 66221d6 NetworkManager[928]: <info>  [1637770207.8223] Executing: /usr/sbin/iptables --table filter --insert FORWARD --destination 192.168.1.0/255.255.255.0 --out-interface wlan0 --match state --state ESTABLISHED,RELATED --jump ACCEPT
Nov 24 16:10:07 66221d6 NetworkManager[928]: <warn>  [1637770207.9570] ** Command returned exit status 4.
Nov 24 16:10:07 66221d6 NetworkManager[928]: <info>  [1637770207.9574] Executing: /usr/sbin/iptables --table nat --insert POSTROUTING --source 192.168.1.0/255.255.255.0 ! --destination 192.168.1.0/255.255.255.0 --jump MASQUERADE

What I understand NetworkManager add those iptables roules because I use ipv4.method=shared

TJvV · November 24, 2021, 6:50pm

Hi,

A quick look into NetworkManager (1.28 and 1.32) sources suggests you cannot pass it any extra options for the iptables commands.
A quick look into iptables (1.8.1, 1.8.6) sources suggests the wait time can only be changed by specifying it in the command arguments.

In the end, while an extra script could be nice, the real question is why the default 1 second isn’t good enough.

Ankan · November 24, 2021, 8:55pm

Does supervisor container have iptables installed and run same command at same time?

Is it possible to track what process iptables conflicts with?

I would prefer to find the root problem instead of hide it with a fix script.

Ankan · November 24, 2021, 9:49pm

Is there any scripts in balena that adds iptables rules that can create the conflict? What else configure iptables except networkmanager?

cywang117 · November 25, 2021, 12:25am

Hi,

The Supervisor also adds some iptables rules. Here is a Supervisor GitHub issue which may be relevant to you: Modifications to firewall (iptables) always removed by Supervisor · Issue #1482 · balena-os/balena-supervisor · GitHub, especially if balena-hotspot adds rules to iptables.

To my knowledge, Supervisor is the only agent that modifies iptables in some way.

Regards,
Christina

Ankan · November 25, 2021, 9:48am

It looks like it’s not only the Supervisor firewall issue as some of the rules get in but not all of them. None of the INPUT rules get added but some of the FORWARD rules.

As seen in my iptables export below, it look like the problem with locked xtable file is collision with something adding FORWARD rules for br-a8483e87e992.
This is why it sometimes work and sometimes not as it depends of what rules get added without collision.

What add those br-a8483e87e992 FORWARD rules and can we change how it is done or when?

I think it’s a problem that NetworkManager does not retry to add rules that is not added because of locked file. It doesn’t matter if I add -w on every other process that use iptables if NetworkManager does not have it. NetworkManager may always have the the problem that it may fail to add rules.

The solution in this case I guess would be to create a script that add missing NetworkManager rules. Where should I put this script to get it working as I guess it have to wait until NetworkManager have tried to add them first?

*filter
:INPUT ACCEPT [265:15904]
:FORWARD DROP [0:0]
:OUTPUT ACCEPT [1652:164696]
:BALENA-FIREWALL - [0:0]
:DOCKER - [0:0]
:DOCKER-ISOLATION-STAGE-1 - [0:0]
:DOCKER-ISOLATION-STAGE-2 - [0:0]
:DOCKER-USER - [0:0]
-A INPUT -j BALENA-FIREWALL
-A FORWARD -j DOCKER-USER
-A FORWARD -j DOCKER-ISOLATION-STAGE-1
-A FORWARD -o balena0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT
-A FORWARD -o balena0 -j DOCKER
-A FORWARD -i balena0 ! -o balena0 -j ACCEPT
-A FORWARD -i balena0 -o balena0 -j ACCEPT
-A FORWARD -o supervisor0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT
-A FORWARD -o supervisor0 -j DOCKER
-A FORWARD -i supervisor0 ! -o supervisor0 -j ACCEPT
-A FORWARD -i supervisor0 -o supervisor0 -j ACCEPT
-A FORWARD -d 192.168.1.0/24 -o wlan0 -m state --state RELATED,ESTABLISHED -j ACCEPT
-A FORWARD -o br-a8483e87e992 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT
-A FORWARD -i wlan0 -o wlan0 -j ACCEPT
-A FORWARD -o wlan0 -j REJECT --reject-with icmp-port-unreachable
-A FORWARD -o br-a8483e87e992 -j DOCKER
-A FORWARD -i wlan0 -j REJECT --reject-with icmp-port-unreachable
-A FORWARD -i br-a8483e87e992 ! -o br-a8483e87e992 -j ACCEPT
-A FORWARD -i br-a8483e87e992 -o br-a8483e87e992 -j ACCEPT
-A BALENA-FIREWALL -m state --state RELATED,ESTABLISHED -j ACCEPT
-A BALENA-FIREWALL -m addrtype --src-type LOCAL -j ACCEPT
-A BALENA-FIREWALL -i resin-vpn -p tcp -m tcp --dport 48484 -j ACCEPT
-A BALENA-FIREWALL -i tun0 -p tcp -m tcp --dport 48484 -j ACCEPT
-A BALENA-FIREWALL -i docker0 -p tcp -m tcp --dport 48484 -j ACCEPT
-A BALENA-FIREWALL -i lo -p tcp -m tcp --dport 48484 -j ACCEPT
-A BALENA-FIREWALL -i supervisor0 -p tcp -m tcp --dport 48484 -j ACCEPT
-A BALENA-FIREWALL -p tcp -m tcp --dport 48484 -j REJECT --reject-with icmp-port-unreachable
-A BALENA-FIREWALL -p tcp -m tcp --dport 22222 -j ACCEPT
-A BALENA-FIREWALL -p tcp -m tcp --dport 2375 -j ACCEPT
-A BALENA-FIREWALL -m addrtype --dst-type MULTICAST -j ACCEPT
-A BALENA-FIREWALL -p icmp -j ACCEPT
-A BALENA-FIREWALL -i balena0 -p udp -m udp --dport 53 -j ACCEPT
-A BALENA-FIREWALL -j RETURN
-A BALENA-FIREWALL -j REJECT --reject-with icmp-port-unreachable
-A DOCKER-ISOLATION-STAGE-1 -i balena0 ! -o balena0 -j DOCKER-ISOLATION-STAGE-2
-A DOCKER-ISOLATION-STAGE-1 -i supervisor0 ! -o supervisor0 -j DOCKER-ISOLATION-STAGE-2
-A DOCKER-ISOLATION-STAGE-1 -i br-a8483e87e992 ! -o br-a8483e87e992 -j DOCKER-ISOLATION-STAGE-2
-A DOCKER-ISOLATION-STAGE-1 -j RETURN
-A DOCKER-ISOLATION-STAGE-2 -o balena0 -j DROP
-A DOCKER-ISOLATION-STAGE-2 -o supervisor0 -j DROP
-A DOCKER-ISOLATION-STAGE-2 -o br-a8483e87e992 -j DROP
-A DOCKER-ISOLATION-STAGE-2 -j RETURN
-A DOCKER-USER -j RETURN
COMMIT

Ankan · November 25, 2021, 10:19am

It look like Balena firewall only removes those INPUT rules and not added FORWARD rules.

I don’t know how many seconds it’s between below iptables outputs. But it’s not critical to get all rules in order before balena firewall have modified iptables.
So a script that fix iptables rules after balena firewall is done with iptables may be the best.

Or is it possible to modify balena firewall to add some extra rules after default rules?

-A INPUT -i wlan0 -p udp -m udp --dport 67 -j ACCEPT
-A INPUT -i wlan0 -p tcp -m tcp --dport 67 -j ACCEPT
-A INPUT -i wlan0 -p udp -m udp --dport 53 -j ACCEPT
-A INPUT -i wlan0 -p tcp -m tcp --dport 53 -j ACCEPT
-A FORWARD -j DOCKER-USER
-A FORWARD -j DOCKER-ISOLATION-STAGE-1
-A FORWARD -o balena0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT
-A FORWARD -o balena0 -j DOCKER
-A FORWARD -i balena0 ! -o balena0 -j ACCEPT
-A FORWARD -i balena0 -o balena0 -j ACCEPT
-A FORWARD -o supervisor0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT
-A FORWARD -o supervisor0 -j DOCKER
-A FORWARD -i supervisor0 ! -o supervisor0 -j ACCEPT
-A FORWARD -i supervisor0 -o supervisor0 -j ACCEPT
-A FORWARD -d 192.168.1.0/24 -o wlan0 -m state --state RELATED,ESTABLISHED -j ACCEPT
-A FORWARD -s 192.168.1.0/24 -i wlan0 -j ACCEPT
-A FORWARD -o br-a8483e87e992 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT
-A FORWARD -o wlan0 -j REJECT --reject-with icmp-port-unreachable
-A FORWARD -i wlan0 -j REJECT --reject-with icmp-port-unreachable
-A FORWARD -o br-a8483e87e992 -j DOCKER
-A FORWARD -i br-a8483e87e992 ! -o br-a8483e87e992 -j ACCEPT
-A FORWARD -i br-a8483e87e992 -o br-a8483e87e992 -j ACCEPT
-A DOCKER-ISOLATION-STAGE-1 -i balena0 ! -o balena0 -j DOCKER-ISOLATION-STAGE-2
-A DOCKER-ISOLATION-STAGE-1 -i supervisor0 ! -o supervisor0 -j DOCKER-ISOLATION-STAGE-2
-A DOCKER-ISOLATION-STAGE-1 -i br-a8483e87e992 ! -o br-a8483e87e992 -j DOCKER-ISOLATION-STAGE-2
-A DOCKER-ISOLATION-STAGE-1 -j RETURN
-A DOCKER-ISOLATION-STAGE-2 -o balena0 -j DROP
-A DOCKER-ISOLATION-STAGE-2 -o supervisor0 -j DROP
-A DOCKER-ISOLATION-STAGE-2 -o br-a8483e87e992 -j DROP
-A DOCKER-ISOLATION-STAGE-2 -j RETURN
-A DOCKER-USER -j RETURN
COMMIT

-A INPUT -j BALENA-FIREWALL
-A FORWARD -j DOCKER-USER
-A FORWARD -j DOCKER-ISOLATION-STAGE-1
-A FORWARD -o balena0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT
-A FORWARD -o balena0 -j DOCKER
-A FORWARD -i balena0 ! -o balena0 -j ACCEPT
-A FORWARD -i balena0 -o balena0 -j ACCEPT
-A FORWARD -o supervisor0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT
-A FORWARD -o supervisor0 -j DOCKER
-A FORWARD -i supervisor0 ! -o supervisor0 -j ACCEPT
-A FORWARD -i supervisor0 -o supervisor0 -j ACCEPT
-A FORWARD -d 192.168.1.0/24 -o wlan0 -m state --state RELATED,ESTABLISHED -j ACCEPT
-A FORWARD -s 192.168.1.0/24 -i wlan0 -j ACCEPT
-A FORWARD -o br-a8483e87e992 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT
-A FORWARD -o wlan0 -j REJECT --reject-with icmp-port-unreachable
-A FORWARD -i wlan0 -j REJECT --reject-with icmp-port-unreachable
-A FORWARD -o br-a8483e87e992 -j DOCKER
-A FORWARD -i br-a8483e87e992 ! -o br-a8483e87e992 -j ACCEPT
-A FORWARD -i br-a8483e87e992 -o br-a8483e87e992 -j ACCEPT
-A BALENA-FIREWALL -m state --state RELATED,ESTABLISHED -j ACCEPT
-A BALENA-FIREWALL -m addrtype --src-type LOCAL -j ACCEPT
-A BALENA-FIREWALL -i resin-vpn -p tcp -m tcp --dport 48484 -j ACCEPT
-A BALENA-FIREWALL -i tun0 -p tcp -m tcp --dport 48484 -j ACCEPT
-A BALENA-FIREWALL -i docker0 -p tcp -m tcp --dport 48484 -j ACCEPT
-A BALENA-FIREWALL -i lo -p tcp -m tcp --dport 48484 -j ACCEPT
-A BALENA-FIREWALL -i supervisor0 -p tcp -m tcp --dport 48484 -j ACCEPT
-A BALENA-FIREWALL -p tcp -m tcp --dport 48484 -j REJECT --reject-with icmp-port-unreachable
-A BALENA-FIREWALL -p tcp -m tcp --dport 22222 -j ACCEPT
-A BALENA-FIREWALL -p tcp -m tcp --dport 2375 -j ACCEPT
-A BALENA-FIREWALL -m addrtype --dst-type MULTICAST -j ACCEPT
-A BALENA-FIREWALL -p icmp -j ACCEPT
-A BALENA-FIREWALL -i balena0 -p udp -m udp --dport 53 -j ACCEPT
-A BALENA-FIREWALL -j RETURN
-A BALENA-FIREWALL -j REJECT --reject-with icmp-port-unreachable
-A DOCKER-ISOLATION-STAGE-1 -i balena0 ! -o balena0 -j DOCKER-ISOLATION-STAGE-2
-A DOCKER-ISOLATION-STAGE-1 -i supervisor0 ! -o supervisor0 -j DOCKER-ISOLATION-STAGE-2
-A DOCKER-ISOLATION-STAGE-1 -i br-a8483e87e992 ! -o br-a8483e87e992 -j DOCKER-ISOLATION-STAGE-2
-A DOCKER-ISOLATION-STAGE-1 -j RETURN
-A DOCKER-ISOLATION-STAGE-2 -o balena0 -j DROP
-A DOCKER-ISOLATION-STAGE-2 -o supervisor0 -j DROP
-A DOCKER-ISOLATION-STAGE-2 -o br-a8483e87e992 -j DROP
-A DOCKER-ISOLATION-STAGE-2 -j RETURN
-A DOCKER-USER -j RETURN
COMMIT

TJvV · November 25, 2021, 1:23pm

Hi,

I think the bridge (br-a8483e87e992) rules might be coming from balena-engine.