ANN: ModemManager 1.18.4 released / Avoiding PPP
Peter Naulls
peter at chocky.org
Wed Jan 12 14:22:53 UTC 2022
On 1/12/22 4:25 AM, Aleksander Morgado wrote:
> Hey
>
>>> Also, please note that if you fully disable the PPP usage (maybe
>>> making sure that data_at_primary is always NULL in
>>> mm_base_modem_organize_ports()), what you will achieve is that the
>>> modem ends up not usable ("Failed to find a data port in the modem").
>>> You need to decide whether that's better than falling back to PPP. As
>>> said in an earlier email, the key would be to understand why you don't
>>> have a valid QMI+NET pair, not really to disable the PPP usage (IMO).
>>
>> Well, it took me a while to get this; it requires a specific setup. What I can
>> say is that it most often happens at OpenWrt boot, but by no means always.
>>
>
> There's a problem in that log, and the problem is exclusively
> happening on system boots.
I'll take your word for it, *but* the problem with triggering PPP happens
other times too, but it's just most likely at boot. The end result is much
the same.
It's worth pointing out that if there's loss of connectivity on the modem
(unplug the antenna for example), it will completely cycle the USB and the
ports will vanish and then come back. I don't know if this is normal, but
the effect is much like (but not identical) to that of boot.
As a digression, the "45 second" issue to which I put the retries in for
would most often happen at "first boot" where it's setting up the flash,
but MM hadn't started yet.
In any case, I have a script which power cycles the modem and the USB
hub, which closely emulates the power on cycle/signal loss, but is obviously not
100% identical. I use this for some of my testing.
Here's a log where the system does come up properly; I think this is worth
considering to make sure this is OK:
ue Jan 11 18:13:57 2022 user.notice ModemManager: hotplug: add network interface
ip6tnl0: event processed
Tue Jan 11 18:13:57 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:13:57 2022 user.notice ModemManager: hotplug: add network
interface gre0: event processed
Tue Jan 11 18:13:57 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:13:58 2022 kern.info kernel: [ 30.616720] mtk_soc_eth
1e100000.ethernet: PPE started
Tue Jan 11 18:13:58 2022 kern.info kernel: [ 30.638877] br-lan: port 1(eth0.1)
entered blocking state
Tue Jan 11 18:13:58 2022 kern.info kernel: [ 30.649726] br-lan: port 1(eth0.1)
entered disabled state
Tue Jan 11 18:13:58 2022 kern.info kernel: [ 30.661516] device eth0.1 entered
promiscuous mode
Tue Jan 11 18:13:58 2022 kern.info kernel: [ 30.671169] device eth0 entered
promiscuous mode
Tue Jan 11 18:13:58 2022 user.notice ModemManager: hotplug: add network
interface gretap0: event processed
Tue Jan 11 18:13:58 2022 kern.info kernel: [ 30.686813] br-lan: port 1(eth0.1)
entered blocking state
Tue Jan 11 18:13:58 2022 kern.info kernel: [ 30.697655] br-lan: port 1(eth0.1)
entered forwarding state
Tue Jan 11 18:13:58 2022 kern.info kernel: [ 30.709392] IPv6:
ADDRCONF(NETDEV_UP): br-lan: link is not ready
Tue Jan 11 18:13:58 2022 daemon.notice netifd: Interface 'lan' is enabled
Tue Jan 11 18:13:58 2022 daemon.notice netifd: Interface 'lan' is setting up now
Tue Jan 11 18:13:58 2022 daemon.notice netifd: Interface 'lan' is now up
Tue Jan 11 18:13:58 2022 daemon.notice netifd: bridge 'br-lan' link is up
Tue Jan 11 18:13:58 2022 daemon.notice netifd: Interface 'lan' has link connectivity
Tue Jan 11 18:13:58 2022 daemon.notice netifd: VLAN 'eth0.1' link is up
Tue Jan 11 18:13:58 2022 daemon.notice netifd: Interface 'loopback' is enabled
Tue Jan 11 18:13:58 2022 daemon.notice netifd: Interface 'loopback' is setting
up now
Tue Jan 11 18:13:58 2022 daemon.notice netifd: Interface 'loopback' is now up
Tue Jan 11 18:13:58 2022 daemon.notice netifd: Interface 'wwan' is setting up now
Tue Jan 11 18:13:58 2022 daemon.notice netifd: Network device 'eth0' link is up
Tue Jan 11 18:13:58 2022 daemon.notice netifd: Network device 'lo' link is up
Tue Jan 11 18:13:58 2022 daemon.notice netifd: Interface 'loopback' has link
connectivity
Tue Jan 11 18:13:58 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:13:58 2022 daemon.notice netifd: wwan (2328): error: couldn't get
bus: Could not connect: No such file or directory
Tue Jan 11 18:13:58 2022 daemon.notice netifd: wwan (2328): Device not managed
by ModemManager
Tue Jan 11 18:13:58 2022 user.notice firewall: Reloading firewall due to ifup of
lan (br-lan)
Tue Jan 11 18:13:59 2022 daemon.notice netifd: wwan (2400): stopping network
Tue Jan 11 18:13:59 2022 daemon.notice netifd: wwan (2400): error: couldn't get
bus: Could not connect: No such file or directory
Tue Jan 11 18:13:59 2022 daemon.notice netifd: wwan (2400): couldn't load bearer
path
Tue Jan 11 18:13:59 2022 daemon.notice netifd: Interface 'wwan' is now down
Tue Jan 11 18:13:59 2022 kern.info kernel: [ 31.643038] IPv6:
ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
Tue Jan 11 18:13:59 2022 user.notice ModemManager: hotplug: add network
interface erspan0: event processed
Tue Jan 11 18:13:59 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:13:59 2022 daemon.err procd: failed to open pidfile for writing: :
No such file or directory
Tue Jan 11 18:14:00 2022 daemon.err odhcpd[1992]: Failed to send to
ff02::1%lan at br-lan (Address not available)
Tue Jan 11 18:14:00 2022 user.notice ModemManager: hotplug: add network
interface ip6gre0: event processed
Tue Jan 11 18:14:00 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:14:01 2022 user.notice ModemManager: hotplug: checking if
ModemManager is available...
Tue Jan 11 18:14:01 2022 daemon.info [2603]: <info> [1641924841.257035]
ModemManager (version 1.18.4) starting in system bus...
Tue Jan 11 18:14:01 2022 user.notice ModemManager: hotplug: ModemManager not yet
available
Tue Jan 11 18:14:01 2022 user.notice ModemManager: hotplug: add network
interface wwan0: event processed
Tue Jan 11 18:14:01 2022 user.notice ModemManager: hotplug: interface 'wwan' is
set to configure device '/sys/devices/platform/1e1c0000.xhci/usb2/2-1'
Tue Jan 11 18:14:01 2022 user.notice ModemManager: hotplug: now waiting for
modem at sysfs path /sys/devices/platform/1e1c0000.xhci/usb2/2-1
Tue Jan 11 18:14:01 2022 user.notice ModemManager: hotplug: add cdc interface
cdc-wdm0: custom event processed
Tue Jan 11 18:14:02 2022 user.notice ModemManager: hotplug: checking if
ModemManager is available...
Tue Jan 11 18:14:02 2022 user.notice ModemManager: hotplug: add serial interface
ttyUSB0: event processed
Tue Jan 11 18:14:02 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=console, subsystem=tty, sysfspath=/sys/devices/virtual/tty/console
Tue Jan 11 18:14:02 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:14:02 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=ttyS2, subsystem=tty,
sysfspath=/sys/devices/platform/serial8250/tty/ttyS2
Tue Jan 11 18:14:02 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:14:02 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=ttyS0, subsystem=tty,
sysfspath=/sys/devices/platform/1e000000.palmbus/1e000c00.uartlite/tty/ttyS0
Tue Jan 11 18:14:03 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:14:03 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=ttyS1, subsystem=tty,
sysfspath=/sys/devices/platform/serial8250/tty/ttyS1
Tue Jan 11 18:14:03 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:14:03 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=ip6tnl0, subsystem=net, sysfspath=/sys/devices/virtual/net/ip6tnl0
Tue Jan 11 18:14:03 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:14:03 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Opening device
with flags 'version-info, proxy'...
Tue Jan 11 18:14:03 2022 daemon.debug [2603]: [/dev/cdc-wdm0] created endpoint
Tue Jan 11 18:14:03 2022 daemon.debug [2603]: cannot connect to proxy: Could not
connect: Connection refused
Tue Jan 11 18:14:03 2022 daemon.debug [2603]: spawning new qmi-proxy (try 1)...
Tue Jan 11 18:14:03 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=gre0, subsystem=net, sysfspath=/sys/devices/virtual/net/gre0
Tue Jan 11 18:14:03 2022 user.notice ModemManager: hotplug: add serial interface
ttyUSB1: event processed
Tue Jan 11 18:14:03 2022 daemon.debug [2603]: cannot connect to proxy: Could not
connect: Connection refused
Tue Jan 11 18:14:03 2022 daemon.debug [2603]: spawning new qmi-proxy (try 2)...
Tue Jan 11 18:14:03 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:14:04 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Checking version
info (45 retries)...
Tue Jan 11 18:14:04 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=gretap0, subsystem=net, sysfspath=/sys/devices/virtual/net/gretap0
Tue Jan 11 18:14:04 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:14:04 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=erspan0, subsystem=net, sysfspath=/sys/devices/virtual/net/erspan0
Tue Jan 11 18:14:04 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:14:04 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=ip6gre0, subsystem=net, sysfspath=/sys/devices/virtual/net/ip6gre0
Tue Jan 11 18:14:04 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:14:04 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=wwan0, subsystem=net,
sysfspath=/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.4/net/wwan0
Tue Jan 11 18:14:05 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=cdc-wdm0, subsystem=usbmisc,
sysfspath=/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.4/net/wwan0
Tue Jan 11 18:14:05 2022 user.notice root: MCU Version check: Configured:
vehicle Firmware Version: 0x03 config: 0x00
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] No transaction
matched in received message
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] QMI Device
supports 28 services:
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] ctl (1.5)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] wds (1.119)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] dms (1.0)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] nas (1.25)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] qos (1.12)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] wms (1.10)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] auth (1.3)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] at (1.4)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] voice (2.1)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] cat2 (2.24)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] uim (1.77)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] pbm (1.4)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] test (1.0)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] loc (2.0)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] sar (1.0)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] ts (1.0)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] tmd (1.0)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] wda (1.16)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] csvt (1.1)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] coex (1.0)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] pdc (1.0)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] rfrpe (1.0)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] dsd (1.0)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] unknown [0x30]
(1.0)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] unknown [0x31]
(1.0)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] unknown [0x36]
(1.0)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] unknown [0x44]
(1.0)
Tue Jan 11 18:14:05 2022 daemon.debug [2603]: [/dev/cdc-wdm0] unknown [0x4a]
(1.0)
Tue Jan 11 18:14:05 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=ttyUSB0, subsystem=tty,
sysfspath=/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.0/ttyUSB0/tty/ttyUSB0
Tue Jan 11 18:14:05 2022 user.notice ModemManager: hotplug: add serial interface
ttyUSB2: event processed
Tue Jan 11 18:14:05 2022 daemon.info [2603]: <info> [1641924845.629711] [device
/sys/devices/platform/1e1c0000.xhci/usb2/2-1] creating modem with plugin
'quectel' and '4' ports
Tue Jan 11 18:14:05 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=ttyUSB1, subsystem=tty,
sysfspath=/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.1/ttyUSB1/tty/ttyUSB1
Tue Jan 11 18:14:06 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=ttyUSB2, subsystem=tty,
sysfspath=/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.2/ttyUSB2/tty/ttyUSB2
Tue Jan 11 18:14:06 2022 daemon.info [2603]: <info> [1641924846.191458]
[base-manager] modem for device '/sys/devices/platform/1e1c0000.xhci/usb2/2-1'
successfully created
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Opening device
with flags 'version-info, proxy'...
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] created endpoint
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Checking version
info (45 retries)...
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] QMI Device
supports 28 services:
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] ctl (1.5)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] wds (1.119)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] dms (1.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] nas (1.25)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] qos (1.12)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] wms (1.10)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] auth (1.3)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] at (1.4)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] voice (2.1)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] cat2 (2.24)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] uim (1.77)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] pbm (1.4)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] test (1.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] loc (2.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] sar (1.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] ts (1.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] tmd (1.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] wda (1.16)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] csvt (1.1)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] coex (1.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] pdc (1.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] rfrpe (1.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] dsd (1.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] unknown [0x30]
(1.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] unknown [0x31]
(1.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] unknown [0x36]
(1.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] unknown [0x44]
(1.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] unknown [0x4a]
(1.0)
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Registered 'wda'
(version 1.16) client with ID '1'
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Releasing 'wda'
client with flags 'release-cid'...
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Unregistered 'wda'
client with ID '1'
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Registered 'dms'
(version 1.0) client with ID '1'
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Registered 'nas'
(version 1.25) client with ID '5'
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Registered 'wds'
(version 1.119) client with ID '18'
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Registered 'wms'
(version 1.10) client with ID '2'
Tue Jan 11 18:14:06 2022 user.notice ModemManager: hotplug: add serial interface
ttyUSB3: event processed
Tue Jan 11 18:14:06 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Registered 'uim'
(version 1.77) client with ID '3'
Tue Jan 11 18:14:07 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Registered 'loc'
(version 2.0) client with ID '1'
Tue Jan 11 18:14:07 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Registered 'pdc'
(version 1.0) client with ID '1'
Tue Jan 11 18:14:07 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Registered 'voice'
(version 2.1) client with ID '4'
Tue Jan 11 18:14:07 2022 daemon.info procd: - init complete -
Tue Jan 11 18:14:07 2022 user.notice ModemManager: hotplug: add network
interface br-lan: event processed
Tue Jan 11 18:14:07 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:14:08 2022 user.notice ModemManager: hotplug: add network
interface eth0.1: event processed
Tue Jan 11 18:14:08 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Tue Jan 11 18:14:10 2022 daemon.warn [2603]: <warn> [1641924850.320900]
[modem0/sim0] couldn't load list of emergency numbers: No AT port available to
run command
Tue Jan 11 18:14:10 2022 daemon.info [2603]: <info> [1641924850.569189]
[base-manager] couldn't check support for device
'/sys/devices/platform/1e100000.ethernet': not supported by any plugin
Tue Jan 11 18:14:10 2022 daemon.warn [2603]: <warn> [1641924850.708098]
[modem0] couldn't load UE mode of operation for EPS: No AT port available to run
command
Tue Jan 11 18:14:11 2022 daemon.warn [2603]: <warn> [1641924851.429237]
[modem0] couldn't open ports during Modem SIM hot swap enabling: Couldn't get
primary port
Tue Jan 11 18:14:11 2022 daemon.info [2603]: <info> [1641924851.430371]
[modem0] state changed (unknown -> disabled)
Tue Jan 11 18:14:12 2022 user.notice ModemManager: hotplug: modem exported
successfully at /sys/devices/platform/1e1c0000.xhci/usb2/2-1
Tue Jan 11 18:14:12 2022 user.notice ModemManager: hotplug: setting interface
'wwan' as available
Tue Jan 11 18:14:12 2022 daemon.notice netifd: Interface 'wwan' is setting up now
Tue Jan 11 18:14:12 2022 daemon.notice netifd: wwan (4900): modem available at
/org/freedesktop/ModemManager1/Modem/0
Tue Jan 11 18:14:12 2022 daemon.notice netifd: wwan (4900): starting connection
with apn 'firstnet-broadband'...
Tue Jan 11 18:14:12 2022 daemon.info [2603]: <info> [1641924852.763833]
[modem0] simple connect started...
Tue Jan 11 18:14:12 2022 daemon.info [2603]: <info> [1641924852.764102]
[modem0] simple connect state (3/8): enable
Tue Jan 11 18:14:12 2022 daemon.info [2603]: <info> [1641924852.764524]
[modem0] state changed (disabled -> enabling)
Tue Jan 11 18:14:12 2022 daemon.info [2603]: <info> [1641924852.983603]
[modem0] autoconnect explicitly disabled
Tue Jan 11 18:14:13 2022 daemon.info [2603]: <info> [1641924853.105314]
[modem0] power state updated: on
Tue Jan 11 18:14:14 2022 daemon.info [2603]: <info> [1641924854.385721]
[modem0] simple connect state (4/8): wait to get fully enabled
Tue Jan 11 18:14:14 2022 daemon.info [2603]: <info> [1641924854.386581]
[modem0] state changed (enabling -> enabled)
Tue Jan 11 18:14:14 2022 daemon.info [2603]: <info> [1641924854.393321]
[modem0] simple connect state (5/8): register
Tue Jan 11 18:14:14 2022 daemon.info [2603]: <info> [1641924854.513488]
[modem0] 3GPP registration state changed (unknown -> registering)
Tue Jan 11 18:14:14 2022 daemon.info [2603]: <info> [1641924854.514782]
[modem0] 3GPP registration state changed (registering -> home)
Tue Jan 11 18:14:14 2022 daemon.info [2603]: <info> [1641924854.515336]
[modem0] state changed (enabled -> registered)
Tue Jan 11 18:14:14 2022 daemon.info [2603]: <info> [1641924854.642636]
[modem0] simple connect state (6/8): bearer
Tue Jan 11 18:14:14 2022 daemon.info [2603]: <info> [1641924854.655644]
[modem0] simple connect state (7/8): connect
Tue Jan 11 18:14:14 2022 daemon.info [2603]: <info> [1641924854.658590]
[modem0] state changed (registered -> connecting)
Tue Jan 11 18:14:14 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Registered 'wds'
(version 1.119) client with ID '19'
Tue Jan 11 18:14:15 2022 daemon.info [2603]: <info> [1641924855.472873]
[modem0/bearer1] QMI IPv4 Settings:
Tue Jan 11 18:14:15 2022 daemon.info [2603]: <info> [1641924855.473295]
[modem0/bearer1] address: 10.99.10.66/30
Tue Jan 11 18:14:15 2022 daemon.info [2603]: <info> [1641924855.473450]
[modem0/bearer1] gateway: 10.99.10.65
Tue Jan 11 18:14:15 2022 daemon.info [2603]: <info> [1641924855.473612]
[modem0/bearer1] DNS #1: 107.112.229.135
Tue Jan 11 18:14:15 2022 daemon.info [2603]: <info> [1641924855.473796]
[modem0/bearer1] DNS #2: failed (Field 'Secondary IPv4 DNS Address' was not
found in the message)
Tue Jan 11 18:14:15 2022 daemon.info [2603]: <info> [1641924855.473973]
[modem0/bearer1] MTU: 1342
Tue Jan 11 18:14:15 2022 daemon.debug [2603]: [/dev/cdc-wdm0] Registered 'wds'
(version 1.119) client with ID '20'
Tue Jan 11 18:14:16 2022 daemon.info [2603]: <info> [1641924856.368787]
[modem0/bearer1] QMI IPv6 Settings:
Tue Jan 11 18:14:16 2022 daemon.info [2603]: <info> [1641924856.369119]
[modem0/bearer1] address: 2600:380:fea3:a19a:909e:981f:304f:61ac/64
Tue Jan 11 18:14:16 2022 daemon.info [2603]: <info> [1641924856.369336]
[modem0/bearer1] gateway: 2600:380:fea3:a19a:948e:bc6:5528:a2c7/64
Tue Jan 11 18:14:16 2022 daemon.info [2603]: <info> [1641924856.369548]
[modem0/bearer1] DNS #1: 2600:300:2050:1e05::7
Tue Jan 11 18:14:16 2022 daemon.info [2603]: <info> [1641924856.369743]
[modem0/bearer1] DNS #2: failed (Field 'IPv6 Secondary DNS Address' was not
found in the message)
Tue Jan 11 18:14:16 2022 daemon.info [2603]: <info> [1641924856.369923]
[modem0/bearer1] MTU: 1342
Tue Jan 11 18:14:16 2022 daemon.info [2603]: <info> [1641924856.373960]
[modem0] state changed (connecting -> connected)
Tue Jan 11 18:14:16 2022 daemon.info [2603]: <info> [1641924856.377581]
[modem0] simple connect state (8/8): all done
Tue Jan 11 18:14:16 2022 daemon.notice netifd: wwan (4900): successfully
connected the modem
Tue Jan 11 18:14:16 2022 daemon.notice netifd: wwan (4900): signal refresh rate
is not set
Tue Jan 11 18:14:16 2022 daemon.notice netifd: wwan (4900): network operator
name: FirstNet
Tue Jan 11 18:14:16 2022 daemon.notice netifd: wwan (4900): network operator
MCCMNC: 313100
Tue Jan 11 18:14:16 2022 daemon.notice netifd: wwan (4900): registration type: home
Tue Jan 11 18:14:16 2022 daemon.notice netifd: wwan (4900): access technology: lte
Tue Jan 11 18:14:16 2022 daemon.notice netifd: wwan (4900): signal quality: 100%
Tue Jan 11 18:14:16 2022 daemon.notice netifd: wwan (4900): IPv4 connection
setup required in interface wwan: static
Tue Jan 11 18:14:16 2022 daemon.notice netifd: wwan (4900): adding IPv4 address
10.99.10.66, netmask 255.255.255.252
Tue Jan 11 18:14:16 2022 daemon.notice netifd: wwan (4900): adding default IPv4
route via 10.99.10.65
Tue Jan 11 18:14:16 2022 daemon.notice netifd: wwan (4900): adding primary DNS
at 107.112.229.135
Tue Jan 11 18:14:16 2022 daemon.notice netifd: Interface 'wwan' is now up
Tue Jan 11 18:14:16 2022 daemon.info dnsmasq[1582]: reading
/tmp/resolv.conf.d/resolv.conf.auto
Tue Jan 11 18:14:16 2022 daemon.notice netifd: Network device 'wwan0' link is up
Tue Jan 11 18:14:16 2022 daemon.info dnsmasq[1582]: using nameserver
107.112.229.135#53
Tue Jan 11 18:14:16 2022 daemon.info dnsmasq[1582]: using only locally-known
addresses for test
Tue Jan 11 18:14:16 2022 daemon.info dnsmasq[1582]: using only locally-known
addresses for onion
Tue Jan 11 18:14:16 2022 daemon.notice netifd: wwan (4900): IPv6 connection
setup required in interface wwan: static
Tue Jan 11 18:14:16 2022 daemon.info dnsmasq[1582]: using only locally-known
addresses for localhost
Tue Jan 11 18:14:16 2022 daemon.info dnsmasq[1582]: using only locally-known
addresses for local
Tue Jan 11 18:14:16 2022 daemon.info dnsmasq[1582]: using only locally-known
addresses for invalid
Tue Jan 11 18:14:16 2022 daemon.info dnsmasq[1582]: using only locally-known
addresses for bind
Tue Jan 11 18:14:16 2022 daemon.info dnsmasq[1582]: using only locally-known
addresses for lan
Tue Jan 11 18:14:17 2022 daemon.notice netifd: wwan (4900): adding IPv6 address
2600:380:fea3:a19a:909e:981f:304f:61ac, prefix 64
Tue Jan 11 18:14:17 2022 daemon.notice netifd: wwan (4900): adding default IPv6
route via 2600:380:fea3:a19a:948e:bc6:5528:a2c7
Tue Jan 11 18:14:17 2022 daemon.notice netifd: wwan (4900): adding primary DNS
at 2600:300:2050:1e05::7
Tue Jan 11 18:14:17 2022 daemon.info dnsmasq[1582]: reading
/tmp/resolv.conf.d/resolv.conf.auto
Tue Jan 11 18:14:17 2022 daemon.info dnsmasq[1582]: using nameserver
107.112.229.135#53
Tue Jan 11 18:14:17 2022 daemon.info dnsmasq[1582]: using nameserver
2600:300:2050:1e05::7#53
Tue Jan 11 18:14:17 2022 daemon.info dnsmasq[1582]: using only locally-known
addresses for test
Tue Jan 11 18:14:17 2022 daemon.info dnsmasq[1582]: using only locally-known
addresses for onion
Tue Jan 11 18:14:17 2022 daemon.info dnsmasq[1582]: using only locally-known
addresses for localhost
Tue Jan 11 18:14:17 2022 daemon.info dnsmasq[1582]: using only locally-known
addresses for local
Tue Jan 11 18:14:17 2022 daemon.info dnsmasq[1582]: using only locally-known
addresses for invalid
Tue Jan 11 18:14:17 2022 daemon.info dnsmasq[1582]: using only locally-known
addresses for bind
Tue Jan 11 18:14:17 2022 daemon.info dnsmasq[1582]: using only locally-known
addresses for lan
Tue Jan 11 18:14:17 2022 user.notice firewall: Reloading firewall due to ifup of
wwan (wwan0)
Tue Jan 11 18:14:17 2022 user.notice firewall: Reloading firewall due to
ifupdate of wwan (wwan0)
Tue Jan 11 18:14:18 2022 daemon.warn odhcpd[1992]: A default route is present
but there is no public prefix on lan thus we don't announce a default route!
Tue Jan 11 18:14:19 2022 daemon.info dnsmasq[1582]: read /etc/hosts - 4 addresses
Tue Jan 11 18:14:19 2022 daemon.info dnsmasq[1582]: read
/tmp/hosts/dhcp.cfg01411c - 0 addresses
More information about the ModemManager-devel
mailing list