balena-os / wifi-connect

Easy WiFi setup for Linux devices from your mobile phone or laptop
Apache License 2.0
1.28k stars 360 forks source link

Device not reconnecting to created nmconnection after reboot #381

Open acostach opened 3 years ago

acostach commented 3 years ago

After successfully connecting to the AP specified in the captive portal, if the device is rebooted it doesn't reconnect to the router, instead the wifi-connect connection gets re-activated:

Feb 18 13:31:37 3552abc NetworkManager[1469]: [1613655097.6011] device (wlan0): disconnecting for new activation request.

Could this be a timing issue, scan results not ready / saved connection not fully activated when the wifi-connect container starts? If I move the device to another Application, it reconnects fine. Or is this the intended behavior?

Tested on Pi4 v2.68.1 (ESR)

Feb 18 13:31:34 3552abc NetworkManager[1469]: <info>  [1613655094.1843] device (supervisor0): Activation: successful, device activated.
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.2705] policy: auto-activating connection 'Balena' (1fe24d61-1c14-483b-871c-e7d8f4694b36)
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.2722] device (wlan0): Activation: starting connection 'Balena' (1fe24d61-1c14-483b-871c-e7d8f4694b36)
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.2727] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.2814] manager: NetworkManager state is now CONNECTING
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8196] device (wlan0): set-hw-addr: reset MAC address to DC:A6:32:03:EE:79 (preserve)
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8298] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8313] device (wlan0): Activation: (wifi) access point 'Balena' has security, but secrets are required.
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8314] device (wlan0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8472] device (wlan0): supplicant interface state: disconnected -> interface_disabled
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8473] device (wlan0): supplicant interface state: interface_disabled -> inactive
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8590] device (wlan0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8608] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8689] device (wlan0): Activation: (wifi) connection 'Balena' has security, and secrets exist.  No new secrets needed.
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8691] Config: added 'ssid' value 'Balena'
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8691] Config: added 'scan_ssid' value '1'
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8692] Config: added 'bgscan' value 'simple:30:-70:86400'
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8692] Config: added 'key_mgmt' value 'WPA-PSK'
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8693] Config: added 'auth_alg' value 'OPEN'
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.8693] Config: added 'psk' value '<hidden>'
Feb 18 13:31:35 3552abc NetworkManager[1469]: <info>  [1613655095.9343] device (wlan0): supplicant interface state: inactive -> scanning
Feb 18 13:31:37 3552abc NetworkManager[1469]: <info>  [1613655097.6011] device (wlan0): disconnecting for new activation request.
Feb 18 13:31:37 3552abc NetworkManager[1469]: <info>  [1613655097.6011] device (wlan0): state change: config -> deactivating (reason 'new-activation', sys-iface-state: 'managed')
Feb 18 13:31:37 3552abc NetworkManager[1469]: <info>  [1613655097.6027] manager: NetworkManager state is now CONNECTED_LOCAL
Feb 18 13:31:37 3552abc NetworkManager[1469]: <info>  [1613655097.6096] audit: op="connection-add-activate" uuid="c2713f15-885d-45b2-a898-6a76343e29d7" name="WiFi Connect" pid=1867 uid=0 result="success"
Feb 18 13:31:37 3552abc NetworkManager[1469]: <info>  [1613655097.6146] device (wlan0): supplicant interface state: scanning -> disconnected
Feb 18 13:31:37 3552abc NetworkManager[1469]: <info>  [1613655097.6150] device (wlan0): state change: deactivating -> disconnected (reason 'new-activation', sys-iface-state: 'managed')
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.1488] device (wlan0): set-hw-addr: set MAC address to 26:9B:06:AB:F4:9D (scanning)
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.1582] device (wlan0): Activation: starting connection 'WiFi Connect' (c2713f15-885d-45b2-a898-6a76343e29d7)
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.1662] device (wlan0): supplicant interface state: disconnected -> interface_disabled
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.1664] device (wlan0): supplicant interface state: interface_disabled -> disconnected
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.1740] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.1762] manager: NetworkManager state is now CONNECTING
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.7379] device (wlan0): set-hw-addr: reset MAC address to DC:A6:32:03:EE:79 (preserve)
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.7483] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.7498] device (wlan0): Activation: (wifi) connection 'WiFi Connect' requires no security.  No secrets needed.
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.7523] Config: added 'ssid' value 'WiFi Connect'
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.7524] Config: added 'mode' value '2'
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.7524] Config: added 'frequency' value '2412'
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.7525] Config: added 'freq_list' value '2412 2417 2422 2427 2432 2437 2442 2447 2452 2457 2462 2467 2472 2484'
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.7525] Config: added 'key_mgmt' value 'NONE'
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.7535] device (wlan0): supplicant interface state: disconnected -> interface_disabled
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.7540] device (wlan0): supplicant interface state: interface_disabled -> disconnected
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.8553] device (wlan0): supplicant interface state: disconnected -> completed
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.8555] device (wlan0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Started Wi-Fi Hotspot "WiFi Connect"
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.8597] device (wlan0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.8812] device (wlan0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.8910] device (wlan0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Feb 18 13:31:38 3552abc NetworkManager[1469]: <info>  [1613655098.9034] device (wlan0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
acostach commented 3 years ago

Indeed, on a board that loads containers slower, like the Raspberrypi 1 model B v1.2 this issue is not reproducible.

romarcin commented 3 years ago

I'm having the same problem with wifi not reconnecting to the inputed network. Did you figure out how to add a delay?

acostach commented 3 years ago

@romarcin I think you can try add a delay in the start script, where the wifi-connect app gets started.