wwan interface settings will not load on startup
Open, LowPublicBUG
Actions

Assigned To

None

Authored By

	galets
	Jul 23 2024, 9:04 PM

Description

Following configuration created prior to reboot:

set interfaces wwan wwan0 description 'LTE Backup Connection'
set interfaces wwan wwan0 ipv6 disable-forwarding
set interfaces wwan wwan0 apn '*****'
set interfaces wwan wwan0 mtu 1428

After reboot, following warning happens after configure command:

WARNING: There was a config error on boot: saving the configuration now could overwrite data.
You may want to check and reload the boot config

section not loaded is:

+    wwan wwan0 {
+        apn **********
+        description "LTE Backup Connection"
+        ipv6 {
+            disable-forwarding
+        }
+        mtu 1428
+    }

journalctl shows following:

Jul 22 13:40:20 **** ModemManager[2757]: [1721655620.196215] [device /sys/devices/pci0000:00/0000:00:14.0/usb1/1-1] creating modem wi>
Jul 22 13:40:20 **** ModemManager[2757]: [1721655620.201364] [plugin/sierra] could not grab port ttyUSB1: Cannot add port 'tty/ttyUSB>
Jul 22 13:40:20 **** ModemManager[2757]: [1721655620.202107] [base-manager] modem for device '/sys/devices/pci0000:00/0000:00:14.0/us>
Jul 22 13:40:20 **** ModemManager[2757]: [1721655620.650615] [modem0/cdc-wdm0/mbim] MBIM device is QMI capable
Jul 22 13:40:20 **** vyos-configd[800]: [Errno 1] failed to run command: mmcli --modem 0 --simple-disconnect
Jul 22 13:40:20 **** vyos-configd[800]: returned:
Jul 22 13:40:20 **** vyos-configd[800]: exit code: 1
Jul 22 13:40:20 **** vyos-configd[800]: Sending response 4
Jul 22 13:40:21 **** ModemManager[2757]: [1721655621.290262] [modem0] QMI-based capability and mode switching support enabled
Jul 22 13:40:21 **** python3[3213]: Report time:      2024-07-22 13:40:21
Jul 22 13:40:21 **** python3[3213]: Image version:    VyOS 1.5-rolling-202407171706
Jul 22 13:40:21 **** python3[3213]: Release train:    current
Jul 22 13:40:21 **** python3[3213]: Built by:         autobuild@vyos.net
Jul 22 13:40:21 **** python3[3213]: Built on:         Wed 17 Jul 2024 17:49 UTC
Jul 22 13:40:21 **** python3[3213]: Build UUID:       5f886798-85fc-4c20-ac53-8629ec6c8f5c
Jul 22 13:40:21 **** python3[3213]: Build commit ID:  31684479b205ca
Jul 22 13:40:21 **** Architecture[3213]:     x86_64
Jul 22 13:40:21 **** python3[3213]: Boot via:         installed image
Jul 22 13:40:21 **** python3[3213]: System type:      bare metal
Jul 22 13:40:21 **** python3[3213]: Hardware vendor:  Dell Inc.
Jul 22 13:40:21 **** python3[3213]: Hardware model:   OptiPlex 3070
Jul 22 13:40:21 **** python3[3213]: Hardware S/N:     *******
Jul 22 13:40:21 **** python3[3213]: Hardware UUID:    ******************************
Jul 22 13:40:21 **** python3[3213]: Traceback (most recent call last):
Jul 22 13:40:21 **** python3[3213]:   File "/usr/libexec/vyos/conf_mode/interfaces_wwan.py", line 186, in <module>
Jul 22 13:40:21 **** python3[3213]:     apply(c)
Jul 22 13:40:21 **** python3[3213]:   File "/usr/libexec/vyos/conf_mode/interfaces_wwan.py", line 143, in apply
Jul 22 13:40:21 **** python3[3213]:     cmd(f'{base_cmd} --simple-disconnect')
Jul 22 13:40:21 **** python3[3213]:   File "/usr/lib/python3/dist-packages/vyos/utils/process.py", line 155, in cmd
Jul 22 13:40:21 **** python3[3213]:     raise OSError(code, feedback)
Jul 22 13:40:21 **** PermissionError[3213]: [Errno 1] failed to run command: mmcli --modem 0 --simple-disconnect
Jul 22 13:40:21 **** returned[3213]: 
Jul 22 13:40:21 **** python3[3213]: exit code: 1
Jul 22 13:40:21 **** noteworthy[3213]: 
Jul 22 13:40:21 **** python3[3213]: cmd 'mmcli --modem 0 --simple-disconnect'
Jul 22 13:40:21 **** python3[3213]: returned (out):
Jul 22 13:40:21 **** python3[3213]: returned (err):
Jul 22 13:40:21 **** error[3213]: couldn't find modem

after installing polkit from ubuntu 22.04 into /etc/dbus-1/system.d/org.freedesktop.ModemManager1.conf in hopes that this is a permission issue:

Jul 22 14:28:28 **** ModemManager[2760]: [1721658508.197325] [device /sys/devices/pci0000:00/0000:00:14.0/usb1/1-1] creating modem wi>
Jul 22 14:28:28 **** ModemManager[2760]: [1721658508.204171] [plugin/sierra] could not grab port ttyUSB1: Cannot add port 'tty/ttyUSB>
Jul 22 14:28:28 **** ModemManager[2760]: [1721658508.207370] [base-manager] modem for device '/sys/devices/pci0000:00/0000:00:14.0/us>
Jul 22 14:28:28 **** vyos-configd[801]: [Errno 1] failed to run command: mmcli --modem 0 --simple-disconnect
Jul 22 14:28:28 **** vyos-configd[801]: returned:
Jul 22 14:28:28 **** vyos-configd[801]: exit code: 1
Jul 22 14:28:28 **** vyos-configd[801]: Sending response 4
Jul 22 14:28:28 **** ModemManager[2760]: [1721658508.666411] [modem0/cdc-wdm0/mbim] MBIM device is QMI capable
Jul 22 14:28:29 **** ModemManager[2760]: [1721658509.306339] [modem0] QMI-based capability and mode switching support enabled
Jul 22 14:28:29 **** python3[3211]: Report time:      2024-07-22 14:28:29
Jul 22 14:28:29 **** python3[3211]: Image version:    VyOS 1.5-rolling-202407171706
Jul 22 14:28:29 **** python3[3211]: Release train:    current
Jul 22 14:28:29 **** python3[3211]: Built by:         autobuild@vyos.net
Jul 22 14:28:29 **** python3[3211]: Built on:         Wed 17 Jul 2024 17:49 UTC
Jul 22 14:28:29 **** python3[3211]: Build UUID:       5f886798-85fc-4c20-ac53-8629ec6c8f5c
Jul 22 14:28:29 **** python3[3211]: Build commit ID:  31684479b205ca
Jul 22 14:28:29 **** Architecture[3211]:     x86_64
Jul 22 14:28:29 **** python3[3211]: Boot via:         installed image
Jul 22 14:28:29 **** python3[3211]: System type:      bare metal
Jul 22 14:28:29 **** python3[3211]: Hardware vendor:  Dell Inc.
Jul 22 14:28:29 **** python3[3211]: Hardware model:   OptiPlex 3070
Jul 22 14:28:29 **** python3[3211]: Hardware S/N:     *******
Jul 22 14:28:29 **** python3[3211]: Hardware UUID:    ******************************
Jul 22 14:28:29 **** python3[3211]: Traceback (most recent call last):
Jul 22 14:28:29 **** python3[3211]:   File "/usr/libexec/vyos/conf_mode/interfaces_wwan.py", line 186, in <module>
Jul 22 14:28:29 **** python3[3211]:     apply(c)
Jul 22 14:28:29 **** python3[3211]:   File "/usr/libexec/vyos/conf_mode/interfaces_wwan.py", line 143, in apply
Jul 22 14:28:29 **** python3[3211]:     cmd(f'{base_cmd} --simple-disconnect')
Jul 22 14:28:29 **** python3[3211]:   File "/usr/lib/python3/dist-packages/vyos/utils/process.py", line 155, in cmd
Jul 22 14:28:29 **** python3[3211]:     raise OSError(code, feedback)
Jul 22 14:28:29 **** PermissionError[3211]: [Errno 1] failed to run command: mmcli --modem 0 --simple-disconnect
Jul 22 14:28:29 **** returned[3211]: 
Jul 22 14:28:29 **** python3[3211]: exit code: 1
Jul 22 14:28:29 **** noteworthy[3211]: 
Jul 22 14:28:29 **** python3[3211]: cmd 'mmcli --modem 0 --simple-disconnect'
Jul 22 14:28:29 **** python3[3211]: returned (out):
Jul 22 14:28:29 **** python3[3211]: returned (err):
Jul 22 14:28:29 **** error[3211]: couldn't find modem

re-adding modem lines yields successful connect:

Jul 22 14:33:47 **** vyos-configd[801]: Received message: {"type": "init"}
Jul 22 14:33:48 **** vyos-configd[801]: config session pid is 4982
Jul 22 14:33:48 **** vyos-configd[801]: config session sudo_user is galets
Jul 22 14:33:48 **** vyos-configd[801]: Received message: {"type": "node", "last": true, "data": "VYOS_TAGNODE_VALUE=wwan0/usr/libexe>
Jul 22 14:33:48 **** vyos-configd[801]: final element of priority queue
Jul 22 14:33:48 **** ModemManager[2760]: [1721658828.481920] [modem0] simple connect started...
Jul 22 14:33:48 **** ModemManager[2760]: [1721658828.481944] [modem0] simple connect state (3/10): enable
Jul 22 14:33:48 **** ModemManager[2760]: [1721658828.481972] [modem0] state changed (disabled -> enabling)
Jul 22 14:33:48 **** ModemManager[2760]: [1721658828.592780] [modem0] power state updated: on
Jul 22 14:33:49 **** ModemManager[2760]: [1721658829.017343] [modem0] simple connect state (4/10): wait to get fully enabled
Jul 22 14:33:49 **** ModemManager[2760]: [1721658829.017480] [modem0] state changed (enabling -> enabled)
Jul 22 14:33:49 **** ModemManager[2760]: [1721658829.017616] [modem0] 3GPP registration state changed (unknown -> registering)
Jul 22 14:33:49 **** ModemManager[2760]: [1721658829.018442] [modem0] simple connect state (5/10): wait after enabled
Jul 22 14:33:49 **** ModemManager[2760]: [1721658829.018641] [modem0] 3GPP registration state changed (registering -> home)
Jul 22 14:33:49 **** ModemManager[2760]: [1721658829.018747] [modem0] state changed (enabled -> registered)
Jul 22 14:33:49 **** ModemManager[2760]: [1721658829.119411] [modem0] simple connect state (6/10): register
Jul 22 14:33:49 **** ModemManager[2760]: [1721658829.119571] [modem0] simple connect state (7/10): wait to get packet service state a>
Jul 22 14:33:49 **** ModemManager[2760]: [1721658829.119653] [modem0] simple connect state (8/10): bearer
Jul 22 14:33:49 **** ModemManager[2760]: [1721658829.120581] [modem0] simple connect state (9/10): connect
Jul 22 14:33:49 **** ModemManager[2760]: [1721658829.120804] [modem0] state changed (registered -> connecting)
Jul 22 14:33:49 **** ModemManager[2760]: [1721658829.552396] [modem0/bearer0] reloading stats is supported by the device
Jul 22 14:33:49 **** ModemManager[2760]: [1721658829.552506] [modem0] state changed (connecting -> connected)
Jul 22 14:33:49 **** ModemManager[2760]: [1721658829.553864] [modem0] simple connect state (10/10): all done
Jul 22 14:33:49 **** vyos-configd[801]: Sending response 1

this seems to be initialization race condition, e.g.: config is being loaded before ModemManager is fully initialized. Re-applying config after it is loaded resolves the issue, however warning never goes away and on reboot the issue re-appears.