Using mikroe "LTE IoT Click" aka u-blox SARA-R410M-02B with native serial UART

[Alexander Dahl]

Hello Aleksander,

thanks for your quick reply, it put me on the right track end now I'm
stuck in a hardware problem again, at least it seems so. See below if
you're interested.

Am Wed, Apr 28, 2021 at 09:14:14PM +0200 schrieb Aleksander Morgado:
> > > That looks promising, I'll see if I can register to the network if the
> > > correct SIM cards arrive.
> >
> > I got the SIM cards now. Those are by German Telekom for business customers.
> > (German FAQ here: [1])
> >
> > Recap: the modem is a u-blox SARA-R410M-02B, and it's connected through the
> > serial UART only (NOT through USB), meaning only two pins, txd and rxd,
> > classical uart, 115200 baud, /dev/ttyAT2.
> >
> > I got ModemManager (1.16.4) to recognize the modem and this works:
> >
> >     mmcli -m 1 -e
> >     mmcli -m 1 --simple-connect='apn=iot.telekom.net'
> >     mmcli -m 1
> >
> 
> Nice!
> 
> > The modem is shown in connected state with reasonable operator id 26201 and
> > signal quality 80%. Debug log even shows an IP address (in 10.0.0.0/8), the
> > same as listed in the web portal of Deutsche Telekom, which also confirms
> > modem/sim are registered to the network. So far so good.
> >
> 
> Yes.

And when connected through USB to my Debian laptop I could actually
use the LTE module to connect to the internet and send an e-mail, so
the LTE module hardware itself is fine.  One piece less to worry about.

> 
> > However there's no network device listed, `ip addr show` shows only ethernet
> > and loopback.
> >
> 
> Yes, the next step would be to run pppd over the TTY. What
> ModemManager does is setting up the connection and putting the TTY in
> data mode instead of command (AT) mode. Once it's in data mode, pppd
> should take over.

There were quite a few parts missing in my software stack.  I had to
enable PPP in kernel, in NetworkManager and build pppd itself.
NetworkManager log was very clear about that, too.

> > In the hope NetworkManager (1.30.4) would create that device for me, I tried
> > to get a connection with NetworkManager like this:
> >
> >     nmcli connection add type gsm
> >     nmcli connection modify gsm apn iot.telekom.net
> >
> 
> That is fine, yes. NetworkManager can take care of the pppd setup once
> MM connects the modem.

It does, I got a ppp0 network device eventually.

> > And:
> >
> >     root at DistroKit:~ nmcli -a con up gsm
> >     Error: Connection activation failed: The base network connection was
> > interrupted
> 
> Ok, this may be because the modem was already in connected mode after
> your manual --simple-connect?
> Have you retried this but after fully power cycling the modem? If
> you're using NetworkManager, you should *not* do --simple-connect
> manually.

Yes I tried that, along with several other things, and it kind of
worked.

> >     Hint: use 'journalctl -xe NM_CONNECTION=0b5580ba-33f9-49f6-
> > bd17-33c14d38bb97 + NM_DEVICE=ttyAT2' to get more details.
> >
> > I had NetworkManager monitor on a second console in parallel, which gave this:
> >
> >     root at DistroKit:~ nmcli m
> >     ttyAT2: deactivating
> >     ttyAT2: disconnected
> >     ttyAT2: using connection 'gsm'
> >     ttyAT2: connecting (prepare)
> >     ttyAT2: unmanaged
> >     ttyAT2: device removed
> >
> > Now the interesting part, `journalctl -u ModemManager`:
> >
> > ```
> > Apr 27 14:49:46 DistroKit systemd[1]: Starting ModemManager.service...
> > Apr 27 14:49:47 DistroKit ModemManager[416]: <info>  ModemManager (version
> > 1.16.4) starting in system bus...
> > Apr 27 14:49:47 DistroKit systemd[1]: Started ModemManager.service.
> > Apr 27 14:49:50 DistroKit ModemManager[416]: <info>  [base-manager] couldn't
> > check support for device '/sys/devices/platform/ahb/ahb:apb/
> > f8008000.ethernet': not supported by any plugin
> > Apr 27 14:50:05 DistroKit ModemManager[416]: <info>  [device /sys/devices/
> > platform/ahb/ahb:apb/f8024000.serial/atmel_usart_serial.1.auto] creating modem
> > with plugin 'generic' and '1' ports
> > Apr 27 14:50:05 DistroKit ModemManager[416]: <warn>  [plugin/generic] could
> > not grab port ttyAT2: Cannot add port 'tty/ttyAT2', unhandled port type
> > Apr 27 14:50:05 DistroKit ModemManager[416]: <warn>  [base-manager] couldn't
> > create modem for device '/sys/devices/platform/ahb/ahb:apb/f8024000.serial/
> > atmel_usart_serial.1.auto': Failed to fi>
> > Apr 27 14:50:10 DistroKit ModemManager[416]: <info>  [base-manager] couldn't
> > check support for device '/sys/devices/platform/ahb/ahb:apb/
> > f8008000.ethernet': not supported by any plugin
> > Apr 27 14:50:25 DistroKit ModemManager[416]: <info>  [device /sys/devices/
> > platform/ahb/ahb:apb/f8024000.serial/atmel_usart_serial.1.auto] creating modem
> > with plugin 'generic' and '1' ports
> > Apr 27 14:50:25 DistroKit ModemManager[416]: <warn>  [plugin/generic] could
> > not grab port ttyAT2: Cannot add port 'tty/ttyAT2', unhandled port type
> > Apr 27 14:50:25 DistroKit ModemManager[416]: <warn>  [base-manager] couldn't
> > create modem for device '/sys/devices/platform/ahb/ahb:apb/f8024000.serial/
> > atmel_usart_serial.1.auto': Failed to fi>
> > Apr 27 14:50:50 DistroKit ModemManager[416]: <info>  [base-manager] couldn't
> > check support for device '/sys/devices/platform/ahb/ahb:apb/
> > f8008000.ethernet': not supported by any plugin
> > Apr 27 14:50:58 DistroKit ModemManager[416]: <info>  [device /sys/devices/
> > platform/ahb/ahb:apb/f8024000.serial/atmel_usart_serial.1.auto] creating modem
> > with plugin 'u-blox' and '1' ports
> > Apr 27 14:50:59 DistroKit ModemManager[416]: <info>  [base-manager] modem for
> > device '/sys/devices/platform/ahb/ahb:apb/f8024000.serial/atmel_usart_serial.
> > 1.auto' successfully created
> > Apr 27 14:50:59 DistroKit ModemManager[416]: <warn>  [modem2] (u-blox)
> > unexpected AcT value: 7
> > Apr 27 14:50:59 DistroKit ModemManager[416]: <warn>  [modem2] (u-blox)
> > unexpected AcT value: 8
> > Apr 27 14:50:59 DistroKit ModemManager[416]: <warn>  [modem2] couldn't load
> > supported modes: No combinations built from +URAT=? response
> > Apr 27 14:50:59 DistroKit ModemManager[416]: <warn>  [modem2] couldn't load
> > unlock retries: Unknown error
> > Apr 27 14:50:59 DistroKit ModemManager[416]: <warn>  [modem2/sim0] couldn't
> > load list of emergency numbers: uninitialized emergency numbers list
> > Apr 27 14:50:59 DistroKit ModemManager[416]: <warn>  [modem2] couldn't load
> > list of own numbers: Invalid characters in dial string
> > Apr 27 14:50:59 DistroKit ModemManager[416]: <warn>  [modem2] couldn't load
> > current bands: Unknown error
> > Apr 27 14:50:59 DistroKit ModemManager[416]: <info>  [modem2] state changed
> > (unknown -> disabled)
> > Apr 27 14:50:59 DistroKit ModemManager[416]: <info>  [modem2] state changed
> > (disabled -> enabling)
> > Apr 27 14:51:00 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > started...
> > Apr 27 14:51:00 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > state (4/8): wait to get fully enabled
> > Apr 27 14:51:00 DistroKit ModemManager[416]: <info>  [modem2] 3GPP
> > registration state changed (unknown -> idle)
> > Apr 27 14:51:00 DistroKit ModemManager[416]: <info>  [modem2] state changed
> > (enabling -> enabled)
> > Apr 27 14:51:00 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > state (5/8): register
> > Apr 27 14:51:00 DistroKit ModemManager[416]: <info>  [modem2] 3GPP
> > registration state changed (idle -> registering)
> > Apr 27 14:51:00 DistroKit ModemManager[416]: <info>  [modem2] 3GPP
> > registration state changed (registering -> roaming)
> > Apr 27 14:51:00 DistroKit ModemManager[416]: <info>  [modem2] state changed
> > (enabled -> registered)
> > Apr 27 14:51:00 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > state (6/8): bearer
> > Apr 27 14:51:01 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > state (7/8): connect
> > Apr 27 14:51:01 DistroKit ModemManager[416]: <info>  [modem2] state changed
> > (registered -> connecting)
> > Apr 27 14:51:01 DistroKit ModemManager[416]: <info>  [modem2] state changed
> > (connecting -> connected)
> > Apr 27 14:51:01 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > state (8/8): all done
> > Apr 27 14:51:06 DistroKit ModemManager[416]: <warn>  [modem2] couldn't load
> > network timezone from the current network
> > Apr 27 14:51:12 DistroKit ModemManager[416]: <info>  [base-manager] couldn't
> > check support for device '/sys/devices/platform/ahb/ahb:apb/
> > f8008000.ethernet': not supported by any plugin
> > Apr 27 14:55:36 DistroKit ModemManager[416]: <info>  [modem2] state changed
> > (connected -> disconnecting)
> 
> Is this log from your manual test in which you connected with
> --simple-connect and then you tried with NetworkManager?

I don't recall exactly, but I think it could not have worked anyways,
because PPP was not yet enabled in kernel config.

> > Apr 27 14:55:45 DistroKit ModemManager[416]: <warn>  [modem2] port ttyAT2
> > timed out 2 consecutive times
> > Apr 27 14:55:48 DistroKit ModemManager[416]: <warn>  [modem2] port ttyAT2
> > timed out 3 consecutive times
> > Apr 27 14:55:51 DistroKit ModemManager[416]: <warn>  [modem2] port ttyAT2
> > timed out 4 consecutive times
> > Apr 27 14:55:54 DistroKit ModemManager[416]: <warn>  [modem2] port ttyAT2
> > timed out 5 consecutive times
> > Apr 27 14:56:04 DistroKit ModemManager[416]: <info>  [modem2] state changed
> > (disconnecting -> registered)
> > Apr 27 14:56:04 DistroKit ModemManager[416]: <info>  [modem2/bearer0]
> > connection #1 finished: duration 302s, tx: 0 bytes, rx :0 bytes
> > Apr 27 14:56:04 DistroKit ModemManager[416]: <warn>  [modem2] port ttyAT2
> > timed out 6 consecutive times
> > Apr 27 14:56:04 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > started...
> > Apr 27 14:56:04 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > state (4/8): wait to get fully enabled
> > Apr 27 14:56:04 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > state (5/8): register
> > Apr 27 14:56:04 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > state (6/8): bearer
> > Apr 27 14:56:04 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > state (7/8): connect
> > Apr 27 14:56:04 DistroKit ModemManager[416]: <info>  [modem2] state changed
> > (registered -> connecting)
> > Apr 27 14:56:09 DistroKit ModemManager[416]: <warn>  [modem2] port ttyAT2
> > timed out 7 consecutive times
> > Apr 27 14:56:12 DistroKit ModemManager[416]: <warn>  [modem2] port ttyAT2
> > timed out 8 consecutive times
> > Apr 27 14:56:15 DistroKit ModemManager[416]: <warn>  [modem2] port ttyAT2
> > timed out 9 consecutive times
> > Apr 27 14:56:18 DistroKit ModemManager[416]: <warn>  [modem2/bearer0] couldn't
> > initialize context: Serial command timed out
> > Apr 27 14:56:18 DistroKit ModemManager[416]: <warn>  [modem2/bearer0]
> > connection attempt #2 failed: Serial command timed out
> > Apr 27 14:56:18 DistroKit ModemManager[416]: <info>  [modem2] state changed
> > (connecting -> registered)
> > Apr 27 14:56:18 DistroKit ModemManager[416]: <info>  [modem2/bearer0]
> > connection #2 finished: duration 0s, tx: 0 bytes, rx :0 bytes
> > Apr 27 14:56:18 DistroKit ModemManager[416]: <error> [modem2] port ttyAT2
> > timed out 10 consecutive times, marking modem as invalid
> 
> Yes, after 10 consecutive timeouts we mark the modem as invalid. And
> this is actually very important in your usecase, because we have no
> way to detect when the modem is no longer there in the pure RS232 line
> (i.e. the TTY always exists in the system even if there is no modem at
> the other end of the TX/RX lines).
> 
> What happened here is, I think, that the modem is in data mode and
> we're trying to send commands to it, and I don't know how much of that
> is due to your initial test with --simple-connect.
> 
> > Apr 27 14:56:18 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > started...
> > Apr 27 14:56:18 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > state (4/8): wait to get fully enabled
> > Apr 27 14:56:18 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > state (5/8): register
> > Apr 27 14:56:18 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > state (6/8): bearer
> > Apr 27 14:56:18 DistroKit ModemManager[416]: <info>  [modem2] simple connect
> > state (7/8): connect
> > Apr 27 14:56:18 DistroKit ModemManager[416]: <info>  [modem2] state changed
> > (registered -> connecting)
> > Apr 27 14:56:18 DistroKit ModemManager[416]: <warn>  [modem2/bearer1]
> > connection attempt #1 failed: Operation was cancelled
> > Apr 27 14:56:18 DistroKit ModemManager[416]: <info>  [modem2/bearer1]
> > connection #1 finished: duration 0s, tx: 0 bytes, rx :0 bytes
> > ```
> >
> > From my naïve understanding, commands and data stream have to be multiplexed
> > over the same serial uart, right? Is it a problem of ModemManager or
> > NetworkManager?
> 
> We don't support that multiplexing over the single UART :/ That's
> called CMUX, and we never got around to supporting it in MM (it's
> never too late!). In MM if you have one single TTY, you need to switch
> that TTY between command and data modes, so while connected you won't
> be able to send AT commands.

We are talking about the same thing here.  Switching between different
modes is what I meant, I was not aware of any special multiplexing
features.  If pppd can take care, fine.

> >
> > I have not much experience with these kinds of devices, so each hint to
> > proceed would be helpful. I can build and run MM and NM from source, even most
> > recent master. I can provide debug logs. I would provide patches, but
> > currently I don't even know where to start. O:-)
> >
> > Is there a way to get this modem running on Linux over that single UART at
> > all?
> 
> Oh yes yes, this should be no problem. Also, make sure you have the
> correct expected flow control settings configured via udev tags, not
> sure if you did that.

There are no hardware flow control lines connected, just TX and RX,
the kernel should know already, because I did not configure any rts,
cts, or other lines in device tree for this serial port.

I'll go try to find out how to put this into the udev rule, maybe
someone has a hint?  I saw one could set options in pppd config, but I
have none on the system and I suppose NetworkManager generates a
matching one on the fly?  NetworkManager has options for that like
ppp.crtscts and that's default false, so I guess in my case it should
just work.

Long story short, I made it to a ppp0 device:

3: ppp0: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UNKNOWN group default qlen 3
    link/ppp
    inet 10.***.***.*/32 scope global noprefixroute ppp0
       valid_lft forever preferred_lft forever

And seconds after that, the system freezes.  I currently test on a
(modified) Microchip SAMA5D27-SOM1-EK1 board, an evualuation kit for
the SAMA5D27 SoC, a single board computer.  Serial console freezes,
ssh connections stall, heartbeat LED goes off, no way to get any log
output anymore.  I can only press the reset button. :-/

I'll try on a different hardware.  Thanks for reading and for your
support. :-)

Greets
Alex