Quectel UC20: Correct way to get it up and running on embedded?

[Dan Williams]

On Wed, 2017-03-22 at 21:36 +0100, Einar Jón wrote:
> TLDR: I guess most of my problems are from calling ifup in the wrong
> state (CONNECTING instead of CONNECTED). More inline.
> I might bring some follow-up questions next week.

As you say below, I was wrong in the last mail because I assumed you
were calling ifup in CONNECTED state.  Calling it in CONNECTING state
caused the dhclient to show up in the logs in that state, which I
confused with an existing dhclient process.

So your last notes in the mail seem true to me.  Let us know if there
are more questions!

RE PolicyMismatch: we're not quite sure what that error represents;
we've determined that in some cases it means IPv4 vs. IPv6 mismatch and
profiles in the modem, but that doesn't seem to always be the case.

Dan

> On 20 March 2017 at 19:33, Dan Williams <dcbw at redhat.com> wrote:
> > On Mon, 2017-03-20 at 12:14 +0100, Einar Jón wrote:
> > > Hello,
> > > 
> > 
> > Let me preface my response by saying I have no idea what
> > ifup/ifdown do
> > on your platform, and whether they correctly handle teardown of the
> > interface and DHCP.
> > 
> > > Our main issues:
> > > Operstate seems to be always UNKNOWN
> > 
> > You can basically ignore operstate.  You care about interface flags
> > instead (UP, DOWN, LOWER_UP, etc).
> 
> I should have also mentioned that the interface flags are always UP,
> LOWER_UP with an operstate UNKNOWN. So ip addr/ifconfig is always the
> same for me.
> 
> When using the Quectel UC20 with ModemManager - no matter what the
> state is:
> $ ip a show dev wwan0
> 4: wwan0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast
> state UNKNOWN qlen 1000
>     link/ether 2a:eb:68:af:9e:1b brd ff:ff:ff:ff:ff:ff
>     inet6 fe80::28eb:68ff:feaf:9e1b/64 scope link
>        valid_lft forever preferred_lft forever
> 
> Different OS using the Quectel UC20 without ModemManager (Using
> custom
> C code with AT commands):
> $ ip a show dev wwan0
> 5: wwan0: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN group
> default qlen 1000
>     link/ether 0a:f6:61:71:71:e4 brd ff:ff:ff:ff:ff:ff
> $ sudo rild -q &  # this connects the modem
> [1] 1417
> $ ip a show dev wwan0
> 5: wwan0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast
> state UNKNOWN group default qlen 1000
>     link/ether 0a:f6:61:71:71:e4 brd ff:ff:ff:ff:ff:ff
>     inet XX.YY.153.249/30 brd XX.YY.153.251 scope global wwan0
>        valid_lft forever preferred_lft forever
> 
> > 
> > > "ip link set dev wwan0 up" and "ip link set dev wwan0 down" seem
> > > to
> > > do nothing.
> > 
> > Right.  That's normal Linux.  These set/clear the IFF_UP flag which
> > means "administratively up".  Which means that when the interface
> > is
> > UP, it can do IP and other stuff.  When it's down, it
> > can't.  That's
> > all.  It doesn't affect *what* addressing is done on the interface,
> > it's simply a pre-requisite for doing anything with the interface.
> 
> Good to know...
> 
> > > We need to reset the connection once a day (with mmcli --
> > > disable),
> > > because of external reasons.
> > 
> > I presume the provider terminates the packet data session after 24h
> > or
> > something like that?  Not uncommon.
> 
> Exactly why we need that.
> 
> > 
> > > This mostly works, but sometimes we lose connectivity after the
> > > reconnect.
> > > In those cases I have 2 IP addresses in the interface, and ip
> > > route
> > > tells me that both of them are gateways.
> > 
> > Since MM doesn't do any IP address setup/teardown on the interface
> > itself, I wouldn't expect '--disable' alone to clean anything
> > up.  When
> > disabling, you'll need to either have a process monitor the modem
> > state
> > and call "ifdown" or do some other kind of cleanup, or do the
> > ifdown
> > along with the --disable.
> > 
> > > "ifup wwan0 && ifdown wwan0" fixes the connection again without
> > > any
> > > action from the python script (this automatically starts a new
> > > dhclient and updates ip route).
> > > This seems to be just a timing issue, or a question of doing
> > > things
> > > in
> > > the right order.
> > 
> > The order would probably be to disconnect the bearer (mmcli -m X -b
> > Y
> > --disconnect), "ifdown wwan0", "mmcli -m X --disable".
> 
> That's worth a try.
> 
> > 
> > > My main questions:
> > > 1) what do I need to do to have a reliable connection?
> > 
> > That depends on quite a few things, many of them not ModemManager
> > related, so let's try to address them individually as they come up.
> > 
> > > 2) when do I need to do those things?
> > >   -  in what state should I call ifup ?
> > 
> > After the modem state becomes CONNECTED, or after the bearer
> > activation/connect returns successfully and you can retrieve the
> > bearer
> > IP details from MM.  CONNECTED state requires that the bearer
> > activation be successful, so if you see CONNECTED you should be
> > fine.
> > 
> > >   -  in what state should I call connect_bearer()? Any
> > > exceptions?
> > 
> > Bearer-interface specific operations require the modem to be in the
> > right state (eg, something like REGISTERED).  I would wait to
> > connect a
> > bearer until the modem has found the network and registered.
> 
> So CONNECTING is too soon.
> We currently try to connect_bearer when we reach REGISTERED. At least
> that's right...
> 
> > 
> > If you use the Simple interface instead, you can call
> > Simple.Connect()
> > at any time other than FAILED state, as the Simple interface will
> > do
> > everything it can to get connected, including enabling the modem,
> > waiting for registration, and then starting the bearer.  That could
> > take a few minutes, but it's meant as a dead-simple interface.
> 
> I would like to stick with what we have.
> 
> > 
> > > 3) I switch modem states really fast (from DISABLING to
> > > CONNECTING in
> > > under a second - see syslog below). Do some of these states need
> > > to
> > > wait a bit?
> > 
> > ModemManager won't return from the D-Bus requests for
> > disabling/enabling/connecting/etc until it's ready; if it does so
> > and
> > the modem hasn't fully entered that state, I'd consider it a bug.
> > 
> > But I don't think that's your problem, see below.
> 
> Probably just incorrect use.
> 
> > 
> > > 4) Is ModemManager 1.4.10 too old? Are there any major
> > > improvements
> > > I'm missing from staying on Ubuntu 12.04?
> > 
> > Obviously we always recommend the most recent released version
> > (currently 1.6.x) but I can't think of anything specific that 1.4.x
> > has
> > that you'd need in terms of bug fixes or features.
> 
> Good to know. Upgrading would be a pain.
> 
> > > NOTE: To find out the status of the connection, I check if the
> > > IfState
> > > is up or down (basically "grep wwan0  /run/network/ifstate"),
> > > instead
> > > of checking operstate (which is UNKNOWN no matter what I do).
> > > If ifstate is down I call "ifup wwan0" manually.
> > > When disconnecting (and on the pyhon startup), I call "ifdown
> > > wwan0"
> > > manually.
> > 
> > This could be part of the problem.  The network stack of your
> > distro
> > (especially ifup/ifdown) has literally no idea what state the modem
> > is
> > in.  There is no real connection between the modem firmware state
> > and
> > the Linux-side network interface; it's just a packet tunnel.  Its
> > Linux-side state doesn't represent anything about the data
> > connection
> > in the modem firmware itself.
> 
> Right. I as an admin have literally no idea what state the modem is
> in.
> So this seemed to make sense at the time.
> 
> > 
> > While perhaps unfortunate, there are various reasons why this is
> > the
> > case and I'm happy to explain further if you'd like.
> > 
> > The point being:
> > 
> > 1) when the modem enters the CONNECTED state, call "ifup wwan0"
> > 2) when the mode leaves the CONNECTED state, call "ifdown wwan0"
> > and
> > wait for that to complete before doing anything else
> 
> I guess I'm calling it too soon (in CONNECTING state), and I wait for
> ifup to finish before going to CONNECTED.
> This may be causing many of my issues.
> I did that because we have had a bearer_connect failure with
> PolicyMismatch that does an endless
> CONNECTING -> REGISTERED -> CONNECTING -> REGISTERED loop until the
> modem is reset.
> So I thought ifup would be needed for that.
> 
> > don't bother checking the existing ifup/ifdown state because it may
> > not
> > be accurate, because ifup/ifdown don't know anything about the
> > actual
> > modem state.
> 
> True. But it seems to be the only way to know if something is
> actually
> happening or not, since the
> And calling "ifdown wwan0; ifup wwan0" manually seems to fix the
> double IP issue.
> So it seemed like a good idea at the time.
> 
> > 
> > One last comment about the double-address thing; it's in the logs
> > below
> > but I'll say it here instead.
> > 
> > I don't think your process is waiting for "ifdown wwan0" to
> > complete
> > before attempting to re-enable the modem.  ifdown may take a short
> > period of time to clean things up, including letting DHCP release
> > the
> > address.
> > 
> > Mar 19 06:35:52 ifdown
> > Mar 19 06:35:52 re-enable
> > Mar 19 06:35:52 registered
> > Mar 19 06:35:53 dhclient is calling DISCOVER
> > Mar 19 06:36:53 dhclient gets a lease
> > Mar 19 06:37:16 ifup
> > Mar 19 06:37:17 finally CONNECTED state
> > 
> > I think the old dhclient process is sticking around requesting a
> > lease
> > long before you're at the point where you call 'ifup'.  I'd suggest
> > waiting until the 'ifdown' completes before re-enabling the modem.
> > That is likely where your duplicate addresses are coming from.
> 
> I don't think you are correct. What is actually happening:
> Mar 19 06:35:52 Modem state: CONNECTED -> DISABLING
> --- ifdown is called when we reach state DISABLING
> Mar 19 06:35:52 ifdown RETURNS and logs everything that happened
> since
> it was called
> Mar 19 06:35:52 Modem state: DISABLING -> DISABLED
> Mar 19 06:35:52 Modem state: DISABLED -> ENABLING
> Mar 19 06:35:52 Modem state: ENABLING -> REGISTERED
> Mar 19 06:35:52 Modem state: REGISTERED -> CONNECTING
> --- ifup is called when we reach state CONNECTING - this surely too
> soon
> Mar 19 06:35:53 dhclient is calling DISCOVER
> Mar 19 06:36:53 dhclient gets a lease
> Mar 19 06:37:16 ifup RETURNS and logs everything that happened since
> it was called at 06:35:52
> Mar 19 06:37:17 finally CONNECTED state
> -- I should be calling ifup here
> 
> Thanks for the detailed response.
> Einar
> 
> > 
> > Dan
> > 
> > > Relevant python code:
> > > def handle_modem_state(self, oldState, state):
> > >     logging.debug('Handle modem state, old: ' +
> > > self.modem_state_str(oldState) + ' new: ' +
> > > self.modem_state_str(state))
> > >     if state == ModemManager.ModemState.DISABLED:
> > >         self.enable_modem()     # calls modemProxy.Enable(1, ...)
> > >     elif state == ModemManager.ModemState.ENABLED:
> > >         self.register_modem()   # calls modemProxy.Register(...)
> > >     elif state == ModemManager.ModemState.SEARCHING:
> > >         pass
> > >     elif state == ModemManager.ModemState.REGISTERED:
> > >         if oldState != ModemManager.ModemState.CONNECTING and
> > > oldState
> > > != ModemManager.ModemState.DISCONNECTING:
> > >             self.connect_bearer()  # get bearer from DBUS and
> > > connect
> > >     elif state == ModemManager.ModemState.CONNECTED:
> > >         self.triedPreferredOperator = False
> > >     elif state == ModemManager.ModemState.CONNECTING:
> > >         if not self.is_network_interface_up('wwan0'): # check
> > > operstate/ifstate
> > >             self.set_network_state('wwan0', 'up')     # calls
> > > ifup
> > > wwan0 in a new process
> > >     elif state == ModemManager.ModemState.DISABLING:
> > >         if self.is_network_interface_up('wwan0'):     # check
> > > operstate/ifstate
> > >             self.set_network_state('wwan0', 'down')   # calls
> > > ifdown
> > > wwan0 in a new process
> > > 
> 
> ... snip ...
> 
> 
>