ANN: ModemManager 1.18.4 released / Avoiding PPP
Peter Naulls
peter at chocky.org
Thu Jan 13 14:22:17 UTC 2022
On 1/13/22 5:08 AM, Aleksander Morgado wrote:
> Hey Peter,
>
>
> Unfortunately this log is missing the port notifications and the port
> probing phase; so we cannot investigate why the QMI port was not
> included in the modem object :/
> We need the log including the port addition events until the modem
> object is created; the connection attempt itself is really not needed
> to debug this problem.
>
Ok, I think I got it.
Wed Jan 12 19:32:31 2022 user.notice ModemManager: hotplug: add network
interface ip6tnl0: event processed
Wed Jan 12 19:32:31 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:31 2022 user.notice ModemManager: hotplug: add network
interface gre0: event processed
Wed Jan 12 19:32:31 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:32 2022 user.notice : Added device handler type: bonding
Wed Jan 12 19:32:32 2022 user.notice : Added device handler type: 8021ad
Wed Jan 12 19:32:32 2022 user.notice : Added device handler type: 8021q
Wed Jan 12 19:32:32 2022 user.notice : Added device handler type: macvlan
Wed Jan 12 19:32:32 2022 user.notice : Added device handler type: veth
Wed Jan 12 19:32:32 2022 user.notice : Added device handler type: bridge
Wed Jan 12 19:32:32 2022 user.notice : Added device handler type: Network device
Wed Jan 12 19:32:32 2022 user.notice : Added device handler type: tunnel
Wed Jan 12 19:32:32 2022 user.notice ModemManager: hotplug: add network
interface gretap0: event processed
Wed Jan 12 19:32:32 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:33 2022 user.notice ModemManager: hotplug: add network
interface erspan0: event processed
Wed Jan 12 19:32:33 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:33 2022 kern.info kernel: [ 30.281783] mtk_soc_eth
1e100000.ethernet: PPE started
Wed Jan 12 19:32:33 2022 kern.info kernel: [ 30.303055] br-lan: port 1(eth0.1)
entered blocking state
Wed Jan 12 19:32:33 2022 kern.info kernel: [ 30.313910] br-lan: port 1(eth0.1)
entered disabled state
Wed Jan 12 19:32:33 2022 kern.info kernel: [ 30.326039] device eth0.1 entered
promiscuous mode
Wed Jan 12 19:32:33 2022 kern.info kernel: [ 30.335772] device eth0 entered
promiscuous mode
Wed Jan 12 19:32:33 2022 kern.info kernel: [ 30.351905] br-lan: port 1(eth0.1)
entered blocking state
Wed Jan 12 19:32:33 2022 kern.info kernel: [ 30.362769] br-lan: port 1(eth0.1)
entered forwarding state
Wed Jan 12 19:32:33 2022 kern.info kernel: [ 30.374506] IPv6:
ADDRCONF(NETDEV_UP): br-lan: link is not ready
Wed Jan 12 19:32:33 2022 daemon.notice netifd: Interface 'lan' is enabled
Wed Jan 12 19:32:33 2022 daemon.notice netifd: Interface 'lan' is setting up now
Wed Jan 12 19:32:33 2022 daemon.notice netifd: Interface 'lan' is now up
Wed Jan 12 19:32:33 2022 daemon.notice netifd: bridge 'br-lan' link is up
Wed Jan 12 19:32:33 2022 daemon.notice netifd: Interface 'lan' has link connectivity
Wed Jan 12 19:32:33 2022 daemon.notice netifd: VLAN 'eth0.1' link is up
Wed Jan 12 19:32:33 2022 daemon.notice netifd: Interface 'loopback' is enabled
Wed Jan 12 19:32:33 2022 daemon.notice netifd: Interface 'loopback' is setting
up now
Wed Jan 12 19:32:33 2022 daemon.notice netifd: Interface 'loopback' is now up
Wed Jan 12 19:32:33 2022 daemon.notice netifd: Interface 'wwan' is setting up now
Wed Jan 12 19:32:33 2022 daemon.notice netifd: Network device 'eth0' link is up
Wed Jan 12 19:32:33 2022 daemon.notice netifd: Network device 'lo' link is up
Wed Jan 12 19:32:33 2022 daemon.notice netifd: Interface 'loopback' has link
connectivity
Wed Jan 12 19:32:33 2022 daemon.notice netifd: wwan (2475): error: couldn't get
bus: Could not connect: No such file or directory
Wed Jan 12 19:32:34 2022 daemon.notice netifd: wwan (2475): Device not managed
by ModemManager
Wed Jan 12 19:32:34 2022 daemon.notice netifd: wwan (2521): stopping network
Wed Jan 12 19:32:34 2022 user.notice firewall: Reloading firewall due to ifup of
lan (br-lan)
Wed Jan 12 19:32:34 2022 daemon.notice netifd: wwan (2521): error: couldn't get
bus: Could not connect: No such file or directory
Wed Jan 12 19:32:34 2022 user.notice ModemManager: hotplug: add network
interface ip6gre0: event processed
Wed Jan 12 19:32:34 2022 daemon.notice netifd: wwan (2521): couldn't load bearer
path
Wed Jan 12 19:32:34 2022 daemon.notice netifd: Interface 'wwan' is now down
Wed Jan 12 19:32:34 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:34 2022 kern.info kernel: [ 31.368611] IPv6:
ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
Wed Jan 12 19:32:34 2022 daemon.err procd: failed to open pidfile for writing: :
No such file or directory
Wed Jan 12 19:32:35 2022 user.notice ModemManager: hotplug: add network
interface wwan0: event processed
Wed Jan 12 19:32:35 2022 user.notice ModemManager: hotplug: interface 'wwan' is
set to configure device '/sys/devices/platform/1e1c0000.xhci/usb2/2-1'
Wed Jan 12 19:32:35 2022 daemon.err odhcpd[2130]: Failed to send to
ff02::1%lan at br-lan (Address not available)
Wed Jan 12 19:32:35 2022 user.notice ModemManager: hotplug: now waiting for
modem at sysfs path /sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:35 2022 user.notice ModemManager: hotplug: add cdc interface
cdc-wdm0: custom event processed
Wed Jan 12 19:32:35 2022 user.notice ucitrack: Setting up /etc/config/network
reload dependency on /etc/config/dhcp
Wed Jan 12 19:32:35 2022 user.notice ucitrack: Setting up /etc/config/wireless
reload dependency on /etc/config/network
Wed Jan 12 19:32:36 2022 user.notice ucitrack: Setting up /etc/config/firewall
reload dependency on /etc/config/luci-splash
Wed Jan 12 19:32:36 2022 user.notice ucitrack: Setting up /etc/config/firewall
reload dependency on /etc/config/qos
Wed Jan 12 19:32:36 2022 user.notice ModemManager: hotplug: checking if
ModemManager is available...
Wed Jan 12 19:32:36 2022 user.notice ucitrack: Setting up /etc/config/firewall
reload dependency on /etc/config/miniupnpd
Wed Jan 12 19:32:36 2022 user.notice ModemManager: hotplug: ModemManager not yet
available
Wed Jan 12 19:32:36 2022 user.notice ModemManager: hotplug: add serial interface
ttyUSB0: event processed
Wed Jan 12 19:32:36 2022 daemon.info [2709]: <info> [1642015956.367284]
ModemManager (version 1.18.4) starting in system bus...
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.376579]
[charsets] detecting platform iconv() support...
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.383435]
[charsets] UTF-8: iconv conversion to/from charset is supported
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.384310]
[charsets] UCS-2BE: iconv conversion to charset not supported
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.384927]
[charsets] ASCII: iconv conversion to/from charset is supported
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.385457]
[charsets] ISO8859-1: iconv conversion to charset not supported
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.385902]
[charsets] CP437: iconv conversion to charset not supported
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.386370]
[charsets] CP850: iconv conversion to charset not supported
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.386789]
[charsets] UTF-16BE: iconv conversion to/from charset is supported
Wed Jan 12 19:32:36 2022 user.notice ucitrack: Setting up /etc/config/dhcp
reload dependency on /etc/config/odhcpd
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.429339] bus
acquired, creating manager...
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.467919]
[auth-provider] singleton created
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.479975]
[filter] created
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.485626]
[filter] explicit whitelist: yes
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.485955]
[filter] explicit blacklist: yes
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.486254]
[filter] plugin whitelist: yes
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.486552]
[filter] qrtr devices allowed: yes
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.486843]
[filter] virtual devices forbidden: yes
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.487147]
[filter] net devices allowed: yes
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.487442]
[filter] usbmisc devices allowed: yes
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.487738]
[filter] rpmsg devices allowed: yes
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.488035]
[filter] wwan devices allowed: yes
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.488333]
[filter] tty devices:
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.488613]
[filter] platform driver check: yes
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.488930]
[filter] driver check: yes
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.489231]
[filter] cdc-acm interface check: yes
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.489528]
[filter] with net check: yes
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.489829]
[filter] default: forbidden
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.507730]
[plugin-manager] looking for plugins in '/usr/lib/ModemManager'
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.585216]
[plugin-manager] loaded plugin 'quectel' from
'/usr/lib/ModemManager/libmm-plugin-quectel.so'
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.585930]
[filter] registered plugin whitelist vendor id: 2c7c
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.586380]
[filter] registered plugin whitelist vendor id: 1eac
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.586540]
[plugin-manager] generic plugin not loaded
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.586777]
[plugin-manager] successfully loaded 1 plugins registering 4 subsystems: tty,
net, usbmisc, wwan
Wed Jan 12 19:32:36 2022 daemon.debug [2709]: <debug> [1642015956.597948]
service name 'org.freedesktop.ModemManager1' was acquired
Wed Jan 12 19:32:36 2022 user.notice ucitrack: Setting up non-init
/etc/config/fstab reload handler: /sbin/block mount
Wed Jan 12 19:32:36 2022 user.notice ucitrack: Setting up /etc/config/system
reload trigger for non-procd /etc/init.d/led
Wed Jan 12 19:32:36 2022 user.notice ucitrack: Setting up /etc/config/system
reload dependency on /etc/config/luci_statistics
Wed Jan 12 19:32:37 2022 user.notice ucitrack: Setting up /etc/config/system
reload dependency on /etc/config/dhcp
Wed Jan 12 19:32:37 2022 user.notice ModemManager: hotplug: add serial interface
ttyUSB1: event processed
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.270123]
[base-manager] kernel event reported:
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.270434]
[base-manager] action: add
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.270619]
[base-manager] subsystem: tty
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.270805]
[base-manager] name: ttyUSB1
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.271000]
[base-manager] uid: n/a
Wed Jan 12 19:32:37 2022 user.notice ModemManager: hotplug: checking if
ModemManager is available...
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.504123]
[ttyUSB1] preloading contents and properties...
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.507742]
[ttyUSB1] sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.1/ttyUSB1/tty/ttyUSB1
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.525832]
[ttyUSB1] port contents loaded:
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.526158]
[ttyUSB1] bus: usb
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.526357]
[ttyUSB1] interface: /sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.1
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.526578]
[ttyUSB1] interface class: ff
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.526790]
[ttyUSB1] interface subclass: 00
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.526964]
[ttyUSB1] interface protocol: 00
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.527154]
[ttyUSB1] interface number: 01
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.527379]
[ttyUSB1] device: /sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.527571]
[ttyUSB1] subsystems: tty, usb-serial, usb
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.527752]
[ttyUSB1] drivers: option1, option, usb
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.527921]
[ttyUSB1] vendor: 2c7c
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.528099]
[ttyUSB1] product: 0512
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.528306]
[ttyUSB1] revision: 0318
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.528483]
[ttyUSB1] manufacturer: Quectel
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.528675]
[ttyUSB1] product: EM12-AW
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.532322]
[ttyUSB1] ID_USB_INTERFACE_NUM: 0x01
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.532735]
[ttyUSB1] ID_MODEL: EM12-AW
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.532946]
[ttyUSB1] ID_VENDOR: Quectel
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.533227]
[ttyUSB1] ID_VENDOR_ID: 0x2c7c
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.533478]
[ttyUSB1] ID_MODEL_ID: 0x0512
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.533758]
[ttyUSB1] ID_REVISION: 0x0318
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.534616]
[ttyUSB1] property added: .MM_USBIFNUM=01
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.536126]
[ttyUSB1] property added: .MM_USBIFNUM=01
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.536553]
[ttyUSB1] property added: ID_MM_PORT_TYPE_GPS=1
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.539454]
[ttyUSB1] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.539903]
[base-manager] adding port ttyUSB1 at sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.1/ttyUSB1/tty/ttyUSB1
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.546808]
[filter] (tty/ttyUSB1) port allowed: device is whitelisted by plugin (vid)
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.547242]
[base-manager] port ttyUSB1 is first in device
/sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.566848]
[plugin-manager] task 0: new support task for device:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.586429]
[plugin-manager] task 0: port grabbed: ttyUSB1
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.587136]
[plugin-manager] task 0,ttyUSB1: new support task for port
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.587551]
[plugin-manager] task 0,ttyUSB1: deferred until min wait time elapsed
Wed Jan 12 19:32:37 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=console, subsystem=tty, sysfspath=/sys/devices/virtual/tty/console
Wed Jan 12 19:32:37 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:37 2022 daemon.err insmod: module is already loaded - qmi_wwan
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.991576]
[base-manager] kernel event reported:
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.991895]
[base-manager] action: add
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.992075]
[base-manager] subsystem: tty
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.992497]
[base-manager] name: console
Wed Jan 12 19:32:37 2022 daemon.debug [2709]: <debug> [1642015957.992689]
[base-manager] uid: n/a
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015957.993103]
[console] preloading contents and properties...
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015957.993846]
[console] sysfs path: /sys/devices/virtual/tty/console
Wed Jan 12 19:32:38 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=ttyS2, subsystem=tty,
sysfspath=/sys/devices/platform/serial8250/tty/ttyS2
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015957.998371]
[console] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015957.998908]
[base-manager] adding port console at sysfs path: /sys/devices/virtual/tty/console
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015957.999248]
[filter] (tty/console) port filtered: virtual device
Wed Jan 12 19:32:38 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.200656]
[base-manager] kernel event reported:
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.201021]
[base-manager] action: add
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.201193]
[base-manager] subsystem: tty
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.201355]
[base-manager] name: ttyS2
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.201521]
[base-manager] uid: n/a
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.201874]
[ttyS2] preloading contents and properties...
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.202593]
[ttyS2] sysfs path: /sys/devices/platform/serial8250/tty/ttyS2
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.210816]
[ttyS2] port contents loaded:
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.211375]
[ttyS2] bus: platform
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.211738]
[ttyS2] device: /sys/devices/platform/serial8250
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.212090]
[ttyS2] subsystems: tty, platform
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.212701]
[ttyS2] drivers: serial8250
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.213141]
[ttyS2] ID_VENDOR_ID: 0x0000
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.213519]
[ttyS2] ID_MODEL_ID: 0x0000
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.213913]
[ttyS2] ID_REVISION: 0x0000
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.214738]
[ttyS2] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.215412]
[base-manager] adding port ttyS2 at sysfs path:
/sys/devices/platform/serial8250/tty/ttyS2
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.218306]
[filter] (tty/ttyS2): port filtered: tty platform driver
Wed Jan 12 19:32:38 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=ttyS0, subsystem=tty,
sysfspath=/sys/devices/platform/1e000000.palmbus/1e000c00.uartlite/tty/ttyS0
Wed Jan 12 19:32:38 2022 user.notice ModemManager: hotplug: add serial interface
ttyUSB2: event processed
Wed Jan 12 19:32:38 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.446908]
[base-manager] kernel event reported:
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.447276]
[base-manager] action: add
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.447464]
[base-manager] subsystem: tty
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.447621]
[base-manager] name: ttyS0
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.447779]
[base-manager] uid: n/a
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.448115]
[ttyS0] preloading contents and properties...
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.448839]
[ttyS0] sysfs path:
/sys/devices/platform/1e000000.palmbus/1e000c00.uartlite/tty/ttyS0
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.454975]
[ttyS0] port contents loaded:
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.455489]
[ttyS0] bus: platform
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.455882]
[ttyS0] device: /sys/devices/platform/1e000000.palmbus/1e000c00.uartlite
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.456305]
[ttyS0] subsystems: tty, platform
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.456735]
[ttyS0] drivers: of_serial
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.457183]
[ttyS0] ID_VENDOR_ID: 0x0000
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.457615]
[ttyS0] ID_MODEL_ID: 0x0000
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.458088]
[ttyS0] ID_REVISION: 0x0000
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.458914]
[ttyS0] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.459723]
[base-manager] adding port ttyS0 at sysfs path:
/sys/devices/platform/1e000000.palmbus/1e000c00.uartlite/tty/ttyS0
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.460399]
[filter] (tty/ttyS0): port filtered: tty platform driver
Wed Jan 12 19:32:38 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=ttyS1, subsystem=tty,
sysfspath=/sys/devices/platform/serial8250/tty/ttyS1
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.548906]
[base-manager] kernel event reported:
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.549246]
[base-manager] action: add
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.549415]
[base-manager] subsystem: tty
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.549567]
[base-manager] name: ttyUSB2
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.549735]
[base-manager] uid: n/a
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.550183]
[ttyUSB2] preloading contents and properties...
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.551358]
[ttyUSB2] sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.2/ttyUSB2/tty/ttyUSB2
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.561156]
[ttyUSB2] port contents loaded:
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.561507]
[ttyUSB2] bus: usb
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.561690]
[ttyUSB2] interface: /sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.2
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.561884]
[ttyUSB2] interface class: ff
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.562057]
[ttyUSB2] interface subclass: 00
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.564845]
[ttyUSB2] interface protocol: 00
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.565579]
[ttyUSB2] interface number: 02
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.566149]
[ttyUSB2] device: /sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.566630]
[ttyUSB2] subsystems: tty, usb-serial, usb
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.567093]
[ttyUSB2] drivers: option1, option, usb
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.567581]
[ttyUSB2] vendor: 2c7c
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.567974]
[ttyUSB2] product: 0512
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.568320]
[ttyUSB2] revision: 0318
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.568702]
[ttyUSB2] manufacturer: Quectel
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.569178]
[ttyUSB2] product: EM12-AW
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.569730]
[ttyUSB2] ID_USB_INTERFACE_NUM: 0x02
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.570233]
[ttyUSB2] ID_MODEL: EM12-AW
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.570730]
[ttyUSB2] ID_VENDOR: Quectel
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.571240]
[ttyUSB2] ID_VENDOR_ID: 0x2c7c
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.571804]
[ttyUSB2] ID_MODEL_ID: 0x0512
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.572616]
[ttyUSB2] ID_REVISION: 0x0318
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.573709]
[ttyUSB2] property added: .MM_USBIFNUM=02
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.575421]
[ttyUSB2] property added: .MM_USBIFNUM=02
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.577564]
[ttyUSB2] property added: ID_MM_PORT_TYPE_AT_PRIMARY=1
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.579108]
[ttyUSB2] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.580584]
[base-manager] adding port ttyUSB2 at sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.2/ttyUSB2/tty/ttyUSB2
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.581807]
[filter] (tty/ttyUSB2) port allowed: device is whitelisted by plugin (vid)
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.582833]
[base-manager] additional port ttyUSB2 in device
/sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.584681]
[plugin-manager] task 0: port grabbed: ttyUSB2
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.586748]
[plugin-manager] task 0,ttyUSB2: new support task for port
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.588005]
[plugin-manager] task 0,ttyUSB2: deferred until min wait time elapsed
Wed Jan 12 19:32:38 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.725312]
[base-manager] kernel event reported:
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.725649]
[base-manager] action: add
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.725815]
[base-manager] subsystem: tty
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.725994]
[base-manager] name: ttyS1
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.726154]
[base-manager] uid: n/a
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.726575]
[ttyS1] preloading contents and properties...
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.727242]
[ttyS1] sysfs path: /sys/devices/platform/serial8250/tty/ttyS1
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.730340]
[ttyS1] port contents loaded:
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.730649]
[ttyS1] bus: platform
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.730823]
[ttyS1] device: /sys/devices/platform/serial8250
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.731013]
[ttyS1] subsystems: tty, platform
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.731210]
[ttyS1] drivers: serial8250
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.731378]
[ttyS1] ID_VENDOR_ID: 0x0000
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.731578]
[ttyS1] ID_MODEL_ID: 0x0000
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.731757]
[ttyS1] ID_REVISION: 0x0000
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.732754]
[ttyS1] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.733660]
[base-manager] adding port ttyS1 at sysfs path:
/sys/devices/platform/serial8250/tty/ttyS1
Wed Jan 12 19:32:38 2022 daemon.debug [2709]: <debug> [1642015958.734343]
[filter] (tty/ttyS1): port filtered: tty platform driver
Wed Jan 12 19:32:38 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=ip6tnl0, subsystem=net, sysfspath=/sys/devices/virtual/net/ip6tnl0
Wed Jan 12 19:32:38 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:38 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=gre0, subsystem=net, sysfspath=/sys/devices/virtual/net/gre0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.053246]
[base-manager] kernel event reported:
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.053573]
[base-manager] action: add
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.053743]
[base-manager] subsystem: net
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.053914]
[base-manager] name: ip6tnl0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.054081]
[base-manager] uid: n/a
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.054481]
[ip6tnl0] preloading contents and properties...
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.055267]
[ip6tnl0] sysfs path: /sys/devices/virtual/net/ip6tnl0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.064645]
[ip6tnl0] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.065449]
[base-manager] adding port ip6tnl0 at sysfs path: /sys/devices/virtual/net/ip6tnl0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.065953]
[filter] (net/ip6tnl0) port filtered: virtual device
Wed Jan 12 19:32:39 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.080577]
[plugin-manager] task 0: min wait time elapsed
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.081326]
[plugin-manager] task 0,ttyUSB2: found '1' plugins to try
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.082185]
[plugin-manager] task 0,ttyUSB2: will try with plugin 'quectel'
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.085805]
[plugin-manager] task 0,ttyUSB2: started
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.087415]
[plugin-manager] task 0,ttyUSB2: checking with plugin 'quectel'
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.095570]
[plugin/quectel] probes required for port ttyUSB2: 'at, qcdm'
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.097326]
[ttyUSB2/probe] no QCDM/QMI/MBIM probing in possible AT port
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.098612]
[ttyUSB2/probe] port is not QCDM-capable
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.099559]
[ttyUSB2/probe] port is not QMI-capable
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.100347]
[ttyUSB2/probe] port is not MBIM-capable
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.101016]
[ttyUSB2/probe] launching port probing: 'at'
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.102437]
[plugin-manager] task 0,ttyUSB1: found '1' plugins to try
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.103208]
[plugin-manager] task 0,ttyUSB1: will try with plugin 'quectel'
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.104058]
[plugin-manager] task 0,ttyUSB1: started
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.104591]
[plugin-manager] task 0,ttyUSB1: checking with plugin 'quectel'
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.105415]
[plugin/quectel] probes required for port ttyUSB1: 'at, qcdm'
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.106244]
[ttyUSB1/probe] GPS port detected
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.107360]
[ttyUSB1/probe] port is not AT-capable
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.107837]
[ttyUSB1/probe] port is not QCDM-capable
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.108266]
[ttyUSB1/probe] port is not QMI-capable
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.108733]
[ttyUSB1/probe] port is not MBIM-capable
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.109210]
[ttyUSB1/probe] port probing finished: no more probings needed
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.115725]
[plugin-manager] task 0,ttyUSB1: found best plugin for port (quectel)
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.116864]
[plugin-manager] task 0,ttyUSB1: finished in '1.529659' seconds
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.117682]
[plugin-manager] task 0,ttyUSB1: found best plugin: quectel
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.118285]
[plugin-manager] task 0,ttyUSB2: got suggested plugin (quectel)
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.119169]
[plugin-manager] task 0: still 1 running probes (1 active): ttyUSB2
Wed Jan 12 19:32:39 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=gretap0, subsystem=net, sysfspath=/sys/devices/virtual/net/gretap0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.384336]
[ttyUSB2/at] opening serial port...
Wed Jan 12 19:32:39 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.397109]
[ttyUSB2/at] setting up baudrate: 57600
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.398685]
[ttyUSB2/at] no flow control explicitly requested for device
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.399694]
[ttyUSB2/at] port attributes not fully set
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.400356]
[ttyUSB2/at] device open count is 1 (open)
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.415252]
[ttyUSB2/at] --> 'AT<CR>'
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.419679]
[base-manager] kernel event reported:
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.420369]
[base-manager] action: add
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.420946]
[base-manager] subsystem: net
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.421681]
[base-manager] name: gre0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.422950]
[base-manager] uid: n/a
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.424142] [gre0]
preloading contents and properties...
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.425754] [gre0]
sysfs path: /sys/devices/virtual/net/gre0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.450873] [gre0]
property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.455746]
[base-manager] adding port gre0 at sysfs path: /sys/devices/virtual/net/gre0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.456674]
[filter] (net/gre0) port filtered: virtual device
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.500795]
[base-manager] kernel event reported:
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.501429]
[base-manager] action: add
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.501915]
[base-manager] subsystem: net
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.502488]
[base-manager] name: gretap0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.504079]
[base-manager] uid: n/a
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.505992]
[gretap0] preloading contents and properties...
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.506961]
[gretap0] sysfs path: /sys/devices/virtual/net/gretap0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.519445]
[gretap0] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.529122]
[base-manager] adding port gretap0 at sysfs path: /sys/devices/virtual/net/gretap0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.532069]
[filter] (net/gretap0) port filtered: virtual device
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.639036]
[ttyUSB2/at] <-- 'AT'
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.647513]
[ttyUSB2/at] <-- '<CR><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.648717]
[ttyUSB2/probe] port is AT-capable
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.649409]
[plugin-manager] task 0,ttyUSB2: found best plugin for port (quectel)
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.649875]
[plugin-manager] task 0,ttyUSB2: finished in '1.063136' seconds
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.650622]
[plugin-manager] task 0,ttyUSB2: best plugin matches device reported one: quectel
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.651194]
[plugin-manager] task 0: no more ports to probe
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.651858]
[plugin-manager] task 0: all port probings completed, but not reached min
probing time yet
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.653372]
[ttyUSB2/at] device open count is 0 (close)
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.661080]
[ttyUSB2/at] closing serial port...
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.663964]
[ttyUSB2/at] serial port closed
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.665024]
[ttyUSB2/at] forced to close port
Wed Jan 12 19:32:39 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=erspan0, subsystem=net, sysfspath=/sys/devices/virtual/net/erspan0
Wed Jan 12 19:32:39 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:39 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=ip6gre0, subsystem=net, sysfspath=/sys/devices/virtual/net/ip6gre0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.949613]
[base-manager] kernel event reported:
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.949934]
[base-manager] action: add
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.950104]
[base-manager] subsystem: net
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.950259]
[base-manager] name: erspan0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.950421]
[base-manager] uid: n/a
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.950788]
[erspan0] preloading contents and properties...
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.956517]
[erspan0] sysfs path: /sys/devices/virtual/net/erspan0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.974766]
[erspan0] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.975796]
[base-manager] adding port erspan0 at sysfs path: /sys/devices/virtual/net/erspan0
Wed Jan 12 19:32:39 2022 daemon.debug [2709]: <debug> [1642015959.992709]
[filter] (net/erspan0) port filtered: virtual device
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.082521]
[plugin-manager] task 0: min probing time elapsed
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.082871]
[plugin-manager] task 0: no more ports to probe
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.083047]
[plugin-manager] task 0: all port probings completed, but not reached extra
probing time yet
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.092428]
[plugin-manager] task 0: extra probing time elapsed
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.092728]
[plugin-manager] task 0: no more ports to probe
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.092911]
[plugin-manager] task 0: finished in '2.526089' seconds
Wed Jan 12 19:32:40 2022 daemon.info [2709]: <info> [1642015960.093395] [device
/sys/devices/platform/1e1c0000.xhci/usb2/2-1] creating modem with plugin
'quectel' and '2' ports
Wed Jan 12 19:32:40 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:40 2022 user.notice ModemManager: hotplug: add serial interface
ttyUSB3: event processed
Wed Jan 12 19:32:40 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
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[1587]: exiting on receipt of SIGTERM
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: started, version 2.86
cachesize 150
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: DNS service limited to local
subnets
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: compile time options: IPv6
GNU-getopt no-DBus UBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack
no-ipset no-auth no-cryptohash no-DNSSEC no-ID loop-detect inotify dumpfile
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: UBus support enabled:
connected to system bus
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq-dhcp[4200]: DHCP, IP range
192.168.113.100 -- 192.168.113.249, lease time 12h
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: using only locally-known
addresses for test
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: using only locally-known
addresses for onion
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: using only locally-known
addresses for localhost
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: using only locally-known
addresses for local
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: using only locally-known
addresses for invalid
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: using only locally-known
addresses for bind
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: using only locally-known
addresses for lan
Wed Jan 12 19:32:40 2022 daemon.warn dnsmasq[4200]: no servers found in
/tmp/resolv.conf.d/resolv.conf.auto, will retry
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: read /etc/hosts - 4 addresses
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: read
/tmp/hosts/dhcp.cfg01411c - 1 addresses
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq-dhcp[4200]: read /etc/ethers - 0
addresses
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: read /etc/hosts - 4 addresses
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq[4200]: read
/tmp/hosts/dhcp.cfg01411c - 1 addresses
Wed Jan 12 19:32:40 2022 daemon.info dnsmasq-dhcp[4200]: read /etc/ethers - 0
addresses
Wed Jan 12 19:32:40 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
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.708708]
[modem0/ttyUSB2/at] AT port flagged as primary
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.716479]
[modem0] port 'tty/ttyUSB2' grabbed
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.718253]
[modem0] port 'tty/ttyUSB1' grabbed
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.725684]
[modem0] tty/ttyUSB2 at (primary)
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.726381]
[modem0] tty/ttyUSB2 at (data primary)
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.726963]
[modem0] tty/ttyUSB1 gps (nmea)
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.767830]
[modem0/ttyUSB2/at] opening serial port...
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.769922]
[modem0/ttyUSB2/at] setting up baudrate: 57600
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.770687]
[modem0/ttyUSB2/at] no flow control explicitly requested for device
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.771421]
[modem0/ttyUSB2/at] port attributes not fully set
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.772383]
[modem0/ttyUSB2/at] device open count is 1 (open)
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.773154]
[modem0/ttyUSB2/at] running init sequence...
Wed Jan 12 19:32:40 2022 daemon.info [2709]: <info> [1642015960.774657]
[base-manager] modem for device '/sys/devices/platform/1e1c0000.xhci/usb2/2-1'
successfully created
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.931273]
[modem0] loading current capabilities...
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.931978]
[modem0/ttyUSB2/at] device open count is 2 (open)
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.947469]
[modem0/ttyUSB2/at] --> 'ATE0<CR>'
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.985808]
[base-manager] kernel event reported:
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.986213]
[base-manager] action: add
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.986384]
[base-manager] subsystem: tty
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.986561]
[base-manager] name: ttyUSB3
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.986749]
[base-manager] uid: n/a
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.987151]
[ttyUSB3] preloading contents and properties...
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.987978]
[ttyUSB3] sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.3/ttyUSB3/tty/ttyUSB3
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.996230]
[ttyUSB3] port contents loaded:
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.996669]
[ttyUSB3] bus: usb
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.996834]
[ttyUSB3] interface: /sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.3
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.997007]
[ttyUSB3] interface class: ff
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.997227]
[ttyUSB3] interface subclass: 00
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.997398]
[ttyUSB3] interface protocol: 00
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.997590]
[ttyUSB3] interface number: 03
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.997805]
[ttyUSB3] device: /sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:40 2022 daemon.debug [2709]: <debug> [1642015960.998028]
[ttyUSB3] subsystems: tty, usb-serial, usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015960.998203]
[ttyUSB3] drivers: option1, option, usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015960.998393]
[ttyUSB3] vendor: 2c7c
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015960.998538]
[ttyUSB3] product: 0512
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015960.998685]
[ttyUSB3] revision: 0318
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015960.998827]
[ttyUSB3] manufacturer: Quectel
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015960.998989]
[ttyUSB3] product: EM12-AW
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015960.999142]
[ttyUSB3] ID_USB_INTERFACE_NUM: 0x03
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015960.999344]
[ttyUSB3] ID_MODEL: EM12-AW
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015960.999513]
[ttyUSB3] ID_VENDOR: Quectel
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015960.999688]
[ttyUSB3] ID_VENDOR_ID: 0x2c7c
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015960.999868]
[ttyUSB3] ID_MODEL_ID: 0x0512
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.000082]
[ttyUSB3] ID_REVISION: 0x0318
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.006477]
[ttyUSB3] property added: .MM_USBIFNUM=03
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.008007]
[ttyUSB3] property added: .MM_USBIFNUM=03
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.008697]
[ttyUSB3] property added: ID_MM_PORT_TYPE_AT_SECONDARY=1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.009182]
[ttyUSB3] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.009545]
[base-manager] adding port ttyUSB3 at sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.3/ttyUSB3/tty/ttyUSB3
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.009873]
[filter] (tty/ttyUSB3) port allowed: device is whitelisted by plugin (vid)
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.010150]
[base-manager] additional port ttyUSB3 in device
/sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.015148]
[base-manager] kernel event reported:
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.015552]
[base-manager] action: add
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.015715]
[base-manager] subsystem: net
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.015886]
[base-manager] name: ip6gre0
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.016070]
[base-manager] uid: n/a
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.016485]
[ip6gre0] preloading contents and properties...
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.017196]
[ip6gre0] sysfs path: /sys/devices/virtual/net/ip6gre0
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.027154]
[ip6gre0] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.027683]
[base-manager] adding port ip6gre0 at sysfs path: /sys/devices/virtual/net/ip6gre0
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.028117]
[filter] (net/ip6gre0) port filtered: virtual device
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.030655]
[base-manager] kernel event reported:
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.030978]
[base-manager] action: add
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.031141]
[base-manager] subsystem: net
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.031315]
[base-manager] name: wwan0
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.031496]
[base-manager] uid: n/a
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.031872]
[wwan0] preloading contents and properties...
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.032707]
[wwan0] sysfs path: /sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.4/net/wwan0
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.038213]
[wwan0] port contents loaded:
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.038550]
[wwan0] bus: usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.038704]
[wwan0] interface: /sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.4
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.038899]
[wwan0] interface class: ff
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.039080]
[wwan0] interface subclass: ff
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.039267]
[wwan0] interface protocol: ff
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.039450]
[wwan0] interface number: 04
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.039629]
[wwan0] interface description: RmNet
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.039816]
[wwan0] device: /sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.040017]
[wwan0] subsystems: net, usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.040207]
[wwan0] drivers: qmi_wwan, usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.040395]
[wwan0] vendor: 2c7c
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.040571]
[wwan0] product: 0512
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.040727]
[wwan0] revision: 0318
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.040886]
[wwan0] manufacturer: Quectel
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.041040]
[wwan0] product: EM12-AW
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.041201]
[wwan0] ID_USB_INTERFACE_NUM: 0x04
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.041398]
[wwan0] ID_MODEL: EM12-AW
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.041564]
[wwan0] ID_VENDOR: Quectel
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.041742]
[wwan0] ID_VENDOR_ID: 0x2c7c
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.041927]
[wwan0] ID_MODEL_ID: 0x0512
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.042108]
[wwan0] ID_REVISION: 0x0318
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.044203]
[wwan0] property added: .MM_USBIFNUM=04
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.048488]
[wwan0] property added: .MM_USBIFNUM=04
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.049132]
[wwan0] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.049450]
[base-manager] adding port wwan0 at sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.4/net/wwan0
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.049775]
[filter] (net/wwan0) port allowed: device is whitelisted by plugin (vid)
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.049996]
[base-manager] additional port wwan0 in device
/sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:41 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
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.097060]
[base-manager] kernel event reported:
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.097440]
[base-manager] action: add
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.097695]
[base-manager] subsystem: usbmisc
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.097888]
[base-manager] name: cdc-wdm0
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.098165]
[base-manager] uid: n/a
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.098590]
[cdc-wdm0] preloading contents and properties...
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.099482]
[cdc-wdm0] sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.4/usbmisc/cdc-wdm0
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.107770]
[cdc-wdm0] port contents loaded:
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.108098]
[cdc-wdm0] bus: usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.108279]
[cdc-wdm0] interface: /sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.4
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.108458]
[cdc-wdm0] interface class: ff
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.108648]
[cdc-wdm0] interface subclass: ff
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.108836]
[cdc-wdm0] interface protocol: ff
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.109010]
[cdc-wdm0] interface number: 04
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.109193]
[cdc-wdm0] interface description: RmNet
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.109359]
[cdc-wdm0] device: /sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.109555]
[cdc-wdm0] subsystems: usbmisc, usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.109765]
[cdc-wdm0] drivers: qmi_wwan, usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.109957]
[cdc-wdm0] vendor: 2c7c
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.110140]
[cdc-wdm0] product: 0512
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.110309]
[cdc-wdm0] revision: 0318
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.110483]
[cdc-wdm0] manufacturer: Quectel
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.110669]
[cdc-wdm0] product: EM12-AW
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.110854]
[cdc-wdm0] ID_USB_INTERFACE_NUM: 0x04
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.111074]
[cdc-wdm0] ID_MODEL: EM12-AW
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.111271]
[cdc-wdm0] ID_VENDOR: Quectel
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.111502]
[cdc-wdm0] ID_VENDOR_ID: 0x2c7c
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.115522]
[cdc-wdm0] ID_MODEL_ID: 0x0512
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.115994]
[cdc-wdm0] ID_REVISION: 0x0318
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.117156]
[cdc-wdm0] property added: .MM_USBIFNUM=04
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.118998]
[cdc-wdm0] property added: .MM_USBIFNUM=04
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.120139]
[cdc-wdm0] pattern '^cdc-wdm.*$' matched: 'cdc-wdm0'
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.120553]
[cdc-wdm0] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.120864]
[base-manager] adding port cdc-wdm0 at sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.4/usbmisc/cdc-wdm0
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.121270]
[filter] (usbmisc/cdc-wdm0) port allowed: device is whitelisted by plugin (vid)
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.121626]
[base-manager] additional port cdc-wdm0 in device
/sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.293054]
[base-manager] kernel event reported:
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.293353]
[base-manager] action: add
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.293559]
[base-manager] subsystem: tty
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.293752]
[base-manager] name: ttyUSB0
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.293914]
[base-manager] uid: n/a
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.294276]
[ttyUSB0] preloading contents and properties...
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.295147]
[ttyUSB0] sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.0/ttyUSB0/tty/ttyUSB0
Wed Jan 12 19:32:41 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
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.303725]
[ttyUSB0] port contents loaded:
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.303970]
[ttyUSB0] bus: usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.304151]
[ttyUSB0] interface: /sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.0
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.304343]
[ttyUSB0] interface class: ff
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.304584]
[ttyUSB0] interface subclass: ff
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.304867]
[ttyUSB0] interface protocol: ff
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.305090]
[ttyUSB0] interface number: 00
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.305328]
[ttyUSB0] device: /sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.305545]
[ttyUSB0] subsystems: tty, usb-serial, usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.305785]
[ttyUSB0] drivers: option1, option, usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.305994]
[ttyUSB0] vendor: 2c7c
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.306212]
[ttyUSB0] product: 0512
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.306446]
[ttyUSB0] revision: 0318
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.306673]
[ttyUSB0] manufacturer: Quectel
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.306901]
[ttyUSB0] product: EM12-AW
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.307106]
[ttyUSB0] ID_USB_INTERFACE_NUM: 0x00
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.307330]
[ttyUSB0] ID_MODEL: EM12-AW
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.307563]
[ttyUSB0] ID_VENDOR: Quectel
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.307773]
[ttyUSB0] ID_VENDOR_ID: 0x2c7c
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.308006]
[ttyUSB0] ID_MODEL_ID: 0x0512
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.308234]
[ttyUSB0] ID_REVISION: 0x0318
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.309385]
[ttyUSB0] property added: .MM_USBIFNUM=00
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.311571]
[ttyUSB0] property added: .MM_USBIFNUM=00
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.312169]
[ttyUSB0] property added: ID_MM_PORT_TYPE_QCDM=1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.313236]
[ttyUSB0] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.313844]
[base-manager] adding port ttyUSB0 at sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.0/ttyUSB0/tty/ttyUSB0
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.314309]
[filter] (tty/ttyUSB0) port allowed: device is whitelisted by plugin (vid)
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.314655]
[base-manager] additional port ttyUSB0 in device
/sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.479950]
[base-manager] kernel event reported:
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.480243]
[base-manager] action: add
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.480406]
[base-manager] subsystem: tty
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.480557]
[base-manager] name: ttyUSB1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.480735]
[base-manager] uid: n/a
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.481104]
[ttyUSB1] preloading contents and properties...
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.481865]
[ttyUSB1] sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.1/ttyUSB1/tty/ttyUSB1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.490793]
[ttyUSB1] port contents loaded:
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.494737]
[ttyUSB1] bus: usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.495929]
[ttyUSB1] interface: /sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.499114]
[ttyUSB1] interface class: ff
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.499815]
[ttyUSB1] interface subclass: 00
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.500285]
[ttyUSB1] interface protocol: 00
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.500912]
[ttyUSB1] interface number: 01
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.501516]
[ttyUSB1] device: /sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.501979]
[ttyUSB1] subsystems: tty, usb-serial, usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.502758]
[ttyUSB1] drivers: option1, option, usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.503294]
[ttyUSB1] vendor: 2c7c
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.503715]
[ttyUSB1] product: 0512
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.505398]
[ttyUSB1] revision: 0318
Wed Jan 12 19:32:41 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
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.506052]
[ttyUSB1] manufacturer: Quectel
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.508148]
[ttyUSB1] product: EM12-AW
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.508899]
[ttyUSB1] ID_USB_INTERFACE_NUM: 0x01
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.509579]
[ttyUSB1] ID_MODEL: EM12-AW
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.510219]
[ttyUSB1] ID_VENDOR: Quectel
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.510697]
[ttyUSB1] ID_VENDOR_ID: 0x2c7c
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.511195]
[ttyUSB1] ID_MODEL_ID: 0x0512
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.511568]
[ttyUSB1] ID_REVISION: 0x0318
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.513523]
[ttyUSB1] property added: .MM_USBIFNUM=01
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.517317]
[ttyUSB1] property added: .MM_USBIFNUM=01
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.518568]
[ttyUSB1] property added: ID_MM_PORT_TYPE_GPS=1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.519657]
[ttyUSB1] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.520460]
[base-manager] adding port ttyUSB1 at sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.1/ttyUSB1/tty/ttyUSB1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.521249]
[filter] (tty/ttyUSB1) port allowed: device is whitelisted by plugin (vid)
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.522076]
[base-manager] port ttyUSB1 already added
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.740969]
[base-manager] kernel event reported:
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.741365]
[base-manager] action: add
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.741595]
[base-manager] subsystem: tty
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.741842]
[base-manager] name: ttyUSB2
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.742064]
[base-manager] uid: n/a
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.742682]
[ttyUSB2] preloading contents and properties...
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.744049]
[ttyUSB2] sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.2/ttyUSB2/tty/ttyUSB2
Wed Jan 12 19:32:41 2022 user.notice ModemManager: hotplug: cached event found:
action=add, name=ttyUSB3, subsystem=tty,
sysfspath=/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.3/ttyUSB3/tty/ttyUSB3
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.754865]
[ttyUSB2] port contents loaded:
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.755288]
[ttyUSB2] bus: usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.755646]
[ttyUSB2] interface: /sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.2
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.756847]
[ttyUSB2] interface class: ff
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.757120]
[ttyUSB2] interface subclass: 00
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.757304]
[ttyUSB2] interface protocol: 00
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.757541]
[ttyUSB2] interface number: 02
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.757765]
[ttyUSB2] device: /sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.758053]
[ttyUSB2] subsystems: tty, usb-serial, usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.758363]
[ttyUSB2] drivers: option1, option, usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.758675]
[ttyUSB2] vendor: 2c7c
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.758913]
[ttyUSB2] product: 0512
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.759081]
[ttyUSB2] revision: 0318
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.759280]
[ttyUSB2] manufacturer: Quectel
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.759501]
[ttyUSB2] product: EM12-AW
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.759703]
[ttyUSB2] ID_USB_INTERFACE_NUM: 0x02
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.759981]
[ttyUSB2] ID_MODEL: EM12-AW
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.760294]
[ttyUSB2] ID_VENDOR: Quectel
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.760637]
[ttyUSB2] ID_VENDOR_ID: 0x2c7c
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.760922]
[ttyUSB2] ID_MODEL_ID: 0x0512
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.761149]
[ttyUSB2] ID_REVISION: 0x0318
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.762045]
[ttyUSB2] property added: .MM_USBIFNUM=02
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.763750]
[ttyUSB2] property added: .MM_USBIFNUM=02
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.764437]
[ttyUSB2] property added: ID_MM_PORT_TYPE_AT_PRIMARY=1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.765097]
[ttyUSB2] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.765567]
[base-manager] adding port ttyUSB2 at sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.2/ttyUSB2/tty/ttyUSB2
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.766015]
[filter] (tty/ttyUSB2) port allowed: device is whitelisted by plugin (vid)
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.766369]
[base-manager] port ttyUSB2 already added
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.922764]
[base-manager] kernel event reported:
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.923143]
[base-manager] action: add
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.923339]
[base-manager] subsystem: tty
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.923535]
[base-manager] name: ttyUSB3
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.923718]
[base-manager] uid: n/a
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.924179]
[ttyUSB3] preloading contents and properties...
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.925183]
[ttyUSB3] sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.3/ttyUSB3/tty/ttyUSB3
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.931757]
[ttyUSB3] port contents loaded:
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.932146]
[ttyUSB3] bus: usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.932731]
[ttyUSB3] interface: /sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.3
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.933011]
[ttyUSB3] interface class: ff
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.933227]
[ttyUSB3] interface subclass: 00
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.933433]
[ttyUSB3] interface protocol: 00
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.933721]
[ttyUSB3] interface number: 03
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.934023]
[ttyUSB3] device: /sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.934351]
[ttyUSB3] subsystems: tty, usb-serial, usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.934612]
[ttyUSB3] drivers: option1, option, usb
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.934852]
[ttyUSB3] vendor: 2c7c
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.935113]
[ttyUSB3] product: 0512
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.935416]
[ttyUSB3] revision: 0318
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.935633]
[ttyUSB3] manufacturer: Quectel
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.935897]
[ttyUSB3] product: EM12-AW
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.936172]
[ttyUSB3] ID_USB_INTERFACE_NUM: 0x03
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.936513]
[ttyUSB3] ID_MODEL: EM12-AW
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.936849]
[ttyUSB3] ID_VENDOR: Quectel
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.937113]
[ttyUSB3] ID_VENDOR_ID: 0x2c7c
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.937394]
[ttyUSB3] ID_MODEL_ID: 0x0512
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.937644]
[ttyUSB3] ID_REVISION: 0x0318
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.938461]
[ttyUSB3] property added: .MM_USBIFNUM=03
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.940210]
[ttyUSB3] property added: .MM_USBIFNUM=03
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.941028]
[ttyUSB3] property added: ID_MM_PORT_TYPE_AT_SECONDARY=1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.941595]
[ttyUSB3] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.942111]
[base-manager] adding port ttyUSB3 at sysfs path:
/sys/devices/platform/1e1c0000.xhci/usb2/2-1/2-1:1.3/ttyUSB3/tty/ttyUSB3
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.942696]
[filter] (tty/ttyUSB3) port allowed: device is whitelisted by plugin (vid)
Wed Jan 12 19:32:41 2022 daemon.debug [2709]: <debug> [1642015961.943017]
[base-manager] port ttyUSB3 already added
Wed Jan 12 19:32:42 2022 user.notice ModemManager: hotplug: add network
interface br-lan: event processed
Wed Jan 12 19:32:42 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.338165]
[base-manager] kernel event reported:
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.338568]
[base-manager] action: add
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.338781]
[base-manager] subsystem: net
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.339046]
[base-manager] name: br-lan
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.339260]
[base-manager] uid: n/a
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.339787]
[br-lan] preloading contents and properties...
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.340605]
[br-lan] sysfs path: /sys/devices/virtual/net/br-lan
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.349688]
[eth0.1] preloading contents and properties...
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.350267]
[eth0.1] sysfs path: /sys/devices/virtual/net/eth0.1
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.357578] [eth0]
preloading contents and properties...
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.358382] [eth0]
sysfs path: /sys/devices/platform/1e100000.ethernet/net/eth0
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.362664] [eth0]
port contents loaded:
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.362979] [eth0]
bus: platform
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.363141] [eth0]
device: /sys/devices/platform/1e100000.ethernet
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.363324] [eth0]
subsystems: net, platform
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.363510] [eth0]
drivers: mtk_soc_eth
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.363700] [eth0]
ID_VENDOR_ID: 0x0000
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.363934] [eth0]
ID_MODEL_ID: 0x0000
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.364158] [eth0]
ID_REVISION: 0x0000
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.364769] [eth0]
property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.365196]
[eth0.1] setting up lower device: net/eth0
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.366609]
[eth0.1] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.367121]
[br-lan] setting up lower device: net/eth0.1
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.368432]
[br-lan] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:42 2022 daemon.info procd: - init complete -
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.375394]
[base-manager] adding port br-lan at sysfs path: /sys/devices/virtual/net/br-lan
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.375978]
[filter] (net/br-lan) port allowed: net device
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.376449]
[base-manager] port br-lan is first in device
/sys/devices/platform/1e100000.ethernet
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.377260]
[plugin-manager] task 1: new support task for device:
/sys/devices/platform/1e100000.ethernet
Wed Jan 12 19:32:42 2022 user.notice ModemManager: hotplug: add network
interface eth0.1: event processed
Wed Jan 12 19:32:42 2022 user.notice ModemManager: hotplug: error: parent device
sysfspath not found
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.821002]
[base-manager] kernel event reported:
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.821206]
[base-manager] action: add
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.821310]
[base-manager] subsystem: net
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.821411]
[base-manager] name: eth0.1
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.821514]
[base-manager] uid: n/a
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.821726]
[eth0.1] preloading contents and properties...
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.822172]
[eth0.1] sysfs path: /sys/devices/virtual/net/eth0.1
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.825980] [eth0]
preloading contents and properties...
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.826321] [eth0]
sysfs path: /sys/devices/platform/1e100000.ethernet/net/eth0
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.827857] [eth0]
port contents loaded:
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.827970] [eth0]
bus: platform
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.828071] [eth0]
device: /sys/devices/platform/1e100000.ethernet
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.828185] [eth0]
subsystems: net, platform
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.828297] [eth0]
drivers: mtk_soc_eth
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.828408] [eth0]
ID_VENDOR_ID: 0x0000
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.828534] [eth0]
ID_MODEL_ID: 0x0000
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.828651] [eth0]
ID_REVISION: 0x0000
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.829022] [eth0]
property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.829241]
[eth0.1] setting up lower device: net/eth0
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.829760]
[eth0.1] property added: ID_MM_CANDIDATE=1
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.829972]
[base-manager] adding port eth0.1 at sysfs path: /sys/devices/virtual/net/eth0.1
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.830140]
[filter] (net/eth0.1) port allowed: net device
Wed Jan 12 19:32:42 2022 daemon.debug [2709]: <debug> [1642015962.830299]
[base-manager] additional port eth0.1 in device
/sys/devices/platform/1e100000.ethernet
Wed Jan 12 19:32:43 2022 daemon.debug [2709]: <debug> [1642015963.882315]
[plugin-manager] task 1: min wait time elapsed
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.502685]
[modem0/ttyUSB2/at] --> 'ATV1<CR>'
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.544465]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.545060]
[modem0/ttyUSB2/at] --> 'AT+CMEE=1<CR>'
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.634394]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.634918]
[modem0/ttyUSB2/at] --> 'ATX4<CR>'
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.674308]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.674804]
[modem0/ttyUSB2/at] --> 'AT&C1<CR>'
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.724329]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.724826]
[modem0/ttyUSB2/at] --> 'AT+GCAP<CR>'
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.794323]
[modem0/ttyUSB2/at] <-- '<CR><LF>+GCAP: +CGSM<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.796614]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.796921]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.797206]
[modem0/ttyUSB2/at] --> 'AT+WS46=?<CR>'
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.882271]
[plugin-manager] task 1: min probing time elapsed
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.882416]
[plugin-manager] task 1: no more ports to probe
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.882533]
[plugin-manager] task 1: finished in '2.505304' seconds
Wed Jan 12 19:32:44 2022 daemon.info [2709]: <info> [1642015964.882776]
[base-manager] couldn't check support for device
'/sys/devices/platform/1e100000.ethernet': not supported by any plugin
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.885276]
[modem0/ttyUSB2/at] <-- '<CR><LF>+WS46: (12,22,25,28,29)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.893038]
[modem0] setting EPS network as supported
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.893299]
[modem0] setting CDMA1x/EVDO networks as unsupported
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.893917]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.894222]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.894527]
[modem0/ttyUSB2/at] --> 'AT+CSCS=?<CR>'
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.984387]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CSCS:
("IRA","GSM","UCS2")<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.991949]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.992394]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:44 2022 daemon.debug [2709]: <debug> [1642015964.992710]
[modem0/ttyUSB2/at] --> 'AT+CSCS="UCS2"<CR>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.134429]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.134952]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.135217]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.135466]
[modem0/ttyUSB2/at] --> 'AT+CSCS?<CR>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.214350]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CSCS: "UCS2"<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.214892]
[modem0] allowed up to 1 active bearers
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.216970]
[modem0] loading manufacturer...
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.217173]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.217454]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.217740]
[modem0/ttyUSB2/at] --> 'AT+CGMI<CR>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.285714]
[modem0/ttyUSB2/at] <-- '<CR><LF>Quectel<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.286256]
[modem0] loaded manufacturer: Quectel
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.286515]
[modem0] loading model...
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.286684]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.286927]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.287193]
[modem0/ttyUSB2/at] --> 'AT+CGMM<CR>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.354443]
[modem0/ttyUSB2/at] <-- '<CR><LF>EM12<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.354919]
[modem0] loaded model: EM12
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.355167]
[modem0] loading revision...
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.355335]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.355576]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.355842]
[modem0/ttyUSB2/at] --> 'AT+CGMR<CR>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.424351]
[modem0/ttyUSB2/at] <-- '<CR><LF>EM12AWPAR01A07M4G<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.424849]
[modem0] loaded revision: EM12AWPAR01A07M4G
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.425111]
[modem0] loading equipment identifier...
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.425302]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.425540]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.425804]
[modem0/ttyUSB2/at] --> 'AT+CGSN<CR>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.494963]
[modem0/ttyUSB2/at] <-- '<CR><LF>001119000013505<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.499531]
[modem0] loaded equipment identifier: 001119000013505
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.499858]
[modem0] loading device identifier...
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.500037]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.500297]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.500593]
[modem0/ttyUSB2/at] --> 'ATI<CR>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.524406]
[modem0/ttyUSB2/at] <-- '<CR><LF>Quectel<CR><LF>EM12<CR><LF>Revision:
EM12AWPAR01A07M4G<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.526787]
[modem0] device identifier built:
00002c7c00000512QuectelEM12Revision:EM12AWPAR01A07M4G001119000013505EM12AWPAR01A07M4GEM12Quectel
-> 47ae9aa06e2943b2e33a5b9c180ec78d78491598
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.526960]
[modem0] loaded device identifier: 47ae9aa06e2943b2e33a5b9c180ec78d78491598
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.527263]
[modem0] loading supported modes...
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.527521]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.527786]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.528071]
[modem0/ttyUSB2/at] --> 'AT*CNTI=2<CR>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.614457]
[modem0/ttyUSB2/at] <-- '<CR><LF>*CNTI: 2, GSM, GPRS, EDGE, UMTS, HSDPA,
HSUPA<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.614986]
[modem0] device allows (3GPP) 2G networks
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.615101]
[modem0] device allows (3GPP) 3G networks
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.615284]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.615528]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.617265]
[modem0] device allows (3GPP) mode combination: 2g
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.617414]
[modem0] device allows (3GPP) mode combination: 3g
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.617521]
[modem0] device allows (3GPP) mode combination: 4g
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.618832]
[modem0] device allows (3GPP) mode combination: 2g, 3g
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.618997]
[modem0] device allows (3GPP) mode combination: 2g, 3g, 4g
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.619720]
[modem0] loading supported IP families...
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.619966]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.620239]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.620517]
[modem0/ttyUSB2/at] --> 'AT+CGDCONT=?<CR>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.734479]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CGDCONT:
(1-42),"IP",,,(0-3),(0-4),(0-1),(0-1)<CR><LF>+CGDCONT:
(1-42),"PPP",,,(0-3),(0-4),(0-1),(0-1)<CR><LF>+CGDCONT:
(1-42),"IPV6",,,(0-3),(0-4),(0-1),(0-1)<CR><LF>+CGDCONT:
(1-42),"IPV4V6",,,(0-3),(0-4),(0-1),(0-1)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.740264]
[modem0] unhandled PDP type in CGDCONT=? reply: 'PPP'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.743022]
[modem0] loading power state...
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.743244]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.743536]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.743837]
[modem0/ttyUSB2/at] --> 'AT+CFUN?<CR>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.824391]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CFUN: 1<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.827270]
[modem0] (quectel) +QUSIM detection set up
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.827539]
[modem0/ttyUSB2/at] device open count is 1 (close)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.827822]
[modem0] SIM hot swap setup succeeded
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.830384]
[modem0] checking if unlock required...
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.830585]
[modem0/ttyUSB2/at] device open count is 2 (open)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.830926]
[modem0/ttyUSB2/at] --> 'AT+CPIN?<CR>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.904716]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPIN: READY<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.905508]
[modem0] SIM is ready, and no need for the after SIM unlock step...
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.908085]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.908678]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:45 2022 daemon.debug [2709]: <debug> [1642015965.909036]
[modem0/ttyUSB2/at] --> 'AT+CSIM=10,"0020000100"<CR>'
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.136509]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CSIM: 4,"63C3"<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.137473]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.137789]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.138116]
[modem0/ttyUSB2/at] --> 'AT+CSIM=10,"002C000100"<CR>'
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.366610]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CSIM: 4,"63CA"<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.367587]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.367916]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.368245]
[modem0/ttyUSB2/at] --> 'AT+CSIM=10,"0020008100"<CR>'
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.577237]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CSIM: 4,"6B00"<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.578367]
[modem0] couldn't parse retry count value for lock 'sim-pin2': Unknown error
returned '0x6b00'
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.578849]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.579246]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.579631]
[modem0/ttyUSB2/at] --> 'AT+CSIM=10,"002C008100"<CR>'
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.806349]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CSIM: 4,"6B00"<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.807246]
[modem0] couldn't parse retry count value for lock 'sim-puk2': Unknown error
returned '0x6b00'
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.815376]
[modem0/sim0] loading SIM identifier...
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.815764]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.816183]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:46 2022 daemon.debug [2709]: <debug> [1642015966.816539]
[modem0/ttyUSB2/at] --> 'AT+CRSM=176,12258,0,0,10<CR>'
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.054476]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CRSM:
144,0,"98100140030092884575"<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.055408]
[modem0/sim0] loaded SIM identifier: 89011004300029885457
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.055746]
[modem0/sim0] loading IMSI...
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.056015]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.056357]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.056688]
[modem0/ttyUSB2/at] --> 'AT+CIMI<CR>'
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.124399]
[modem0/ttyUSB2/at] <-- '<CR><LF>313100002988545<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.124968]
[modem0/sim0] loaded IMSI: 313100002988545
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.125275]
[modem0/sim0] loading operator ID...
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.125521]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.125845]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.126166]
[modem0/ttyUSB2/at] --> 'AT+CRSM=176,28589,0,0,4<CR>'
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.354425]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CRSM: 144,0,"01000103"<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.355378]
[modem0/sim0] loading operator name...
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.355655]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.355991]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.356315]
[modem0/ttyUSB2/at] --> 'AT+CRSM=176,28486,0,0,17<CR>'
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.594542]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CRSM: 106,130,""<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:47 2022 daemon.warn [2709]: <warn> [1642015967.595457]
[modem0/sim0] couldn't load operator name: Failed to parse CRSM query result
'+CRSM: 106,130,""'
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.595648]
[modem0/sim0] loading emergency numbers...
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.595931]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.596260]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.596587]
[modem0/ttyUSB2/at] --> 'AT+CRSM=176,28599,0,0,15<CR>'
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.834435]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CRSM: 148,8,""<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:47 2022 daemon.warn [2709]: <warn> [1642015967.835243]
[modem0/sim0] couldn't load list of emergency numbers: Failed to parse CRSM
query result '+CRSM: 148,8,""'
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.835487]
[modem0/sim0] selecting user-defined preferred network list...
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.835741]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.836063]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.836384]
[modem0/ttyUSB2/at] --> 'AT+CPLS=0<CR>'
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.924414]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.924903]
[modem0/sim0] setting preferred networks format...
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.925098]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.925341]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:47 2022 daemon.debug [2709]: <debug> [1642015967.925609]
[modem0/ttyUSB2/at] --> 'AT+CPOL=,2<CR>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.024355]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.024789]
[modem0/sim0] loading preferred networks...
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.024975]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.025210]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.025470]
[modem0/ttyUSB2/at] --> 'AT+CPOL?<CR>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.104403]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CME ERROR: 3<CR><LF>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.106864]
[modem0/ttyUSB2/at] operation failure: 3 (Operation not allowed)
Wed Jan 12 19:32:48 2022 daemon.warn [2709]: <warn> [1642015968.107182]
[modem0/sim0] couldn't load list of preferred networks: Operation not allowed
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.110133]
[modem0] loading own numbers...
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.110417]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.110803]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.111154]
[modem0/ttyUSB2/at] --> 'AT+CNUM<CR>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.184592]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CNUM:
"00310038003500380039003100340037003900330038","18589147938",129<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.195413]
[modem0] loading enabled facility locks...
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.195758]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.196160]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.196523]
[modem0/ttyUSB2/at] --> 'AT+CLCK=?<CR>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.284459]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CLCK:
("AB","AC","AG","AI","AO","IR","OI","OX","SC","FD","PN","PU","PP","PC","PF")<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.290471]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.290848]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.291197]
[modem0/ttyUSB2/at] --> 'AT+CLCK="SC",2<CR>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.434576]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CLCK: 0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.435348]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.435674]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.435999]
[modem0/ttyUSB2/at] --> 'AT+CLCK="FD",2<CR>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.574368]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CLCK: 0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.575095]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.575399]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.575725]
[modem0/ttyUSB2/at] --> 'AT+CLCK="PF",2<CR>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.720344]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CLCK: 0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.721112]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.721417]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.721739]
[modem0/ttyUSB2/at] --> 'AT+CLCK="PN",2<CR>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.870465]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CLCK: 0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.871235]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.871537]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:48 2022 daemon.debug [2709]: <debug> [1642015968.871861]
[modem0/ttyUSB2/at] --> 'AT+CLCK="PU",2<CR>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.020123]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CLCK: 0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.020884]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.021207]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.021537]
[modem0/ttyUSB2/at] --> 'AT+CLCK="PP",2<CR>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.170149]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CLCK: 0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.170908]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.171209]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.171531]
[modem0/ttyUSB2/at] --> 'AT+CLCK="PC",2<CR>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.320553]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CLCK: 0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.322552]
[modem0] loading IMEI...
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.322952]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.323512]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.324175]
[modem0] loaded IMEI: 001119000013505
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.324598]
[modem0] loading UE mode of operation for EPS...
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.324879]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.325271]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.325731]
[modem0/ttyUSB2/at] --> 'AT+CEMODE?<CR>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.426502]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CEMODE: 2<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.432026]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.432596]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.434566]
[modem0/ttyUSB2/at] device open count is 1 (close)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.439207]
[modem0/ttyUSB2/at] device open count is 2 (open)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.439708]
[modem0/ttyUSB2/at] --> 'AT+QGPS=?<CR>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.526947]
[modem0/ttyUSB2/at] <-- '<CR><LF>+QGPS:
(1-4),(1-255),(1-3),(100-65535)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.527661]
[modem0] (quectel) GPS management with +QGPS is supported
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.533740]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.534243]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.534621]
[modem0/ttyUSB2/at] --> 'AT+CNMI=?<CR>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.624455]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CNMI:
(0-2),(0-3),(0,2),(0-2),(0,1)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.625207]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.625492]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.625758]
[modem0/ttyUSB2/at] --> 'AT+CPMS=?<CR>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.714409]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPMS:
("ME","MT","SM","SR"),("ME","MT","SM","SR"),("ME","MT","SM","SR")<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.717151]
[modem0] supported storages loaded:
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.717326]
[modem0] mem1 (list/read/delete) storages: 'me, mt, sm, sr'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.717490]
[modem0] mem2 (write/send) storages: 'me, mt, sm, sr'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.717653]
[modem0] mem3 (reception) storages: 'me, mt, sm, sr'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.718198]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.718554]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.718897]
[modem0/ttyUSB2/at] --> 'AT+CPMS?<CR>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.794674]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPMS:
"ME",0,127,"ME",0,127,"ME",0,127<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.795520]
[modem0] current storages initialized:
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.795687]
[modem0] mem1 (list/read/delete) storages: 'me'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.795865]
[modem0] mem2 (write/send) storages: 'me'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.796053]
[modem0] current storages initialized
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.798601]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.799060]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.799416]
[modem0/ttyUSB2/at] --> 'AT+CTZU=?<CR>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.884379]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CTZU: (0,1)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.885136]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.885442]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.885763]
[modem0/ttyUSB2/at] --> 'AT+CTZU=1<CR>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.974512]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.975092]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.975396]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:49 2022 daemon.debug [2709]: <debug> [1642015969.975716]
[modem0/ttyUSB2/at] --> 'AT+CCLK?<CR>'
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.053342]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CCLK:
"22/01/13,14:02:48-20"<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.055159]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.055613]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.055958]
[modem0/ttyUSB2/at] --> 'AT+CESQ=?<CR>'
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.144407]
[modem0/ttyUSB2/at] <-- '<CR><LF>ERROR<CR><LF>'
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.144929]
[modem0/ttyUSB2/at] operation failure: 100 (Unknown error)
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.145185]
[modem0] extended signal support check failed: Unknown error
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.145390]
[modem0] couldn't initialize interface: 'Extended Signal information not supported'
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.147282]
[modem0/ttyUSB2/at] device open count is 1 (close)
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.147690]
[modem0] couldn't initialize interface: 'OMA not supported'
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.151344]
[modem0/ttyUSB2/at] device open count is 2 (open)
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.151904]
[modem0/ttyUSB2/at] --> 'ATH<CR>'
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.184396]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.185025]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.185326]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.185646]
[modem0/ttyUSB2/at] --> 'AT+CLCC=?<CR>'
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.274409]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.275434]
[modem0] periodic call list polling will be used if supported
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.276651]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.277061]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.277404]
[modem0/ttyUSB2/at] --> 'AT+QFASTBOOT=?<CR>'
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.416587]
[modem0/ttyUSB2/at] <-- '<CR><LF>ERROR<CR><LF>'
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.417067]
[modem0/ttyUSB2/at] operation failure: 100 (Unknown error)
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.422589]
[modem0] creating ports context for SIM hot swap
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.422818]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:50 2022 daemon.info [2709]: <info> [1642015970.423728]
[modem0] state changed (unknown -> disabled)
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.424524]
[modem0] modem initialized
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.434467]
[device /sys/devices/platform/1e1c0000.xhci/usb2/2-1] exported modem at path
'/org/freedesktop/ModemManager1/Modem/0'
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.434758]
[device /sys/devices/platform/1e1c0000.xhci/usb2/2-1] plugin: quectel
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.434934]
[device /sys/devices/platform/1e1c0000.xhci/usb2/2-1] vid:pid: 0x2C7C:0x0512
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.435212]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:50 2022 daemon.debug [2709]: <debug> [1642015970.435482]
[modem0/ttyUSB2/at] device open count is 1 (close)
Wed Jan 12 19:32:51 2022 user.notice ModemManager: hotplug: modem exported
successfully at /sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 19:32:51 2022 user.notice ModemManager: hotplug: setting interface
'wwan' as available
Wed Jan 12 19:32:51 2022 daemon.notice netifd: Interface 'wwan' is setting up now
Wed Jan 12 19:32:51 2022 daemon.notice netifd: wwan (4989): modem available at
/org/freedesktop/ModemManager1/Modem/0
Wed Jan 12 19:32:51 2022 daemon.notice netifd: wwan (4989): starting connection
with apn 'firstnet-broadband'...
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.403417]
[modem0] user request to connect modem
Wed Jan 12 19:32:51 2022 daemon.info [2709]: <info> [1642015971.404306]
[modem0] simple connect started...
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.404465]
[modem0] profile ID: unspecified
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.404628]
[modem0] PIN: unspecified
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.404792]
[modem0] operator ID: unspecified
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.404955]
[modem0] allowed roaming: yes
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.405122]
[modem0] APN: firstnet-broadband
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.405286]
[modem0] APN type: unspecified
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.405457]
[modem0] IP family: ipv4v6
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.405622]
[modem0] allowed authentication: unspecified
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.405789]
[modem0] user: unspecified
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.405955]
[modem0] password: unspecified
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.406117]
[modem0] multiplex: unspecified
Wed Jan 12 19:32:51 2022 daemon.info [2709]: <info> [1642015971.406279]
[modem0] simple connect state (3/8): enable
Wed Jan 12 19:32:51 2022 daemon.info [2709]: <info> [1642015971.406773]
[modem0] state changed (disabled -> enabling)
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.408714]
[modem0] skipping initialization: device hotplugged
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.408988]
[modem0/ttyUSB2/at] device open count is 2 (open)
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.409166]
[modem0] flashing primary AT port before enabling...
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.409836]
[modem0] loading power state...
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.410127]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.410599]
[modem0/ttyUSB2/at] --> 'AT+CFUN?<CR>'
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.484450]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CFUN: 1<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.485297]
[modem0] no need to change power state: already 'on'
Wed Jan 12 19:32:51 2022 daemon.info [2709]: <info> [1642015971.485448]
[modem0] power state updated: on
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.485779]
[modem0] checking if SIM was swapped...
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.485997]
[modem0/sim0] loading SIM identifier...
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.486240]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.486611]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.486947]
[modem0/ttyUSB2/at] --> 'AT+CRSM=176,12258,0,0,10<CR>'
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.724614]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CRSM:
144,0,"98100140030092884575"<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.725571]
[modem0/sim0] loaded SIM identifier: 89011004300029885457
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.725865]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.726198]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.726479]
[modem0/ttyUSB2/at] --> 'AT+IFC=?<CR>'
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.804747]
[modem0/ttyUSB2/at] <-- '<CR><LF>+IFC: (0-2),(0-2)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.806004]
[modem0] TE supports no flow control
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.806316]
[modem0] TE supports XON/XOFF flow control
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.806540]
[modem0] TE supports RTS/CTS flow control
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.806819]
[modem0] TA supports no flow control
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.807027]
[modem0] TA supports XON/XOFF flow control
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.807209]
[modem0] TA supports RTS/CTS flow control
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.807526]
[modem0] flow control settings automatically selected: rts-cts
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.807854]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.808285]
[modem0] modem has 3GPP capabilities, enabling the Modem 3GPP interface...
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.808627]
[modem0] checking indicator support...
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.808883]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.809282]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.809681]
[modem0/ttyUSB2/at] --> 'AT+IFC=2,2<CR>'
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.894503]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.895081]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.895395]
[modem0/ttyUSB2/at] --> 'AT+CIND=?<CR>'
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.984863]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CIND:
("battchg",(0-5)),("signal",(0-5)),("service",(0-1)),("call",(0-1)),("roam",(0-1)),("smsfull",(0-1)),("GPRS
coverage",(0-1)),("callsetup",(0-3))<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.986319]
[modem0] signal quality indications via CIND are supported at index '2' (min: 0,
max: 5)
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.986555]
[modem0] roaming indications via CIND are supported at index '5'
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.986700]
[modem0] service indications via CIND are supported at index '3'
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.987040]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.987382]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:51 2022 daemon.debug [2709]: <debug> [1642015971.987812]
[modem0/ttyUSB2/at] --> 'AT+CMER=?<CR>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.074843]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CMER:
(0-3),(0),(0),(0,1),(0,1)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.075820]
[modem0] supported +CMER modes: discard-urcs, discard-urcs-if-link-reserved,
buffer-urcs-if-link-reserved, forward-urcs
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.076041]
[modem0] supported +CMER indication settings: disable, enable-not-caused-by-cind
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.076223]
[modem0] +CMER enable mode: forward-urcs
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.076402]
[modem0] +CMER disable mode: discard-urcs
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.076564]
[modem0] +CMER indication setting: enable-not-caused-by-cind
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.076736]
[modem0] checking packet domain event reporting...
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.077033]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.077345]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.077727]
[modem0/ttyUSB2/at] --> 'AT+CGEREP=?<CR>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.184431]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CGEREP: (0-2),(0,1)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.185119]
[modem0] packet domain event reporting is supported
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.185374]
[modem0] setting 3GPP +CIEV unsolicited events handlers in ttyUSB2
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.185592]
[modem0] setting 3GPP +CGEV unsolicited events handlers in ttyUSB2
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.185870]
[modem0] enabling +CIND event reporting in primary port...
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.186105]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.186441]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.186767]
[modem0/ttyUSB2/at] --> 'AT+CMER=3,0,0,1<CR>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.331834]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.332770]
[modem0] enabling +CGEV event reporting in primary port...
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.333213]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.333629]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.334172]
[modem0/ttyUSB2/at] --> 'AT+CGEREP=2<CR>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.369373]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.424481]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.427106]
[modem0] setting up 3GPP unsolicited registration messages handlers in ttyUSB2
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.427670]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.428180]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.428544]
[modem0/ttyUSB2/at] --> 'AT+QGPSCFG=autogps,1<CR>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.624696]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CME ERROR: 501<CR><LF>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.625278]
[modem0/ttyUSB2/at] operation failure: 501 (GNSS - Invalid parameter)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.626315]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.626756]
[modem0/ttyUSB2/at] --> 'AT+CREG=2<CR>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.714434]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.715205]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.715529]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.715855]
[modem0/ttyUSB2/at] --> 'AT+CGREG=2<CR>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.804716]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.805703]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.806156]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.806600]
[modem0/ttyUSB2/at] --> 'AT+CEREG=2<CR>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.828315]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.884436]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.885098]
[modem0] modem has 3GPP profile management capabilities, enabling the Modem 3GPP
Profile Manager interface...
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.885499]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.885835]
[modem0] modem has 3GPP/USSD capabilities, enabling the Modem 3GPP/USSD interface...
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.886141]
[modem0] setting unsolicited result code handlers in ttyUSB2
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.886585]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.886937]
[modem0/ttyUSB2/at] --> 'AT+QGPS=1<CR>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.981238]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.982626]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:52 2022 daemon.debug [2709]: <debug> [1642015972.983115]
[modem0/ttyUSB2/at] --> 'AT+CUSD=1<CR>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.073362]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.074605]
[modem0] modem has location capabilities, enabling the Location interface...
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.075041]
[modem0] location 'gps-raw' gathering is already disabled...
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.075265]
[modem0] location 'gps-nmea' gathering is already disabled...
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.075459]
[modem0] location 'gps-unmanaged' gathering is already disabled...
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.075658]
[modem0] need to enable the following location sources: '3gpp-lac-ci'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.082429]
[modem0] running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes', 5GS: 'no')
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.082876]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.083522]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.086874]
[modem0] modem has messaging capabilities, enabling the Messaging interface...
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.087971]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.088670]
[modem0/ttyUSB2/at] --> 'AT+CREG?<CR>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.163414]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.164130]
[modem0] 3GPP registration state change ignored as modem isn't enabled
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.164753]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.165034]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.165389]
[modem0/ttyUSB2/at] --> 'AT+CMGF=?<CR>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.253391]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CMGF: (0,1)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.254609]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.255026]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.255580]
[modem0/ttyUSB2/at] --> 'AT+CGREG?<CR>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.343285]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CGREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.344034]
[modem0] 3GPP registration state change ignored as modem isn't enabled
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.344653]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.344932]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.345286]
[modem0/ttyUSB2/at] --> 'AT+CMGF=0<CR>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.423478]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.424122]
[modem0] successfully set preferred SMS mode: 'PDU'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.424846]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.425250]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.426454]
[modem0/ttyUSB2/at] --> 'AT+CEREG?<CR>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.457448]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.493289]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CEREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.493882]
[modem0] 3GPP registration state change ignored as modem isn't enabled
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.494503]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.494860]
[modem0/ttyUSB2/at] --> 'AT+CPMS="ME","MT","MT"<CR>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.717226]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPMS: 0,127,0,127,0,127<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.717899]
[modem0] listing SMS parts in storage 'me'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.718088]
[modem0] locking SMS storages to: mem1 (ME), mem2 (none)...
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.718357]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.718665]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.719004]
[modem0/ttyUSB2/at] --> 'AT+CPIN?<CR>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.793167]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPIN: READY<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.794412]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.794845]
[modem0/ttyUSB2/at] --> 'AT+CPMS="ME"<CR>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.913653]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPMS: 0,127,0,127,0,127<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.914644]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.915135]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.915578]
[modem0/ttyUSB2/at] --> 'AT+CMGL=4<CR>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.993631]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.994544]
[modem0] listing SMS parts in storage 'sm'
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.994792]
[modem0] locking SMS storages to: mem1 (SM), mem2 (none)...
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.995083]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.995445]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.996147]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:53 2022 daemon.debug [2709]: <debug> [1642015973.996541]
[modem0/ttyUSB2/at] --> 'AT+CPMS="SM"<CR>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.115358]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPMS: 0,5,0,127,0,127<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.116097]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.116419]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.116761]
[modem0/ttyUSB2/at] --> 'AT+GSN<CR>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.173228]
[modem0/ttyUSB2/at] <-- '<CR><LF>001119000013505<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.174443]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.174896]
[modem0/ttyUSB2/at] --> 'AT+CMGL=4<CR>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.263495]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.265009]
[modem0] listing SMS parts in storage 'sr'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.265465]
[modem0] locking SMS storages to: mem1 (SR), mem2 (none)...
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.266014]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.266692]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.267323]
[modem0/ttyUSB2/at] --> 'AT+CPMS="SR"<CR>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.375928]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPMS:
0,0,0,127,0,127<CR><LF><CR><LF>OK<CR><LF><CR><LF>+CIEV: 5,1<CR><LF>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.377105]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.377681]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.378196]
[modem0/ttyUSB2/at] --> 'AT+CMGL=4<CR>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.385717]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.443241]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.444218]
[modem0] setting messaging unsolicited events handlers in ttyUSB2
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.444579]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.444957]
[modem0] enabling messaging unsolicited events on primary port ttyUSB2
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.445193]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.445547]
[modem0/ttyUSB2/at] --> 'AT+QCCID<CR>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.523169]
[modem0/ttyUSB2/at] <-- '<CR><LF>+QCCID:
89011004300029885457<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.524572]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.525010]
[modem0/ttyUSB2/at] --> 'AT+CNMI=2,1,2,1,0<CR>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.694529]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.695226]
[modem0] messaging unsolicited events enabled on primary port ttyUSB2
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.695439]
[modem0] modem has time capabilities, enabling the Time interface...
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.695919]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.696269]
[modem0] modem has voice capabilities, enabling the Voice interface...
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.696939]
[modem0] setting voice unsolicited events handlers in ttyUSB2
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.697625]
[modem0] enabling +CLIP calling line reporting in primary port...
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.697968]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.698490]
[modem0/ttyUSB2/at] --> 'AT+CLIP=1<CR>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.728162]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.773251]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.773891]
[modem0] enabling +CRC extended format of incoming call indications in primary
port...
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.774136]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.774410]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.774757]
[modem0/ttyUSB2/at] --> 'AT+CIMI<CR>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.843211]
[modem0/ttyUSB2/at] <-- '<CR><LF>313100002988545<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.844511]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.844963]
[modem0/ttyUSB2/at] --> 'AT+CRC=1<CR>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.923247]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.923904]
[modem0] enabling +CCWA call waiting indications in primary port...
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.924123]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.924386]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:54 2022 daemon.debug [2709]: <debug> [1642015974.924672]
[modem0/ttyUSB2/at] --> 'AT+CCWA=1<CR>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.017730]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:55 2022 daemon.info [2709]: <info> [1642015975.018516]
[modem0] simple connect state (4/8): wait to get fully enabled
Wed Jan 12 19:32:55 2022 daemon.info [2709]: <info> [1642015975.018968]
[modem0] state changed (enabling -> enabled)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.021427]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:55 2022 daemon.info [2709]: <info> [1642015975.022011]
[modem0] simple connect state (5/8): register
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.022651]
[modem0] launching automatic network registration...
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.023061]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.023887]
[modem0] running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes', 5GS: 'no')
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.024378]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.024900]
[modem0/ttyUSB2/at] --> 'AT+COPS=0<CR>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.051729]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.119549]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.120258]
[modem0] running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes', 5GS: 'no')
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.120562]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.120871]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.121234]
[modem0/ttyUSB2/at] --> 'AT+CREG?<CR>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.203208]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:55 2022 daemon.info [2709]: <info> [1642015975.203848]
[modem0] 3GPP registration state changed (unknown -> registering)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.204091]
[modem0] loading Operator Code...
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.204324]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.204622]
[modem0/ttyUSB2/at] device open count is 7 (open)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.205145]
[modem0] access technology changed (unknown -> lte)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.205381]
[modem0] 3GPP tracking area code updated: '000000->005507'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.205526]
[modem0] 3GPP cell id updated: '00000000->0BE722D8'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.205706]
[modem0] 3GPP location updated (MCCMNC: '<none>', location area code: '0000',
tracking area code: '005507', cell ID: '0BE722D8')
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.206240]
[modem0/ttyUSB2/at] device open count is 8 (open)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.206505]
[modem0/ttyUSB2/at] device open count is 7 (close)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.207651]
[modem0/ttyUSB2/at] --> 'AT+CGMR<CR>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.273228]
[modem0/ttyUSB2/at] <-- '<CR><LF>EM12AWPAR01A07M4G<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.274684]
[modem0/ttyUSB2/at] device open count is 6 (close)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.275141]
[modem0/ttyUSB2/at] --> 'AT+CREG?<CR>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.353250]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.354409]
[modem0/ttyUSB2/at] device open count is 7 (open)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.354658]
[modem0/ttyUSB2/at] device open count is 6 (close)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.354966]
[modem0/ttyUSB2/at] --> 'AT+COPS=3,2<CR>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.454477]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.455376]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.455857]
[modem0/ttyUSB2/at] --> 'AT+COPS?<CR>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.479546]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.523190]
[modem0/ttyUSB2/at] <-- '<CR><LF>+COPS: 0,2,"313100",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.524291]
[modem0] couldn't convert operator string '313100' from charset 'UCS2': Invalid
conversion from UCS2 to UTF-8: Couldn't convert from UCS2 to UTF-8 with
translit: Could not open converter from “UCS-2BE” to “UTF-8”
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.524478]
[modem0] operator normalized '313100'->'313100'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.524640]
[modem0] loaded Operator Code: 313100
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.525124]
[modem0] 3GPP location updated (MCCMNC: '313100', location area code: '0000',
tracking area code: '005507', cell ID: '0BE722D8')
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.525295]
[modem0] loading Operator Name...
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.525542]
[modem0/ttyUSB2/at] device open count is 7 (open)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.525864]
[modem0/ttyUSB2/at] device open count is 8 (open)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.526127]
[modem0/ttyUSB2/at] device open count is 7 (close)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.527299]
[modem0/ttyUSB2/at] --> 'AT+CGREG?<CR>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.582978]
[modem0/ttyUSB2/at] <-- '<CR><LF>+QLWURC: "pdp
active","failed","firstnetbroadband"<CR><LF>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.583891]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CGREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.584656]
[modem0] 3GPP location area code updated: '0000->5507'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.584806]
[modem0] 3GPP tracking area code cleared: '005507->000000'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.584985]
[modem0] 3GPP location updated (MCCMNC: '313100', location area code: '5507',
tracking area code: '000000', cell ID: '0BE722D8')
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.585576]
[modem0/ttyUSB2/at] device open count is 8 (open)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.585853]
[modem0/ttyUSB2/at] device open count is 7 (close)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.586285]
[modem0/ttyUSB2/at] --> 'AT+CGREG?<CR>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.673196]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CGREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.674229]
[modem0/ttyUSB2/at] device open count is 8 (open)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.674528]
[modem0/ttyUSB2/at] device open count is 7 (close)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.674875]
[modem0/ttyUSB2/at] --> 'AT+QCFG="band"<CR>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.813364]
[modem0/ttyUSB2/at] <-- '<CR><LF>+QCFG:
"band",0x260,0x2000000003000281a,0x0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.814693]
[modem0/ttyUSB2/at] device open count is 6 (close)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.815132]
[modem0/ttyUSB2/at] --> 'AT+COPS=3,0<CR>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.913196]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.913831]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.914139]
[modem0/ttyUSB2/at] --> 'AT+COPS?<CR>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.984123]
[modem0/ttyUSB2/at] <-- '<CR><LF>+COPS: 0,0,"FirstNet",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.985402]
[modem0] couldn't convert operator string 'FirstNet' from charset 'UCS2': Hex
byte conversion from 'Fi' failed
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.985628]
[modem0] operator normalized 'FirstNet'->'FirstNet'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.985735]
[modem0] loaded Operator Name: FirstNet
Wed Jan 12 19:32:55 2022 daemon.info [2709]: <info> [1642015975.986120]
[modem0] 3GPP registration state changed (registering -> home)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.986243]
[modem0] consolidated registration state: cs 'home', ps 'home', eps 'home', 5gs
'unknown' --> 'home'
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.986665]
[modem0] will start keeping track of state for subsystem '3gpp'
Wed Jan 12 19:32:55 2022 daemon.info [2709]: <info> [1642015975.986842]
[modem0] state changed (enabled -> registered)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.987321]
[modem0] network timezone polling started
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.989257]
[modem0] periodic signal checks enabled
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.989534]
[modem0] periodic signal check refresh requested
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.989744]
[modem0] loading signal quality...
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.989979]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.990277]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 19:32:55 2022 daemon.debug [2709]: <debug> [1642015975.993736]
[modem0/ttyUSB2/at] --> 'AT+CEREG?<CR>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.021554]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.083185]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CEREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.083860]
[modem0] 3GPP tracking area code updated: '000000->005507'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.083988]
[modem0] 3GPP location area code cleared: '5507->0000'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.084105]
[modem0] 3GPP location updated (MCCMNC: '313100', location area code: '0000',
tracking area code: '005507', cell ID: '0BE722D8')
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.084533]
[modem0] initial 3GPP registration checks finished
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.084709]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.085003]
[modem0/ttyUSB2/at] --> 'AT+CEREG?<CR>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.173196]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CEREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.174078]
[modem0] periodic signal check refresh ignored: check already running
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.174206]
[modem0] currently registered in a 3GPP network
Wed Jan 12 19:32:56 2022 daemon.info [2709]: <info> [1642015976.174337]
[modem0] simple connect state (6/8): bearer
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.174450]
[modem0] creating new bearer...
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.174637]
[modem0] creating broadband bearer in broadband modem...
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.190090]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.190575]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 19:32:56 2022 daemon.info [2709]: <info> [1642015976.192279]
[modem0] simple connect state (7/8): connect
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.194355]
[modem0/bearer0] connecting...
Wed Jan 12 19:32:56 2022 daemon.info [2709]: <info> [1642015976.194875]
[modem0] state changed (registered -> connecting)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.197682]
[modem0/bearer0] launching 3GPP connection attempt
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.198172]
[modem0] set profile state (1/8): check format
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.198618]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.199229]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.201255]
[modem0/ttyUSB2/at] --> 'AT+CIND?<CR>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.283219]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CIND: 0,5,1,1,0,1,1,0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.284546]
[modem0] signal quality updated (100)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.284913]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.285987]
[modem0] polling to refresh access technologies is unsupported
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.286144]
[modem0] periodic signal quality and access technology checks scheduled
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.286385]
[modem0/ttyUSB2/at] --> 'AT+QTEMP<CR>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.390804]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.392348]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.392836]
[modem0/ttyUSB2/at] <-- '<CR><LF>+QTEMP:
"xo_therm_buf","23"<CR><LF><CR><LF>+QTEMP:
"mdm_case_therm","23"<CR><LF><CR><LF>+QTEMP:
"pa_therm1","23"<CR><LF><CR><LF>+QTEMP:
"tsens_tz_sensor0","26"<CR><LF><CR><LF>+QTEMP:
"tsens_tz_sensor1","26"<CR><LF><CR><LF>+QTEMP:
"tsens_tz_sensor2","26"<CR><LF><CR><LF>+QTEMP:
"tsens_tz_sensor3","26"<CR><LF><CR><LF>+QTEMP: "tsens_tz_sensor4","26"<CR><LF>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.395241]
[modem0] unhandled PDP type in CGDCONT=? reply: 'PPP'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.395573]
[modem0] +CGDCONT format details for PDP type 'ipv4v6': minimum 1, maximum 42
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.395734]
[modem0] context definition format: minimum 1, maximum 42
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.395839]
[modem0] set profile state (2/8): list before
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.396163]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.396683]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.397031]
[modem0/ttyUSB2/at] --> 'AT+CGDCONT?<CR>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.504654]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CGDCONT:
1,"IPV4V6","firstnet-broadband","0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,0<CR><LF>+CGDCONT:
16,"IP","firstnetbroadband","0.0.0.0",0,0,0,0<CR><LF>+CGDCONT:
2,"IPV4V6","ims","0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,0<CR><LF>+CGDCONT:
3,"IPV4V6","SOS","0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,1<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.507494]
[modem0] set profile state (3/8): select profile (best)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.507830]
[modem0] found exact context at profile 1
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.507988]
[modem0] reusing profile '1'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.508155]
[modem0] set profile state (4/8): check activated profile
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.508458]
[modem0] checking if profile with id '1' is already activated...
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.508746]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.509222]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.509711]
[modem0/ttyUSB2/at] --> 'AT+CGACT?<CR>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.583449]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CGACT: 1,1<CR><LF>+CGACT: 16,0<CR><LF>+CGACT:
2,0<CR><LF>+CGACT: 3,0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.584634]
[modem0] profile '1' is activated
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.584807]
[modem0] set profile state (5/8): deactivate profile
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.584958]
[modem0] deactivating profile with id '1'...
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.585151]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.585442]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.585761]
[modem0/ttyUSB2/at] --> 'AT+CGACT=0,1<CR>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.596703]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.694015]
[modem0/ttyUSB2/at] <-- '<CR><LF>ERROR<CR><LF>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.694530]
[modem0/ttyUSB2/at] operation failure: 100 (Unknown error)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.694760]
[modem0] couldn't deactivate profile with id '1': Unknown error
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.694877]
[modem0] set profile state (6/8): profile already stored
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.694984]
[modem0] set profile state (8/8): all done
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.695182]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.695294]
[modem0/bearer0] connection through a plain serial AT port: ttyUSB2
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.695488]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.695873]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.696175]
[modem0/ttyUSB2/at] --> 'AT<CR>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.713222]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.714375]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.714737]
[modem0/ttyUSB2/at] --> 'ATD*99***1#<CR>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.828418]
[modem0/ttyUSB2/at] <-- '<CR><LF>CONNECT 150000000<CR><LF>'
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.829700]
[modem0/bearer0] setting flow control in ttyUSB2: rts-cts
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.830080]
[modem0/ttyUSB2/at] enabling RTS/CTS flow control
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.830278]
[modem0/ttyUSB2/at] port attributes not fully set
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.830465]
[modem0/ttyUSB2/at] flow control settings updated to rts-cts
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.830936]
[modem0/ttyUSB2/at] port now connected
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.831634]
[modem0/bearer0] connected
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.833963]
[modem0/bearer0] PPP is required for connection, will ignore disconnection reports
Wed Jan 12 19:32:56 2022 daemon.info [2709]: <info> [1642015976.834508]
[modem0] state changed (connecting -> connected)
Wed Jan 12 19:32:56 2022 daemon.info [2709]: <info> [1642015976.840749]
[modem0] simple connect state (8/8): all done
Wed Jan 12 19:32:56 2022 daemon.debug [2709]: <debug> [1642015976.844724]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 19:32:56 2022 daemon.notice netifd: wwan (4989): successfully
connected the modem
Wed Jan 12 19:32:56 2022 daemon.notice netifd: wwan (4989): signal refresh rate
is not set
Wed Jan 12 19:32:57 2022 daemon.notice netifd: wwan (4989): network operator
name: FirstNet
Wed Jan 12 19:32:57 2022 daemon.notice netifd: wwan (4989): network operator
MCCMNC: 313100
Wed Jan 12 19:32:57 2022 daemon.notice netifd: wwan (4989): registration type: home
Wed Jan 12 19:32:57 2022 daemon.notice netifd: wwan (4989): access technology: lte
Wed Jan 12 19:32:57 2022 daemon.notice netifd: wwan (4989): signal quality: 100%
Wed Jan 12 19:32:57 2022 daemon.notice netifd: wwan (5190): stopping network
Wed Jan 12 19:32:57 2022 daemon.notice netifd: wwan (5190): IPv4 connection
teardown required in interface wwan: ppp
Wed Jan 12 19:32:57 2022 daemon.notice netifd: wwan (5190): IPv6 connection
teardown required in interface wwan: ppp
Wed Jan 12 19:32:57 2022 daemon.notice netifd: wwan (5190): running
disconnection (ppp method)
Wed Jan 12 19:32:57 2022 daemon.notice netifd: wwan (5190): pppd result code not
given
Wed Jan 12 19:32:57 2022 daemon.notice netifd: wwan (5190): running
disconnection (common)
Wed Jan 12 19:32:57 2022 daemon.notice netifd: wwan (5190): Command failed:
Permission denied
Wed Jan 12 19:32:57 2022 daemon.debug [2709]: <debug> [1642015977.787314]
[modem0] user request to disconnect modem (all bearers)
Wed Jan 12 19:32:57 2022 daemon.debug [2709]: <debug> [1642015977.787861]
[modem0/bearer0] disconnecting...
Wed Jan 12 19:32:57 2022 daemon.info [2709]: <info> [1642015977.788121]
[modem0] state changed (connected -> disconnecting)
Wed Jan 12 19:32:57 2022 daemon.debug [2709]: <debug> [1642015977.790454]
[modem0/bearer0] reopening data port ttyUSB2...
Wed Jan 12 19:32:57 2022 daemon.debug [2709]: <debug> [1642015977.790743]
[modem0/ttyUSB2/at] reopening port (3)
Wed Jan 12 19:32:57 2022 daemon.debug [2709]: <debug> [1642015977.790918]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:57 2022 daemon.debug [2709]: <debug> [1642015977.791095]
[modem0/ttyUSB2/at] device open count is 1 (close)
Wed Jan 12 19:32:57 2022 daemon.debug [2709]: <debug> [1642015977.791273]
[modem0/ttyUSB2/at] device open count is 0 (close)
Wed Jan 12 19:32:57 2022 daemon.debug [2709]: <debug> [1642015977.791474]
[modem0/ttyUSB2/at] closing serial port...
Wed Jan 12 19:32:57 2022 daemon.debug [2709]: <debug> [1642015977.791679]
[modem0/ttyUSB2/at] port now disconnected
Wed Jan 12 19:32:57 2022 daemon.debug [2709]: <debug> [1642015977.792573]
[modem0/ttyUSB2/at] serial port closed
Wed Jan 12 19:32:58 2022 daemon.debug [2709]: <debug> [1642015978.802346]
[modem0/ttyUSB2/at] opening serial port...
Wed Jan 12 19:32:58 2022 daemon.debug [2709]: <debug> [1642015978.803105]
[modem0/ttyUSB2/at] setting up baudrate: 57600
Wed Jan 12 19:32:58 2022 daemon.debug [2709]: <debug> [1642015978.803255]
[modem0/ttyUSB2/at] no flow control explicitly requested for device
Wed Jan 12 19:32:58 2022 daemon.debug [2709]: <debug> [1642015978.803385]
[modem0/ttyUSB2/at] port attributes not fully set
Wed Jan 12 19:32:58 2022 daemon.debug [2709]: <debug> [1642015978.803644]
[modem0/ttyUSB2/at] device open count is 1 (open)
Wed Jan 12 19:32:58 2022 daemon.debug [2709]: <debug> [1642015978.803766]
[modem0/ttyUSB2/at] device open count is 2 (open)
Wed Jan 12 19:32:58 2022 daemon.debug [2709]: <debug> [1642015978.803876]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:58 2022 daemon.debug [2709]: <debug> [1642015978.804083]
[modem0/bearer0] flashing data port ttyUSB2...
Wed Jan 12 19:32:58 2022 daemon.debug [2709]: <debug> [1642015978.804423]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 19:32:58 2022 daemon.debug [2709]: <debug> [1642015978.804544]
[modem0/ttyUSB2/at] running init sequence...
Wed Jan 12 19:32:58 2022 daemon.debug [2709]: <debug> [1642015978.804850]
[modem0/bearer0] sending PDP context deactivation in primary/data port...
Wed Jan 12 19:32:58 2022 daemon.debug [2709]: <debug> [1642015978.805025]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 19:32:58 2022 daemon.debug [2709]: <debug> [1642015978.805318]
[modem0/ttyUSB2/at] --> 'ATE0<CR>'
Wed Jan 12 19:33:01 2022 daemon.debug [2709]: <debug> [1642015981.502485]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 19:33:02 2022 daemon.notice netifd: Interface 'wwan' is now down
Wed Jan 12 19:33:02 2022 daemon.notice netifd: Interface 'wwan' is setting up now
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.396646]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.502868]
[modem0/ttyUSB2/at] --> 'ATV1<CR>'
Wed Jan 12 19:33:02 2022 daemon.notice netifd: wwan (5251): modem available at
/org/freedesktop/ModemManager1/Modem/0
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.616178]
[modem0] user request to disconnect modem (all bearers)
Wed Jan 12 19:33:02 2022 daemon.notice netifd: wwan (5251): starting connection
with apn 'firstnet-broadband'...
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.905111]
[modem0] user request to connect modem
Wed Jan 12 19:33:02 2022 daemon.info [2709]: <info> [1642015982.905706]
[modem0] simple connect started...
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.905828]
[modem0] profile ID: unspecified
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.905932]
[modem0] PIN: unspecified
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.906036]
[modem0] operator ID: unspecified
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.906140]
[modem0] allowed roaming: yes
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.906248]
[modem0] APN: firstnet-broadband
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.906354]
[modem0] APN type: unspecified
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.906465]
[modem0] IP family: ipv4v6
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.906575]
[modem0] allowed authentication: unspecified
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.906686]
[modem0] user: unspecified
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.906791]
[modem0] password: unspecified
Wed Jan 12 19:33:02 2022 daemon.debug [2709]: <debug> [1642015982.906897]
[modem0] multiplex: unspecified
Wed Jan 12 19:33:02 2022 daemon.info [2709]: <info> [1642015982.907001]
[modem0] simple connect state (4/8): wait to get fully enabled
Wed Jan 12 19:33:05 2022 daemon.warn [2709]: <warn> [1642015985.502588]
[modem0] port ttyUSB2 timed out 2 consecutive times
Wed Jan 12 19:33:05 2022 daemon.debug [2709]: <debug> [1642015985.502942]
[modem0/ttyUSB2/at] --> 'AT+CMEE=1<CR>'
Wed Jan 12 19:33:08 2022 daemon.warn [2709]: <warn> [1642015988.502592]
[modem0] port ttyUSB2 timed out 3 consecutive times
Wed Jan 12 19:33:08 2022 daemon.debug [2709]: <debug> [1642015988.502935]
[modem0/ttyUSB2/at] --> 'ATX4<CR>'
Wed Jan 12 19:33:11 2022 daemon.warn [2709]: <warn> [1642015991.502583]
[modem0] port ttyUSB2 timed out 4 consecutive times
Wed Jan 12 19:33:11 2022 daemon.debug [2709]: <debug> [1642015991.502937]
[modem0/ttyUSB2/at] --> 'AT&C1<CR>'
Wed Jan 12 19:33:13 2022 daemon.notice netifd: wwan (5251): error: couldn't
connect the modem: 'GDBus.Error:org.freedesktop.ModemManager1.Error.Core.Retry:
Too much time waiting to get to a final state'
Wed Jan 12 19:33:13 2022 daemon.notice netifd: wwan (5380): stopping network
Wed Jan 12 19:33:13 2022 daemon.notice netifd: wwan (5380): IPv4 connection
teardown required in interface wwan: ppp
Wed Jan 12 19:33:13 2022 daemon.notice netifd: wwan (5380): IPv6 connection
teardown required in interface wwan: ppp
Wed Jan 12 19:33:13 2022 daemon.notice netifd: wwan (5380): running
disconnection (ppp method)
Wed Jan 12 19:33:13 2022 daemon.notice netifd: wwan (5380): pppd result code not
given
Wed Jan 12 19:33:13 2022 daemon.notice netifd: wwan (5380): running
disconnection (common)
Wed Jan 12 19:33:13 2022 daemon.notice netifd: wwan (5380): Command failed:
Permission denied
More information about the ModemManager-devel
mailing list