Modem Manager over UART

Konstantinus · January 5, 2024, 2:30pm

Hi,

I have problems during the connection of A7682E Simcom modem to Beaglebone Black Industrial over UART. I have set all flags needed by modem manager to recognize /dev/ttyS4 as AT-capable port. Nevertheless, when it comes to the moment when the modem manager selects plugin for the device, it selects wrong one and thus the initialization fails. When I use my modem through USB it works fine, everything is ok. But through UART it doesn’t want work at all.

Any hints?

Below I enclose some logs that might be useful:

sudo udevadm info /dev/ttyS4
P: /devices/platform/ocp/481a8000.serial/tty/ttyS4
N: ttyS4
L: 0
S: ttyO4
E: DEVPATH=/devices/platform/ocp/481a8000.serial/tty/ttyS4
E: DEVNAME=/dev/ttyS4
E: MAJOR=4
E: MINOR=68
E: SUBSYSTEM=tty
E: USEC_INITIALIZED=12871771
E: ID_MM_DEVICE_PROCESS=1
E: ID_MM_TTY_BAUDRATE=115200
E: ID_MM_PORT_TYPE_AT_PPP=1
E: ID_MM_CANDIDATE=1
E: DEVLINKS=/dev/ttyO4
E: TAGS=:systemd:

Debug logs from modem manager:

Jan 05 11:26:44 ECS01WControl0v1 ModemManager[17927]: [1704454004.725389] [ttyS4] port contents loaded:
Jan 05 11:26:44 ECS01WControl0v1 ModemManager[17927]: [1704454004.725617] [ttyS4]   bus: platform
Jan 05 11:26:44 ECS01WControl0v1 ModemManager[17927]: [1704454004.725724] [ttyS4]   device: /sys/devices/platform/ocp/481a8000.serial
Jan 05 11:26:44 ECS01WControl0v1 ModemManager[17927]: [1704454004.725818] [ttyS4]   driver: omap8250
Jan 05 11:26:44 ECS01WControl0v1 ModemManager[17927]: [1704454004.725908] [base-manager] adding port ttyS4 at sysfs path: /sys/devices/platform/ocp/481a8000.serial/tty/ttyS4
Jan 05 11:26:44 ECS01WControl0v1 ModemManager[17927]: [1704454004.727017] [filter] (tty/ttyS4) port allowed: device is allowlisted
Jan 05 11:26:44 ECS01WControl0v1 ModemManager[17927]: [1704454004.727205] [base-manager] port ttyS4 is first in device /sys/devices/platform/ocp/481a8000.serial
Jan 05 11:26:44 ECS01WControl0v1 ModemManager[17927]: [1704454004.743209] [ttyS4/probe] port type hint detected in udev tag: ID_MM_PORT_TYPE_AT_PPP
Jan 05 11:26:44 ECS01WControl0v1 ModemManager[17927]: [1704454004.743658] [ttyS4/probe] port type hints loaded: AT yes, QMI no, MBIM no, QCDM no, AUDIO no, GPS no
Jan 05 11:26:44 ECS01WControl0v1 ModemManager[17927]: [1704454004.743980] [plugin-manager] task 0: port grabbed: ttyS4
Jan 05 11:26:44 ECS01WControl0v1 ModemManager[17927]: [1704454004.744149] [plugin-manager] task 0,ttyS4: new support task for port
Jan 05 11:26:44 ECS01WControl0v1 ModemManager[17927]: [1704454004.744241] [plugin-manager] task 0,ttyS4: deferred until min wait time elapsed
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.744477] [plugin/option] port ttyS4 filtered by drivers
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.744662] [plugin/broadmobi] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.744775] [plugin/sierra-legacy] port ttyS4 filtered by drivers
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.744878] [plugin/wavecom] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.744980] [plugin/option-hso] port ttyS4 filtered by drivers
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.745089] [plugin/sierra] port ttyS4 filtered by drivers
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.745187] [plugin/longcheer] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.745294] [plugin/foxconn] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.745394] [plugin/dell] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.745487] [plugin/altair-lte] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.745581] [plugin/simtech] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.745684] [plugin/qcom-soc] port ttyS4 filtered by subsystem
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.745778] [plugin/novatel-lte] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.745875] [plugin/gosuncn] port ttyS4 filtered by drivers
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.745998] [plugin/fibocom] port ttyS4 filtered by drivers
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.746249] [plugin/ericsson-mbm] port ttyS4 filtered by udev tags
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.746385] [plugin/nokia-icera] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.746494] [plugin/haier] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.746620] [plugin/thuraya] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.746726] [plugin/tp-link] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.746823] [plugin/zte] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.747040] [plugin/mtk-legacy] port ttyS4 filtered by udev tags
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.747157] [plugin/motorola] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.747263] [plugin/anydata] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.747371] [plugin/mtk] port ttyS4 filtered by subsystem
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.758507] [plugin/linktop] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.758674] [plugin/novatel] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.758784] [plugin/samsung] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.758883] [plugin/intel] port ttyS4 filtered by subsystem
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.758979] [plugin/x22x] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.759076] [plugin/d-link] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.759173] [plugin/pantech] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.759273] [plugin/huawei] port ttyS4 filtered by vendor/product IDs
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.759572] [plugin-manager] task 0,ttyS4: found '8' plugins to try
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.759697] [plugin-manager] task 0,ttyS4: will try with plugin 'iridium'
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.759823] [plugin-manager] task 0,ttyS4: will try with plugin 'nokia'
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.759909] [plugin-manager] task 0,ttyS4: will try with plugin 'cinterion'
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.759987] [plugin-manager] task 0,ttyS4: will try with plugin 'telit'
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.760062] [plugin-manager] task 0,ttyS4: will try with plugin 'quectel'
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.760137] [plugin-manager] task 0,ttyS4: will try with plugin 'u-blox'
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.760212] [plugin-manager] task 0,ttyS4: will try with plugin 'via'
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.760286] [plugin-manager] task 0,ttyS4: will try with plugin 'generic'
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.760412] [plugin-manager] task 0,ttyS4: started
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.760528] [plugin-manager] task 0,ttyS4: checking with plugin 'iridium'
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.760821] [plugin/iridium] probes required for port ttyS4: 'at, at-vendor, at-product'
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.760994] [ttyS4/probe] no QCDM/QMI/MBIM probing in possible AT port
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.761088] [ttyS4/probe] port is not QCDM-capable
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.761168] [ttyS4/probe] port is not QMI-capable
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.761245] [ttyS4/probe] port is not MBIM-capable
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.761336] [ttyS4/probe] launching port probing: 'at, at-vendor, at-product'
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.761739] [plugin-manager] task 0: still 1 running probes (1 active): ttyS4
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.775876] [ttyS4/at] opening serial port...
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.776709] [ttyS4/at] setting up baudrate: 115200
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.776943] [ttyS4/at] no flow control explicitly requested for device
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.777281] [ttyS4/at] device open count is 1 (open)
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.777894] [ttyS4/at] --> 'AT<CR>'
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.980196] [ttyS4/at] <-- 'AT'
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.987142] [ttyS4/at] <-- '<CR><CR><LF>OK<CR><LF>'
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.988111] [ttyS4/probe] port is AT-capable
Jan 05 11:26:46 ECS01WControl0v1 ModemManager[17927]: [1704454006.988661] [ttyS4/at] --> 'AT+CGMI<CR>'
Jan 05 11:26:47 ECS01WControl0v1 ModemManager[17927]: [1704454007.726864] [ttyS4/at] <-- 'AT+CGMI'
Jan 05 11:26:47 ECS01WControl0v1 ModemManager[17927]: [1704454007.735624] [ttyS4/at] <-- '<CR><CR><LF>INCORPORATED<CR><LF><CR><LF>OK<CR><LF>'
Jan 05 11:26:47 ECS01WControl0v1 ModemManager[17927]: [1704454007.736151] [ttyS4/probe] vendor probing finished
Jan 05 11:26:47 ECS01WControl0v1 ModemManager[17927]: [1704454007.736807] [ttyS4/at] --> 'AT+CGMM<CR>'
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.460211] [ttyS4/at] <-- 'AT+CGMM'
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.468020] [ttyS4/at] <-- '<CR><CR><LF>A7682E<CR><LF><CR><LF>OK<CR><LF>'
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.468495] [ttyS4/probe] product probing finished
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.468756] [plugin/iridium] port ttyS4 filtered by vendor/product strings
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.468896] [plugin-manager] task 0,ttyS4: checking with plugin 'nokia'
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.469095] [plugin/nokia] probing of port ttyS4 deferred until result suggested
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.469334] [ttyS4/at] device open count is 0 (close)
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.469466] [ttyS4/at] closing serial port...
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.476492] [ttyS4/at] serial port closed
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.476945] [ttyS4/at] forced to close port
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.477225] [plugin-manager] task 0,ttyS4: deferring support check until result suggested
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.744110] [plugin-manager] task 0: still 1 running probes (0 active): ttyS4
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.744359] [plugin-manager] task 0,ttyS4: deferred task completed, no suggested plugin
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.744474] [plugin-manager] task 0,ttyS4: finished in '4.000331' seconds
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.744637] [plugin-manager] task 0,ttyS4: not supported by any plugin
Jan 05 11:26:48 ECS01WControl0v1 ModemManager[17927]: [1704454008.744774] [device /sys/devices/platform/ocp/481a8000.serial] fully ignoring port ttyS4 from now on

foxsquirrel · January 5, 2024, 3:43pm

My first place to look would be if you have the correct device tree loaded.
If that is correct put a decoder on /dev/ttyS4 and send some code out to make sure it is working.
Are you sure you have the correct address.

Connect the board then:

$sudo dmesg | grep tty

You should see your device if the device tree is correct, it will also give you the correct path to use.

Since you are using uart

$groups

You should be in dialout group.

Konstantinus · January 5, 2024, 3:59pm

$ groups
adm kmem dialout cdrom floppy audio dip video plugdev users systemd-journal input bluetooth netdev cloud9ide weston-launch tisdk i2c admin gpio

Konstantinus · January 5, 2024, 3:59pm

$ dmesg | grep ttyS4
[1.089535] 481a8000.serial: ttyS4 at MMIO 0x481a8000 (irq = 33, base_baud = 3000000) is a 8250

foxsquirrel · January 5, 2024, 4:59pm

If that is with your board connected it does show it is connected…

Is this your own custom code or from the device provider?

Konstantinus · January 8, 2024, 1:11pm

It is not my custom code so I assume it’s from the device provider…

foxsquirrel · January 8, 2024, 1:19pm

Are you able to us a ttl to usb convertor? If so connect that to ttyS4 and the other end to gtkterm then see what or if code is actually being sent out.

I don’t see that rate in gtkterm or am I reading that wrong?

Either way, do a test set up that will actually send out data on ttyS4 that can be decoded in order to verify for fact that you have hardware up. If that works, its the code associated with your device. If you can send data back and forth using a terminal program that will rule out the board/board config having a problem.

Konstantinus · January 9, 2024, 12:58pm

Ok, I don’t have any ttl to usb converter for now. Nevertheless, I performed sudo screen /dev/ttyS4 115200 using the UART4 pins and here is what I see:

*ATREADY: 1
+CPIN: SIM PIN
ATI
Manufacturer: INCORPORATED
Model: A7682E
Revision: A7682M7_V1.11.1
IMEI: 863423067124856
+GCAP: +CGSM,+FCLASS,+DS
OK

foxsquirrel · January 9, 2024, 1:39pm

Since the device id is being read in, nothing wrong with the BBB. You will have to reach out the manufacturer for guidance on getting it up and running.

Ask them if the code is for ARMhf or ARM64. It might work on the BP/AI64 class boards, just a guess.

jkridner · January 9, 2024, 4:28pm

It seems ModemManager is doing the probe, but dies before it reaches ‘generic’. Without further hints to ModemManager, I’d guess that’d be the only plugin that might work. It is strange that something seems to close the serial port. Do you have any other scripts running that might impact the serial port and take it away from ModemManager?

It might be of some help to blacklist probes that you know aren’t valid. See Filter policies: ModemManager Reference Manual.

Konstantinus · January 10, 2024, 1:27pm

Thank you for your assistance.

I’ve implemented the --filter-policy=ALLOWLIST-ONLY option, which now specifically probes only ttyS4. This has significantly improved the initialization process. Additionally, I delved into the selection criteria for the Nokia plugin over the Simtech plugin in the Modem Manager. After inspecting the source code, the reason became apparent: the Nokia plugin accepts zero and null as the vendor ID, and my scenario meets its criteria. Specifically, when the modem is connected to the ttyS4 port, there are no fields like product ID or vendor ID, similar to the USB case.

To address this, I locally modified the Modem Manager source code and rebuilt it using Meson build and a Balena Docker container, ensuring an armhf environment during the build. Consequently, the Modem Manager now prioritizes the Simtech plugin. I removed the Nokia plugin from the Meson options and introduced an option for the Simtech plugin to accept the product ID, even if it cannot be read from the device. These modifications align with the requirements of my setup.

While the modem is now recognized on mmcli -L, an issue arises when attempting to connect to the GSM network by sending a PIN to the SIM card: sudo mmcli -i 0 --pin=1234. The process gets stuck after receiving AT+CNSMOD=2 from the Modem Manager. I’m curious to understand why this is happening and seek guidance on resolving this particular issue.

Konstantinus · January 15, 2024, 1:01pm

Any hints on that?

foxsquirrel · January 15, 2024, 1:44pm

Have you tried this:

--pin='1234'

Konstantinus · January 15, 2024, 3:47pm

I’ve just tried it. Here are the results:

konstantinus@beaglebone:~$ sudo mmcli -L
    /org/freedesktop/ModemManager1/Modem/1 [INCORPORATED] A7682E
konstantinus@beaglebone:~$ sudo mmcli -m 1
  -----------------------------
  General  |              path: /org/freedesktop/ModemManager1/Modem/1
           |         device id: 4d045181cdcb6dc75a508a009078fe375ac76a9d
  -----------------------------
  Hardware |      manufacturer: INCORPORATED
           |             model: A7682E
           | firmware revision: A011B05A7682M7
           |         supported: gsm-umts, lte
           |           current: gsm-umts, lte
           |      equipment id: 862325057980284
  -----------------------------
  System   |            device: /sys/devices/platform/ocp/481a8000.serial
           |           physdev: /sys/devices/platform/ocp/481a8000.serial
           |           drivers: omap8250
           |            plugin: simtech
           |      primary port: ttyS4
           |             ports: ttyS4 (at)
  -----------------------------
  Status   |              lock: sim-pin
           |    unlock retries: sim-pin (3), sim-pin2 (3), sim-puk (10), sim-puk2 (10)
           |             state: locked
           |       power state: on
  -----------------------------
  Modes    |         supported: allowed: 2g; preferred: none
           |                    allowed: 3g; preferred: none
           |                    allowed: 2g, 3g; preferred: none
           |                    allowed: 2g, 3g; preferred: 2g
           |                    allowed: 2g, 3g; preferred: 3g
           |           current: allowed: any; preferred: none
  -----------------------------
  IP       |         supported: ipv4, ipv6, ipv4v6
  -----------------------------
  3GPP     |              imei: 862325057980284
  -----------------------------
  SIM      |  primary sim path: /org/freedesktop/ModemManager1/SIM/0
konstantinus@beaglebone:~$ sudo mmcli -i
error: no actions specified
konstantinus@beaglebone:~$ sudo mmcli -i 0 --pin='1234'
successfully sent PIN code to the SIM
konstantinus@beaglebone:~$ sudo mmcli -m 1 -w
        /org/freedesktop/ModemManager1/Modem/1: Initial state, 'initializing'
        /org/freedesktop/ModemManager1/Modem/1: State changed, 'initializing' --> 'disabled' (Reason: None or unknown)
        /org/freedesktop/ModemManager1/Modem/1: State changed, 'disabled' --> 'enabling' (Reason: User request)
        /org/freedesktop/ModemManager1/Modem/1: Removed
konstantinus@beaglebone:~$ cat /var/log/syslog | grep -i 'modem'
Feb 14 10:15:52 beaglebone ModemManager[468]: [1550139352.201924] [base-manager] processing user request to launch device scan
Feb 14 10:15:52 beaglebone ModemManager[468]: [1550139352.205806] [base-manager] starting manual device scan...
Feb 14 10:15:52 beaglebone ModemManager[468]: [1550139352.306866] [base-manager] finished device scan...
Feb 14 10:15:52 beaglebone ModemManager[468]: [1550139352.373524] [ttyS4] port contents loaded:
Feb 14 10:15:52 beaglebone ModemManager[468]: [1550139352.373740] [ttyS4]   bus: platform
Feb 14 10:15:52 beaglebone ModemManager[468]: [1550139352.373843] [ttyS4]   device: /sys/devices/platform/ocp/481a8000.serial
Feb 14 10:15:52 beaglebone ModemManager[468]: [1550139352.373937] [ttyS4]   driver: omap8250
Feb 14 10:15:52 beaglebone ModemManager[468]: [1550139352.374032] [base-manager] adding port ttyS4 at sysfs path: /sys/devices/platform/ocp/481a8000.serial/tty/ttyS4
Feb 14 10:15:52 beaglebone ModemManager[468]: [1550139352.375352] [filter] (tty/ttyS4) port allowed: device is allowlisted
Feb 14 10:15:52 beaglebone ModemManager[468]: [1550139352.375546] [base-manager] port ttyS4 already added
Feb 14 10:17:06 beaglebone ModemManager[468]: [1550139426.630994] [ttyS4/at] opening serial port...
Feb 14 10:17:06 beaglebone ModemManager[468]: [1550139426.635560] [ttyS4/at] setting up baudrate: 115200
Feb 14 10:17:06 beaglebone ModemManager[468]: [1550139426.635802] [ttyS4/at] no flow control explicitly requested for device
Feb 14 10:17:06 beaglebone ModemManager[468]: [1550139426.638312] [ttyS4/at] device open count is 1 (open)
Feb 14 10:17:06 beaglebone ModemManager[468]: [1550139426.639141] [ttyS4/at] --> 'AT+CPIN="1234"<CR>'
Feb 14 10:17:06 beaglebone ModemManager[468]: [1550139426.932403] [ttyS4/at] <-- '<CR><LF>OK<CR><LF><CR><LF>+CPIN: READY<CR><LF>'
Feb 14 10:17:06 beaglebone ModemManager[468]: [1550139426.933116] [modem1] (simtech) checking if unlock required...
Feb 14 10:17:06 beaglebone ModemManager[468]: [1550139426.933323] [ttyS4/at] device open count is 2 (open)
Feb 14 10:17:06 beaglebone ModemManager[468]: [1550139426.933559] [ttyS4/at] device open count is 1 (close)
Feb 14 10:17:06 beaglebone ModemManager[468]: [1550139426.933777] [ttyS4/at] --> 'AT+CPIN?<CR>'
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.045809] [ttyS4/at] <-- '<CR><LF>+CPIN: READY<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.046643] [modem1] SIM is ready, and no need for the after SIM unlock step...
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.046900] [ttyS4/at] device open count is 2 (open)
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.047167] [ttyS4/at] device open count is 1 (close)
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.047398] [ttyS4/at] --> 'AT+CSIM=10,"0020000100"<CR>'
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.353021] [ttyS4/at] <-- '<CR><LF>+CSIM: 4,"63C3"<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.353888] [ttyS4/at] device open count is 2 (open)
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.354138] [ttyS4/at] device open count is 1 (close)
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.354504] [ttyS4/at] --> 'AT+CSIM=10,"002C000100"<CR>'
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.744665] [ttyS4/at] <-- '<CR><LF>+CSIM: 4,"63CA"<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.749443] [ttyS4/at] device open count is 2 (open)
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.749813] [ttyS4/at] device open count is 1 (close)
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.750092] [ttyS4/at] --> 'AT+CSIM=10,"0020008100"<CR>'
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.809397] [ttyS4/at] <-- '<CR><LF>+CSIM: 4,"63C3"<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.812518] [ttyS4/at] device open count is 2 (open)
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.815103] [ttyS4/at] device open count is 1 (close)
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.817379] [ttyS4/at] --> 'AT+CSIM=10,"002C008100"<CR>'
Feb 14 10:17:07 beaglebone ModemManager[468]: [1550139427.937385] [ttyS4/at] <-- '<CR><LF>SMS DONE<CR><LF>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.415690] [ttyS4/at] <-- '<CR><LF>+CSIM: 4,"63CA"<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.429158] [ttyS4/at] device open count is 0 (close)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.435376] [ttyS4/at] closing serial port...
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.447419] [ttyS4/at] serial port closed
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.453657] [modem1] state changed (locked -> initializing)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.473229] [ttyS4/at] opening serial port...
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.477078] [ttyS4/at] setting up baudrate: 115200
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.477348] [ttyS4/at] no flow control explicitly requested for device
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.477631] [ttyS4/at] device open count is 1 (open)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.477748] [ttyS4/at] running init sequence...
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.482771] [ttyS4/at] device open count is 2 (open)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.483218] [ttyS4/at] --> 'ATE0<CR>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.498133] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.499025] [ttyS4/at] --> 'ATV1<CR>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.512063] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.512734] [ttyS4/at] --> 'AT+CMEE=1<CR>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.533527] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.534204] [ttyS4/at] --> 'ATX4<CR>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.549163] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.549842] [ttyS4/at] --> 'AT&C1<CR>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.566508] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.567539] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.567810] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.568008] [ttyS4/at] --> 'AT+CSCS="UCS2"<CR>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.686183] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.689257] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.691785] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.693972] [ttyS4/at] --> 'AT+CSCS?<CR>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.716336] [ttyS4/at] <-- '<CR><LF>+CSCS: "UCS2"<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.719711] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.722090] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.724565] [ttyS4/at] --> 'AT+CNAOP?<CR>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.748574] [ttyS4/at] <-- '<CR><LF>ERROR<CR><LF>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.753294] [ttyS4/at] operation failure: 100 (Unknown error)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.753658] [modem1] couldn't load current allowed/preferred modes: Unknown error
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.754149] [modem1/sim0] loading IMSI...
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.757563] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.762920] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.763312] [ttyS4/at] --> 'AT+CIMI<CR>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.783554] [ttyS4/at] <-- '<CR><LF>260032110517109<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.784162] [modem1/sim0] loaded IMSI: 260032110517109
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.784421] [modem1/sim0] loaded IMSI: ###
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.784537] [modem1/sim0] loading operator ID...
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.784705] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.784945] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.789249] [ttyS4/at] --> 'AT+CRSM=176,28589,0,0,4<CR>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.840397] [ttyS4/at] <-- '<CR><LF>+CRSM: 144,0,"00FFFF02"<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.843569] [modem1/sim0] loaded operator identifier: 26003
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.845794] [modem1/sim0] loading emergency numbers...
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.848188] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.848615] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.857308] [ttyS4/at] --> 'AT+CRSM=176,28599,0,0,15<CR>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.909125] [ttyS4/at] <-- '<CR><LF>+CRSM: 105,129<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.912122] [modem1/sim0] couldn't load list of emergency numbers: Failed to parse CRSM query result '+CRSM: 105,129'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.914625] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.916927] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.919427] [ttyS4/at] --> 'AT+CRSM=176,28478,0,0,0<CR>'
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.964853] [ttyS4/at] <-- '<LF>+CME ERROR: 13<CR><LF>'
Feb 14 10:17:19 beaglebone ModemManager[468]: [1550139439.360635] [modem1/sim0] couldn't load GID1: Serial command timed out
Feb 14 10:17:19 beaglebone ModemManager[468]: [1550139439.361058] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:19 beaglebone ModemManager[468]: [1550139439.361311] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:19 beaglebone ModemManager[468]: [1550139439.361551] [ttyS4/at] --> 'AT+CRSM=176,28479,0,0,0<CR>'
Feb 14 10:17:20 beaglebone ModemManager[468]: [1550139440.778753] [ttyS4/at] <-- '<CR><LF>+CGEV: EPS PDN ACT 1<CR><LF>'
Feb 14 10:17:21 beaglebone ModemManager[468]: [1550139441.302660] [ttyS4/at] <-- '<LF>+CME ERROR: 13<CR><LF>'
Feb 14 10:17:21 beaglebone ModemManager[468]: [1550139441.752491] [ttyS4/at] <-- '<CR><LF>+CGEV: ME PDN DEACT 8<CR><LF>'
Feb 14 10:17:25 beaglebone ModemManager[468]: [1550139445.620755] [ttyS4/at] <-- '<CR><LF>PB DONE<CR><LF>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.358744] [modem1/sim0] couldn't load GID2: Serial command timed out
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.359150] [modem1] loading own numbers...
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.359319] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.359569] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.359773] [modem1] port ttyS4 timed out 2 consecutive times
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.359952] [ttyS4/at] --> 'AT+CNUM<CR>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.378019] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.379985] [modem1] loading enabled facility locks...
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.380237] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.380507] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.381015] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.381244] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.381445] [ttyS4/at] --> 'AT+CLCK="SC",2<CR>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.412945] [ttyS4/at] <-- '<CR><LF>+CLCK: 1<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.413754] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.414003] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.414227] [ttyS4/at] --> 'AT+CLCK="FD",2<CR>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.445439] [ttyS4/at] <-- '<CR><LF>+CLCK: 0<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.448339] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.450793] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.451218] [ttyS4/at] --> 'AT+CLCK="PN",2<CR>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.483376] [ttyS4/at] <-- '<CR><LF>+CLCK: 0<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.486162] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.488692] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.491107] [ttyS4/at] --> 'AT+CLCK="PU",2<CR>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.524020] [ttyS4/at] <-- '<CR><LF>+CLCK: 0<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.527003] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.529776] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.532326] [ttyS4/at] --> 'AT+CLCK="PP",2<CR>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.564203] [ttyS4/at] <-- '<CR><LF>+CLCK: 0<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.567159] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.569478] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.571922] [ttyS4/at] --> 'AT+CLCK="PC",2<CR>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.608130] [ttyS4/at] <-- '<CR><LF>+CLCK: 0<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.611230] [modem1] loading UE mode of operation for EPS...
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.613946] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.616463] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.625378] [ttyS4/at] --> 'AT+CEMODE?<CR>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.648583] [ttyS4/at] <-- '<CR><LF>+CEMODE: 1<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.669263] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.672111] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.691159] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.693925] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.696429] [ttyS4/at] --> 'AT+CUSD=?<CR>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.719521] [ttyS4/at] <-- '<CR><LF>+CUSD: (0-2)<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.733485] [ttyS4/at] device open count is 1 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.736425] [modem1] (simtech) no GPS data port found: no GPS capabilities
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.751712] [ttyS4/at] device open count is 2 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.754657] [ttyS4/at] --> 'AT+CNMI=?<CR>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.780558] [ttyS4/at] <-- '<CR><LF>+CNMI: (0,1,2),(0,1,2,3),(0,2),(0,1,2),(0,1)<CR><LF><CR>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.783499] [ttyS4/at] <-- '<LF>OK<CR><LF>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.785898] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.788421] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.790895] [ttyS4/at] --> 'AT+CPMS=?<CR>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.816252] [ttyS4/at] <-- '<CR><LF>+CPMS: ("ME","SM"),("ME","SM"),("ME","SM")<CR><LF><CR><LF>O'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.819163] [ttyS4/at] <-- 'K<CR><LF>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.821848] [modem1] supported storages loaded:
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.824247] [modem1]   mem1 (list/read/delete) storages: 'me, sm'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.826187] [modem1]   mem2 (write/send) storages:       'me, sm'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.826635] [modem1]   mem3 (reception) storages:        'me, sm'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.827099] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.827412] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.827705] [ttyS4/at] --> 'AT+CPMS?<CR>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.850846] [ttyS4/at] <-- '<CR><LF>+CPMS: "SM",6,25,"SM",6,25,"SM",6,25<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.851676] [modem1] current storages initialized:
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.851826] [modem1]   mem1 (list/read/delete) storages: 'sm'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.851922] [modem1]   mem2 (write/send) storages:       'sm'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.852019] [modem1] current storages initialized
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.868236] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.868669] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.868961] [ttyS4/at] --> 'AT+CTZU=1<CR>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.982440] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:29 beaglebone ModemManager[468]: [1550139449.983213] [ttyS4/at] --> 'AT+CCLK?<CR>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.005522] [ttyS4/at] <-- '<CR><LF>+CCLK: "24/01/15,15:23:09+04"<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.018718] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.021073] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.021508] [ttyS4/at] --> 'AT+CESQ=?<CR>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.048153] [ttyS4/at] <-- '<CR><LF>+CESQ: (0-63,99),(0-7,99),(0-96,255),(0-49,255)'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.051199] [ttyS4/at] <-- ',(0-34,255),(0-97,255)<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.066202] [ttyS4/at] device open count is 1 (close)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.068980] [modem1] couldn't initialize interface: 'OMA not supported'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.072536] [modem1] couldn't initialize interface: 'SAR not supported'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.075351] [ttyS4/at] device open count is 2 (open)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.077732] [ttyS4/at] --> 'ATH<CR>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.112323] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.112981] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.113227] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.113447] [ttyS4/at] --> 'AT+CLCC=?<CR>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.138948] [ttyS4/at] <-- '<CR><LF>+CLCC: (0-1)<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.141677] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.144353] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.144783] [ttyS4/at] --> 'AT+CLCC=?<CR>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.168403] [ttyS4/at] <-- '<CR><LF>+CLCC: (0-1)<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.171329] [modem1] (simtech) modem supports +CLCC URCs
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.173555] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.175992] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.176426] [ttyS4/at] --> 'AT+CPCMREG=?<CR>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.203348] [ttyS4/at] <-- '<CR><LF>ERROR<CR><LF>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.205895] [ttyS4/at] operation failure: 100 (Unknown error)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.208271] [modem1] (simtech) modem doesn't support USB audio control
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.239090] [ttyS4/at] device open count is 1 (close)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.241887] [modem1] state changed (initializing -> disabled)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.258988] [ttyS4/at] device open count is 0 (close)
Feb 14 10:17:30 beaglebone NetworkManager[425]: <info>  [1550139450.2581] modem["ttyS4"]: modem state changed, 'locked' --> 'disabled' (reason: unknown)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.268343] [ttyS4/at] closing serial port...
Feb 14 10:17:30 beaglebone NetworkManager[425]: <info>  [1550139450.2718] modem["ttyS4"]: modem state changed, 'disabled' --> 'enabling' (reason: user preference)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.272746] [ttyS4/at] serial port closed
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.297591] [modem1] processing user request to enable modem...
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.300699] [modem1] state changed (disabled -> enabling)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.317892] [ttyS4/at] opening serial port...
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.320921] [ttyS4/at] setting up baudrate: 115200
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.323212] [ttyS4/at] no flow control explicitly requested for device
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.325433] [ttyS4/at] device open count is 1 (open)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.325680] [modem1] flashing primary AT port before enabling...
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.326017] [modem1] running initialization sequence...
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.326219] [ttyS4/at] device open count is 2 (open)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.329555] [ttyS4/at] --> 'ATZ<CR>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.344089] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.344653] [modem1] giving some time to settle the modem...
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.344825] [ttyS4/at] device open count is 1 (close)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.851063] [ttyS4/at] running init sequence...
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.851672] [modem1] loading power state...
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.851878] [ttyS4/at] device open count is 2 (open)
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.852154] [ttyS4/at] --> 'ATE0<CR>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.903659] [ttyS4/at] <-- 'ATE0<CR><CR><LF>OK<CR><LF>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.904301] [ttyS4/at] --> 'ATV1<CR>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.923351] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.923986] [ttyS4/at] --> 'AT+CMEE=1<CR>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.947086] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.947751] [ttyS4/at] --> 'ATX4<CR>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.956747] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:30 beaglebone ModemManager[468]: [1550139450.957429] [ttyS4/at] --> 'AT&C1<CR>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139450.971655] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139450.972306] [ttyS4/at] --> 'AT+CFUN?<CR>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139450.988951] [ttyS4/at] <-- '<CR><LF>+CFUN: 1<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139450.989678] [modem1] no need to change power state: already 'on'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139450.989841] [modem1] power state updated: on
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139450.990060] [modem1] checking if SIM was swapped...
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139450.990243] [modem1/sim0] loading SIM identifier...
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139450.990713] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139450.991037] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139450.991301] [ttyS4/at] --> 'AT+CRSM=176,12258,0,0,10<CR>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.036927] [ttyS4/at] <-- '<CR><LF>+CRSM: 144,0,"988430022501151790F9"<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.037667] [modem1/sim0] loaded SIM identifier: 8948032052105171099
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.037864] [modem1] SIM identifier has not changed: ###
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.037969] [modem1/sim0] loading IMSI...
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.038163] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.038595] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.038884] [ttyS4/at] --> 'AT+CIMI<CR>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.053675] [ttyS4/at] <-- '<CR><LF>260032110517109<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.054235] [modem1/sim0] loaded IMSI: 260032110517109
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.054550] [modem1] SIM imsi has not changed: ###
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.054804] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.055074] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.055345] [ttyS4/at] --> 'AT+IFC=?<CR>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.075360] [ttyS4/at] <-- '<CR><LF>+IFC: (0-2),(0-2)<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.076092] [modem1] TE supports no flow control
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.076252] [modem1] TE supports XON/XOFF flow control
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.076344] [modem1] TE supports RTS/CTS flow control
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.076440] [modem1] TA supports no flow control
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.076530] [modem1] TA supports XON/XOFF flow control
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.076609] [modem1] TA supports RTS/CTS flow control
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.076723] [modem1] flow control settings automatically selected: rts-cts
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.076927] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.077149] [modem1] modem has 3GPP capabilities, enabling the Modem 3GPP interface...
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.077338] [modem1] checking packet domain event reporting...
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.077486] [ttyS4/at] device open count is 4 (open)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.077699] [ttyS4/at] device open count is 3 (close)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.077940] [ttyS4/at] --> 'AT+IFC=2,2<CR>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.097589] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.098180] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.098663] [ttyS4/at] --> 'AT+CGEREP=?<CR>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.124157] [ttyS4/at] <-- '<CR><LF>+CGEREP: (0-2),(0-1)<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.124769] [modem1] packet domain event reporting is supported
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.125019] [modem1] setting 3GPP +CGEV unsolicited events handlers in ttyS4
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.125260] [modem1] enabling +CGEV event reporting in primary port...
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.125459] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.125722] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.125976] [ttyS4/at] --> 'AT+CGEREP=2<CR>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.147806] [ttyS4/at] <-- '<CR><LF>OK<CR><LF>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.148411] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.148723] [ttyS4/at] device open count is 4 (open)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.148949] [ttyS4/at] device open count is 3 (close)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.149260] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.149479] [ttyS4/at] --> 'AT+CNSMOD=?<CR>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.174065] [ttyS4/at] <-- '<CR><LF>+CNSMOD: (0,1)<CR><LF><CR><LF>OK<CR><LF>'
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.174991] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.175299] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:31 beaglebone ModemManager[468]: [1550139451.175553] [ttyS4/at] --> 'AT+CNSMOD=1<CR>'
Feb 14 10:17:51 beaglebone ModemManager[468]: [1550139471.367246] [modem1] (simtech) couldn't enable automatic access technology reporting: Serial command timed out
Feb 14 10:17:51 beaglebone ModemManager[468]: [1550139471.367718] [ttyS4/at] device open count is 3 (open)
Feb 14 10:17:51 beaglebone ModemManager[468]: [1550139471.367978] [ttyS4/at] device open count is 2 (close)
Feb 14 10:17:51 beaglebone ModemManager[468]: [1550139471.368263] [ttyS4/at] --> 'AT+AUTOCSQ=?<CR>'
Feb 14 10:17:54 beaglebone ModemManager[468]: [1550139474.359467] [modem1] setting up 3GPP unsolicited registration messages handlers in ttyS4
Feb 14 10:17:54 beaglebone ModemManager[468]: [1550139474.363637] [ttyS4/at] device open count is 1 (close)
Feb 14 10:17:54 beaglebone ModemManager[468]: [1550139474.363974] [modem1] port ttyS4 timed out 2 consecutive times
Feb 14 10:17:54 beaglebone ModemManager[468]: [1550139474.364349] [ttyS4/at] device open count is 2 (open)
Feb 14 10:17:54 beaglebone ModemManager[468]: [1550139474.364640] [ttyS4/at] --> 'AT+CREG=2<CR>'
Feb 14 10:17:55 beaglebone NetworkManager[425]: <warn>  [1550139475.2670] modem-broadband[ttyS4]: failed to enable modem: Timeout was reached
Feb 14 10:17:57 beaglebone ModemManager[468]: [1550139477.358756] [modem1] port ttyS4 timed out 3 consecutive times
Feb 14 10:17:57 beaglebone ModemManager[468]: [1550139477.359130] [ttyS4/at] --> 'AT+CREG=1<CR>'
Feb 14 10:18:00 beaglebone ModemManager[468]: [1550139480.358555] [modem1] enabling unsolicited registration events in primary port failed: AT sequence failed
Feb 14 10:18:00 beaglebone ModemManager[468]: [1550139480.358959] [ttyS4/at] device open count is 3 (open)
Feb 14 10:18:00 beaglebone ModemManager[468]: [1550139480.359192] [ttyS4/at] device open count is 2 (close)
Feb 14 10:18:00 beaglebone ModemManager[468]: [1550139480.359385] [modem1] port ttyS4 timed out 4 consecutive times
Feb 14 10:18:00 beaglebone ModemManager[468]: [1550139480.359552] [ttyS4/at] --> 'AT+CGREG=2<CR>'
Feb 14 10:18:03 beaglebone ModemManager[468]: [1550139483.358642] [modem1] port ttyS4 timed out 5 consecutive times
Feb 14 10:18:03 beaglebone ModemManager[468]: [1550139483.359011] [ttyS4/at] --> 'AT+CGREG=1<CR>'
Feb 14 10:18:06 beaglebone ModemManager[468]: [1550139486.357956] [modem1] enabling unsolicited registration events in primary port failed: AT sequence failed
Feb 14 10:18:06 beaglebone ModemManager[468]: [1550139486.358454] [ttyS4/at] device open count is 3 (open)
Feb 14 10:18:06 beaglebone ModemManager[468]: [1550139486.358698] [ttyS4/at] device open count is 2 (close)
Feb 14 10:18:06 beaglebone ModemManager[468]: [1550139486.358897] [modem1] port ttyS4 timed out 6 consecutive times
Feb 14 10:18:06 beaglebone ModemManager[468]: [1550139486.359067] [ttyS4/at] --> 'AT+CEREG=2<CR>'
Feb 14 10:18:09 beaglebone ModemManager[468]: [1550139489.358077] [modem1] port ttyS4 timed out 7 consecutive times
Feb 14 10:18:09 beaglebone ModemManager[468]: [1550139489.361954] [ttyS4/at] --> 'AT+CEREG=1<CR>'
Feb 14 10:18:12 beaglebone ModemManager[468]: [1550139492.358786] [modem1] enabling unsolicited registration events in primary port failed: AT sequence failed
Feb 14 10:18:12 beaglebone ModemManager[468]: [1550139492.359105] [modem1] enabling unsolicited registration events failed: AT sequence failed
Feb 14 10:18:12 beaglebone ModemManager[468]: [1550139492.359211] [modem1] periodic 3GPP registration checks enabled
Feb 14 10:18:12 beaglebone ModemManager[468]: [1550139492.359369] [modem1] modem has 3GPP profile management capabilities, enabling the Modem 3GPP Profile Manager interface...
Feb 14 10:18:12 beaglebone ModemManager[468]: [1550139492.359620] [ttyS4/at] device open count is 1 (close)
Feb 14 10:18:12 beaglebone ModemManager[468]: [1550139492.359817] [modem1] port ttyS4 timed out 8 consecutive times
Feb 14 10:18:12 beaglebone ModemManager[468]: [1550139492.359987] [modem1] modem has 3GPP/USSD capabilities, enabling the Modem 3GPP/USSD interface...
Feb 14 10:18:12 beaglebone ModemManager[468]: [1550139492.360211] [modem1] setting unsolicited result code handlers in ttyS4
Feb 14 10:18:12 beaglebone ModemManager[468]: [1550139492.360507] [ttyS4/at] device open count is 2 (open)
Feb 14 10:18:12 beaglebone ModemManager[468]: [1550139492.360768] [ttyS4/at] --> 'AT+CUSD=1<CR>'
Feb 14 10:18:15 beaglebone ModemManager[468]: [1550139495.358700] [modem1] couldn't enable unsolicited USSD events: Serial command timed out
Feb 14 10:18:15 beaglebone ModemManager[468]: [1550139495.359227] [modem1] modem has location capabilities, enabling the Location interface...
Feb 14 10:18:15 beaglebone ModemManager[468]: [1550139495.359459] [modem1] need to enable the following location sources: '3gpp-lac-ci'
Feb 14 10:18:15 beaglebone ModemManager[468]: [1550139495.359836] [modem1] running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes', 5GS: 'no')
Feb 14 10:18:15 beaglebone ModemManager[468]: [1550139495.360034] [ttyS4/at] device open count is 3 (open)
Feb 14 10:18:15 beaglebone ModemManager[468]: [1550139495.360312] [ttyS4/at] device open count is 2 (close)
Feb 14 10:18:15 beaglebone ModemManager[468]: [1550139495.360497] [modem1] port ttyS4 timed out 9 consecutive times
Feb 14 10:18:15 beaglebone ModemManager[468]: [1550139495.383000] [modem1] modem has messaging capabilities, enabling the Messaging interface...
Feb 14 10:18:15 beaglebone ModemManager[468]: [1550139495.383897] [ttyS4/at] device open count is 3 (open)
Feb 14 10:18:15 beaglebone ModemManager[468]: [1550139495.384336] [ttyS4/at] --> 'AT+CREG?<CR>'
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.365474] [ttyS4/at] device open count is 4 (open)
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.365886] [ttyS4/at] device open count is 3 (close)
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.366109] [modem1] port ttyS4 timed out 10 consecutive times, marking modem as invalid
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.366327] [ttyS4/at] --> 'AT+CMGF=?<CR>'
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.397895] [device /sys/devices/platform/ocp/481a8000.serial] unexported modem from path '/org/freedesktop/ModemManager1/Modem/1'
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.413207] [modem1] cleaning up port 'tty/ttyS4'...
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.432777] [modem1] failed to query supported SMS modes: Operation was cancelled
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.433031] [modem1] neither PDU nor Text modes are reported as supported; will anyway default to PDU mode
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.433254] [ttyS4/at] device open count is 2 (close)
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.433495] [modem1] failed to set preferred SMS mode: No AT port available to run command; assuming text mode'
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.433650] [modem1] couldn't enable interface: 'Operation was cancelled'
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.433809] [modem1] failed enabling modem: Operation was cancelled
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.441430] [ttyS4/at] --> 'AT+CGREG?<CR>'
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.458197] [ttyS4/at] device open count is 1 (close)
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.458807] [ttyS4/at] device open count is 0 (close)
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.458972] [ttyS4/at] closing serial port...
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.459412] [ttyS4/at] serial port closed
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.459782] [ttyS4/at] forced to close port
Feb 14 10:18:25 beaglebone ModemManager[468]: [1550139505.460037] [modem1] completely disposed
konstantinus@beaglebone:~$ mmcli -L
No modems were found

foxsquirrel · January 15, 2024, 5:15pm

That is a positive, glad that is up.

Konstantinus:

[ttyS4/at] operation failure: 100 (Unknown error)
Feb 14 10:17:08 beaglebone ModemManager[468]: [1550139428.753658] [modem1] couldn't load current allowed/preferred modes: Unknown error

Is that error code generated by the device driver or NMCLI, I cannot tell from this information where it is coming from. Since it is enumerated I would suspect its from the device??

If you have the source for the driver, grep the tree for 100 and see what comes up.

Konstantinus · January 22, 2024, 12:32pm

If you have the source for the driver, grep the tree for 100 and see what comes up.

Ok, I’ve greped the source tree for finding the ‘100’ and here are the results:

$ grep -rne '\b100\b' .
./test/mmtty.c:260:                          100,
./introspection/org.freedesktop.ModemManager1.Modem.xml:1064:        Signal quality in percent (0 - 100) of the dominant access technology
grep: ./.git/objects/pack/pack-58d30ae80973b4614f9cd5502660bf3647f6e5d4.pack: binary file matches
./libmm-glib/tests/test-common-helpers.c:385:    g_assert (mm_get_int_from_str ("-100", &num) == TRUE);
./libmm-glib/tests/test-common-helpers.c:386:    g_assert_cmpint (num, ==, -100);
./libmm-glib/tests/test-common-helpers.c:388:    g_assert (mm_get_int_from_str ("100", &num) == TRUE);
./libmm-glib/tests/test-common-helpers.c:389:    g_assert_cmpint (num, ==, 100);
./libmm-glib/tests/test-common-helpers.c:423:    g_assert (mm_get_uint_from_str ("-100", &num) == FALSE);
./libmm-glib/tests/test-common-helpers.c:436:    g_assert (mm_get_uint_from_str ("100", &num) == TRUE);
./libmm-glib/tests/test-common-helpers.c:437:    g_assert_cmpuint (num, ==, 100);
./libmm-glib/tests/test-common-helpers.c:470:    g_assert (mm_get_double_from_str ("-100", &num) == TRUE);
./libmm-glib/tests/test-common-helpers.c:471:    g_assert (num - (-100.0) < 0000000.1);
./libmm-glib/tests/test-common-helpers.c:473:    g_assert (mm_get_double_from_str ("-100.7567", &num) == TRUE);
./libmm-glib/tests/test-common-helpers.c:474:    g_assert (num - (-100.7567) < 0000000.1);
./libmm-glib/tests/test-common-helpers.c:485:    g_assert (mm_get_double_from_str ("100", &num) == TRUE);
./libmm-glib/tests/test-common-helpers.c:486:    g_assert (num - (100.0) < 0000000.1);
./libmm-glib/tests/test-common-helpers.c:488:    g_assert (mm_get_double_from_str ("100.7567", &num) == TRUE);
./libmm-glib/tests/test-common-helpers.c:489:    g_assert (num - (100.7567) < 0000000.1);
./libmm-glib/tests/test-common-helpers.c:491:    g_assert (mm_get_double_from_str ("100.7567\r\n", &num) == TRUE);
./libmm-glib/tests/test-common-helpers.c:492:    g_assert (num - (100.7567) < 0000000.1);
./libmm-glib/mm-modem.c:1264: * Gets the signal quality value in percent (0 - 100) of the dominant access
./libqcdm/tests/test-qcdm-com.c:819:    char buf[100];
./libqcdm/tests/test-qcdm-com.c:941:    char buf[100];
./libqcdm/tests/test-qcdm-com.c:985:    char buf[100];
./libqcdm/tests/test-qcdm-com.c:1130:    char buf[100];
./libqcdm/tests/test-qcdm-com.c:1258:    char buf[100];
./libqcdm/tests/test-qcdm-com.c:1671:    char buf[100];
./libqcdm/src/dm-commands.h:99:    DIAG_CMD_RPC               = 100, /* Used for RPC */
./libqcdm/src/dm-commands.h:477:    uint8_t data[100];     /* DMCmdSubsysNwSnapshotCdma */
./libqcdm/src/commands.c:620:    tmcc[2] = hmcc / 100;
./libqcdm/src/commands.c:621:    tmcc[1] = (hmcc - (tmcc[2] * 100)) / 10;
./libqcdm/src/commands.c:622:    tmcc[0] = (hmcc - (tmcc[2] * 100) - (tmcc[1] * 10));
./libqcdm/src/commands.c:624:    mcc = (100 * digit_fixup (tmcc[2])) + (10 * digit_fixup (tmcc[1])) + digit_fixup (tmcc[0]);
./libqcdm/src/commands.c:2077:        mcc = (rsp->lai[0] & 0xF) * 100;
./libqcdm/src/commands.c:2082:        mnc = (rsp->lai[2] & 0XF) * 100;
./data/ModemManager-logo-wide-text.svg:103:       gradientTransform="matrix(1.2781955,0,0,0.83050847,-876.89381,-100.54799)" />
./src/mm-shared-qmi.c:383:        if (mnc_pcs_digit && mnc < 100)
./src/mm-shared-qmi.c:454:    if (mnc_pcs_digit && mnc < 100)
./src/mm-modem-helpers.c:4467:    { 100, FALSE,  "Campus" },
./src/mm-modem-helpers.c:4997:    if (year < 100) {
./src/mm-modem-helpers-mbim.c:1024:        quality = MM_CLAMP_HIGH (rssi == 99 ? 0 : rssi, 31) * 100 / 31;
./src/mm-port-probe.c:1394:                          100,
./src/plugins/ublox/tests/test-modem-helpers-ublox.c:194:        .str = "+UIPADDR: 3,\"ccinet2\",\"5.10.100.2\",\"255.255.255.0\",\"2001::1:200:FF:FE00:0/64\",\"FE80::200:FF:FE00:0/64\"",
./src/plugins/ublox/tests/test-modem-helpers-ublox.c:197:        .ipv4_address = "5.10.100.2",
./src/plugins/ublox/tests/test-modem-helpers-ublox.c:908:        .str = "+UGCNTRD: 1, 100, 0, 100, 0",
./src/plugins/ublox/tests/test-modem-helpers-ublox.c:910:        .session_tx_bytes = 100,
./src/plugins/ublox/tests/test-modem-helpers-ublox.c:912:        .total_tx_bytes   = 100,
./src/plugins/ublox/tests/test-modem-helpers-ublox.c:924:        .str = "+UGCNTRD: 1, 100, 0, 100, 0\r\n"
./src/plugins/ublox/tests/test-modem-helpers-ublox.c:927:        .session_tx_bytes = 100,
./src/plugins/ublox/tests/test-modem-helpers-ublox.c:929:        .total_tx_bytes   = 100,
./src/plugins/ublox/tests/test-modem-helpers-ublox.c:933:        .str = "+UGCNTRD: 1, 100, 0, 100, 0\r\n"
./src/plugins/ublox/mm-modem-helpers-ublox.c:240:     * +UIPADDR: 3,"ccinet2","5.10.100.2","255.255.255.0","2001::1:200:FF:FE00:0/64","FE80::200:FF:FE00:0/64"
./src/plugins/ublox/README:32:            inet 192.168.1.100/24 brd 192.168.1.255 scope global dynamic usb0
./src/plugins/ublox/README:37:        192.168.1.0/24 dev usb0  proto kernel  scope link  src 192.168.1.100  metric 700
./src/plugins/iridium/mm-broadband-modem-iridium.c:148:        quality = CLAMP (quality, 0, 5) * 100 / 5;
./src/plugins/xmm/mm-modem-helpers-xmm.c:132:#define XACT_NUM_IS_BAND_3G(num) (num < 100)
./src/plugins/xmm/mm-modem-helpers-xmm.c:133:#define XACT_NUM_IS_BAND_4G(num) (num > 100 && num < 300)
./src/plugins/xmm/mm-modem-helpers-xmm.c:701:    if (rssnr_level <= 100 &&
./src/plugins/xmm/mm-modem-helpers-xmm.c:702:        rssnr_level >= -100) {
./src/plugins/option/mm-broadband-modem-option.c:817:        quality = MM_CLAMP_HIGH (quality, 31) * 100 / 31;
./src/plugins/via/mm-broadband-modem-via.c:280:        quality = MM_CLAMP_HIGH (quality, 100);
./src/plugins/cinterion/tests/test-modem-helpers-cinterion.c:416:        "^SCFG: \"RemoteWakeUp/Pulse\",(\"1\"-\"100\")\r\n"
./src/plugins/cinterion/mm-modem-helpers-cinterion.c:1402:    if (year < 100)
./src/plugins/cinterion/mm-shared-cinterion.c:641:#define GPS_COMMAND_TIMEOUT_DEFAULT_MS  100
./src/plugins/icera/mm-broadband-modem-icera.c:523:        rssi = CLAMP (rssi, 0, 5) * 100 / 5;
./src/plugins/icera/mm-broadband-modem-icera.c:1599:    if (year < 100)
./src/plugins/sierra/mm-broadband-modem-sierra.c:230:     * Temp: 33  State: 100  Sys Mode: NO SRV
./src/plugins/sierra/mm-broadband-modem-sierra.c:249:     * Temp: 39  State: 100  Scan Mode: 0
./src/plugins/mtk/mm-broadband-modem-mtk-legacy.c:515:        quality = MM_CLAMP_HIGH (quality, 31) * 100 / 31;
./src/plugins/mtk/mm-broadband-modem-mtk-legacy.c:534:        quality = MM_CLAMP_HIGH (quality, 63) * 100 / 63;
./src/plugins/mtk/mm-broadband-modem-mtk-legacy.c:550:    quality = MM_CLAMP_HIGH (quality, 96) * 100 / 96;
./src/plugins/mtk/mm-broadband-modem-mtk-legacy.c:566:    quality = MM_CLAMP_HIGH (quality, 97) * 100 / 97;
./src/plugins/simtech/mm-broadband-modem-simtech.c:154:        quality = MM_CLAMP_HIGH (quality, 31) * 100 / 31;
./src/plugins/simtech/mm-broadband-modem-simtech.c:823:            quality = CLAMP (quality, 0, 31) * 100 / 31;
./src/plugins/huawei/tests/test-modem-helpers-huawei.c:157:      "100.92.236.163", 29, "100.92.236.161", "10.177.0.34", "10.168.187.116" },
./src/plugins/huawei/tests/test-modem-helpers-huawei.c:159:      "100.92.236.163", 29, "100.92.236.161", "10.177.0.34", "10.168.187.116" },
./src/plugins/huawei/mm-broadband-modem-huawei.c:1525:        quality = MM_CLAMP_HIGH (quality, 31) * 100 / 31;
./src/plugins/huawei/mm-broadband-modem-huawei.c:2359:    quality = MM_CLAMP_HIGH (quality, 100);
./src/plugins/huawei/mm-broadband-modem-huawei.c:2374:    quality = MM_CLAMP_HIGH (quality, 100);
./src/plugins/huawei/mm-broadband-modem-huawei.c:2445:        quality = MM_CLAMP_HIGH (quality, 100);
./src/plugins/huawei/mm-modem-helpers-huawei.c:1231:        if (year < 100)
./src/plugins/huawei/mm-modem-helpers-huawei.c:1317:        if (year < 100)
./src/mm-broadband-modem-mbim.c:8415:                         100,
./src/tests/test-sms-part-cdma.c:570:#define MAX_TEXT_LEN 100
./src/tests/test-sms-part-3gpp.c:346:        " (PrePay: *100*1233#). Voicemail ontvangen is altijd gratis."
./src/tests/test-modem-helpers.c:1730:        "Revision: 11.100.17.00.114\n"
./src/tests/test-modem-helpers.c:1735:      "\n11.100.17.00.114\n",
./src/tests/test-modem-helpers.c:3167:    {"+CPMS: \"ME\",1,100,\"MT\",5,100,\"TA\",1,100", 2, 3},
./src/tests/test-modem-helpers.c:3168:    {"+CPMS: \"SM\",100,100,\"SR\",5,10,\"TA\",1,100", 1, 4},
./src/tests/test-modem-helpers.c:3169:    {"+CPMS: \"XX\",100,100,\"BM\",5,10,\"TA\",1,100", 0, 5},
./src/tests/test-modem-helpers.c:3170:    {"+CPMS: \"XX\",100,100,\"YY\",5,10,\"TA\",1,100", 0, 0},
./src/mm-iface-modem-3gpp-profile-manager.c:465:    /* If the profile is 100% equal to what we require, nothing to do */
./src/mm-modem-helpers.h:578:    (guint8)(100 - ((CLAMP (rssi, -113, -51) + 51) * 100 / (-113 + 51)))
./src/mm-modem-helpers.h:582:    (guint8)(100 - ((CLAMP (rsrp, -110, -60) + 60) * 100 / (-110 + 60)))
./src/mm-broadband-modem.c:2155:                quality = CLAMP (quality, 0, 31) * 100 / 31;
./src/mm-broadband-modem.c:2208:        return (quality <= 5) ? (quality * 20) : 100;
./src/mm-broadband-modem.c:2213:        return ((100 * (quality - min)) / (max - min));
./src/mm-broadband-modem.c:2354:        quality = (guint32) (100 - (best_db * 100 / (WORST_ECIO - BEST_ECIO)));
./src/mm-broadband-modem.c:11176:                          100,
./src/mm-broadband-modem-qmi.c:1426:    /* Valid nr5g signal quality will be in percentage [0,100].
./src/mm-broadband-modem-qmi.c:1471:                                       (guint8)((nr5g_rsrp - RSRP_MIN) * 100 / (RSRP_MAX - RSRP_MIN)));
./src/mm-broadband-modem-qmi.c:1477:                                       (guint8)((nr5g_snr - SNR_MIN) * 100 / (SNR_MAX - SNR_MIN)));
./src/mm-broadband-modem-qmi.c:1483:                                       (guint8)((nr5g_rsrq - RSRQ_MIN) * 100 / (RSRQ_MAX - RSRQ_MIN)));
./src/mm-broadband-modem-qmi.c:2904:# define DISABLE_FACILITY_LOCK_CHECK_TIMEOUT_MS 100
./src/mm-broadband-modem-qmi.c:3097:    /* Guess about MNC, if < 100 assume it's 2 digits, no PCS info here */
./src/mm-broadband-modem-qmi.c:3098:    if (element->mnc >= 100)
./src/mm-broadband-modem-qmi.c:3351:    if (mnc_pcs_digit && mnc < 100)
./src/mm-broadband-modem-qmi.c:3542:        if (mnc >= 100)
./src/mm-broadband-modem-qmi.c:5375:static const gint8 default_thresholds_data_dbm[] = { -100, -97, -95, -92, -90, -85, -80, -75, -70, -65 };
./src/mm-broadband-modem-qmi.c:6530:#define IGNORED_PROFILE_CHANGED_INDICATION_TIMEOUT_MS 100
./src/mm-broadband-modem-qmi.c:10158:            qmi_client_voice_originate_ussd (QMI_CLIENT_VOICE (client), input, 100, NULL,
./src/mm-broadband-modem-qmi.c:10168:            qmi_client_voice_answer_ussd (QMI_CLIENT_VOICE (client), input, 100, NULL,
./src/mm-broadband-modem-qmi.c:10244:    qmi_client_voice_cancel_ussd (QMI_CLIENT_VOICE (client), NULL, 100, NULL,
./src/mm-sms-part-cdma.c:143:    CAUSE_CODE_GENERAL_PROBLEM_SMS_NOT_SUPPORTED                   = 100,
./src/mm-iface-modem-simple.c:777:        g_timeout_add (100, (GSourceFunc)wait_after_enabled_ready, ctx);
./po/lt.po:20:"Plural-Forms: nplurals=3; plural=(n%10==1 && (n%100<11 || n%100>19) ? 0 : "
./po/lt.po:21:"n%10>=2 && n%10<=9 && (n%100<11 || n%100>19) ? 1 : 2);\n"
./po/pl.po:20:"Plural-Forms: nplurals=3; plural=(n==1 ? 0 : n%10>=2 && n%10<=4 && (n%100<10 "
./po/pl.po:21:"|| n%100>=20) ? 1 : 2);\n"
./po/uk.po:19:"Plural-Forms: nplurals=3; plural=(n%10==1 && n%100!=11 ? 0 : n%10>=2 && "
./po/uk.po:20:"n%10<=4 && (n%100<10 || n%100>=20) ? 1 : 2);\n"
./po/ru.po:19:"Plural-Forms: nplurals=3; plural=(n%10==1 && n%100!=11 ? 0 : n%10>=2 && "
./po/ru.po:20:"n%10<=4 && (n%100<10 || n%100>=20) ? 1 : 2);\n"
./include/ModemManager-enums.h:551:    MM_MODEM_BAND_EUTRAN_70 = 100,
./include/ModemManager-errors.h:373:    MM_MOBILE_EQUIPMENT_ERROR_UNKNOWN                                           = 100, /*< nick=Unknown >*/

foxsquirrel · January 22, 2024, 1:28pm

If you can track this stuff down, it should lead to the code that is actually creating the fault. Look for something with an “if” type statement with output/print statement containing those “#define”.

Search the source for “perror” since it shows an error.h header is included.