RE: Using u-blox TOBY-R200, ModemManager not detecting already registered with network

2018-02-08 Thread Matthew Starr
Aleksander,

Unfortunately changing the settings does not resolve the exact issue I have.  
The issue I have is that ModemManager is not waiting for the TOBY R200 modem to 
auto register itself and instead is telling the modem to reregister with the 
network right before the modem finishes its auto registration.  This causes the 
modem to take about 70-90 seconds to reregister with the network.  The default 
number of retries to get the connection to complete seems to be fine in my 
situation as I only see NetworkManager try once to connect and it eventually 
connects after the delay caused by ModemManager.

Best regards,
 
Matthew Starr


> -Original Message-
> From: Aleksander Morgado [mailto:aleksan...@aleksander.es]
> Sent: Wednesday, February 07, 2018 2:01 PM
> To: Matthew Starr
> Cc: Dan Williams; modemmanager-devel@lists.freedesktop.org
> Subject: Re: Using u-blox TOBY-R200, ModemManager not detecting already
> registered with network
> 
> >
> > There is still an issue that exists where if the GSM connection in
> NetworkManager is setup for "connection.autoconnect yes".  At boot it the
> GSM connection now takes 70-90 seconds to connect after the start of trying,
> which is 1.5 to 2 times as long as it used to be.  It looks like 
> NetworkManager
> is requesting the connection up before the initial modem registration on
> the network and this is causing the delay that was seen always before your
> patch.  Is there any way to force NetworkManager to wait for just the GSM
> connection or to have ModemManager wait for auto registration before
> continuing with the Registration step?
> 
> I may have seen this just yesterday myself doing some tests. I got a quick
> workaround just by letting NetworkManager retry indefinitely until a
> connection was done, with "autoconnect-retries=0" (in addition to
> autoconnect=true). Otherwise, NM was trying 3 or 4 quick attempts, all
> failing, and then it would wait a long time before retrying again, which is
> when it succeeded.
> 
> That said, this is something to fix somewhere in MM or NM. The connection
> attempt using Simple.Connect() as NM does should wait for the modem to
> get fully enabled and registered, it shouldn't blindly error out quickly, 
> which
> is what I believe it was doing.
> 
> --
> Aleksander
> https://aleksander.es
___
ModemManager-devel mailing list
ModemManager-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel


Re: Using u-blox TOBY-R200, ModemManager not detecting already registered with network

2018-02-07 Thread Aleksander Morgado
>
> There is still an issue that exists where if the GSM connection in 
> NetworkManager is setup for "connection.autoconnect yes".  At boot it the GSM 
> connection now takes 70-90 seconds to connect after the start of trying, 
> which is 1.5 to 2 times as long as it used to be.  It looks like 
> NetworkManager is requesting the connection up before the initial modem 
> registration on the network and this is causing the delay that was seen 
> always before your patch.  Is there any way to force NetworkManager to wait 
> for just the GSM connection or to have ModemManager wait for auto 
> registration before continuing with the Registration step?

I may have seen this just yesterday myself doing some tests. I got a
quick workaround just by letting NetworkManager retry indefinitely
until a connection was done, with "autoconnect-retries=0" (in addition
to autoconnect=true). Otherwise, NM was trying 3 or 4 quick attempts,
all failing, and then it would wait a long time before retrying again,
which is when it succeeded.

That said, this is something to fix somewhere in MM or NM. The
connection attempt using Simple.Connect() as NM does should wait for
the modem to get fully enabled and registered, it shouldn't blindly
error out quickly, which is what I believe it was doing.

-- 
Aleksander
https://aleksander.es
___
ModemManager-devel mailing list
ModemManager-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel


RE: Using u-blox TOBY-R200, ModemManager not detecting already registered with network

2018-02-07 Thread Matthew Starr
> 
> Try this patch instead...
> 
> Dan
> 
> ---
>  src/mm-iface-modem-3gpp.c | 28 +++-
>  1 file changed, 15 insertions(+), 13 deletions(-)
> 
> diff --git a/src/mm-iface-modem-3gpp.c b/src/mm-iface-modem-3gpp.c
> index baf743fb..77b502c0 100644
> --- a/src/mm-iface-modem-3gpp.c
> +++ b/src/mm-iface-modem-3gpp.c
> @@ -119,6 +119,13 @@ get_registration_state_context
> (MMIfaceModem3gpp *self)
>  return ctx;
>  }
> 
> +static gboolean
> +reg_state_is_registered (MMModem3gppRegistrationState state) {
> +return state == MM_MODEM_3GPP_REGISTRATION_STATE_HOME ||
> +state == MM_MODEM_3GPP_REGISTRATION_STATE_ROAMING;
> +}
> +
>  static MMModem3gppRegistrationState
>  get_consolidated_reg_state (RegistrationStateContext *ctx)  { @@ -268,8
> +275,7 @@ run_registration_checks_ready (MMIfaceModem3gpp *self,
>  }
> 
>  /* If we got registered, end registration checks */
> -if (current_registration_state ==
> MM_MODEM_3GPP_REGISTRATION_STATE_HOME ||
> -current_registration_state ==
> MM_MODEM_3GPP_REGISTRATION_STATE_ROAMING) {
> +if (reg_state_is_registered (current_registration_state)) {
>  /* Request immediate access tech update */
>  mm_iface_modem_refresh_access_technologies (MM_IFACE_MODEM
> (ctx->self));
>  mm_dbg ("Modem is currently registered in a 3GPP network"); @@ -
> 391,9 +397,11 @@ mm_iface_modem_3gpp_register_in_network
> (MMIfaceModem3gpp *self,
>  }
>  /* Automatic registration requested? */
>  else {
> +MMModem3gppRegistrationState reg_state =
> + mm_gdbus_modem3gpp_get_registration_state (ctx->skeleton);
> +
>  /* If the modem is already registered and the last time it was asked
>   * automatic registration, we're done */
> -if (current_operator_code &&
> +if ((current_operator_code || reg_state_is_registered
> + (reg_state)) &&
>  !registration_state_context->manual_registration) {
>  mm_dbg ("Already registered in network '%s',"
>  " automatic registration not launched...", @@ -1033,9 
> +1041,7 @@
> mm_iface_modem_3gpp_update_access_technologies
> (MMIfaceModem3gpp *self,
> 
>  /* Even if registration state didn't change, report access technology,
>   * but only if something valid to report */
> -if (state == MM_MODEM_3GPP_REGISTRATION_STATE_HOME ||
> -state == MM_MODEM_3GPP_REGISTRATION_STATE_ROAMING ||
> -ctx->reloading_registration_info) {
> +if (reg_state_is_registered (state) ||
> + ctx->reloading_registration_info) {
>  if (access_tech != MM_MODEM_ACCESS_TECHNOLOGY_UNKNOWN)
>  mm_iface_modem_update_access_technologies (MM_IFACE_MODEM
> (self),
> access_tech, @@ 
> -1068,9 +1074,7 @@
> mm_iface_modem_3gpp_update_location (MMIfaceModem3gpp *self,
>   * location updates, but only if something valid to report. For the case
>   * where we're registering (loading current registration info after a 
> state
>   * change to registered), we also allow LAC/CID updates. */
> -if (ctx->reloading_registration_info ||
> -state == MM_MODEM_3GPP_REGISTRATION_STATE_HOME ||
> -state == MM_MODEM_3GPP_REGISTRATION_STATE_ROAMING) {
> +if (reg_state_is_registered (state) ||
> + ctx->reloading_registration_info) {
>  if (location_area_code > 0 && cell_id > 0)
>  mm_iface_modem_location_3gpp_update_lac_ci
> (MM_IFACE_MODEM_LOCATION (self),
>  location_area_code, 
> @@ -1122,8 +1126,7 @@
> update_non_registered_state (MMIfaceModem3gpp *self,
>   * sent by the carrier during registration or b) by looking at the
>   * registration reject error code.  If b), we want to make sure we
>   * preserve the subscription state */
> -if (old_state == MM_MODEM_3GPP_REGISTRATION_STATE_HOME ||
> -old_state == MM_MODEM_3GPP_REGISTRATION_STATE_ROAMING)
> +if (reg_state_is_registered (old_state))
>  clear_subscription_state (self);
> 
>  /* The property in the interface is bound to the property @@ -1160,8
> +1163,7 @@ update_registration_state (MMIfaceModem3gpp *self,
>  if (new_state == old_state)
>  return;
> 
> -if (new_state == MM_MODEM_3GPP_REGISTRATION_STATE_HOME ||
> -new_state == MM_MODEM_3GPP_REGISTRATION_STATE_ROAMING) {
> +if (reg_state_is_registered (new_state)) {
>  /* If already reloading registration info, skip it */
>  if (ctx->reloading_registration_info)
>  return;
> --
> 2.14.3

Dan

The patch was somewhat mangled by the email client, but I fixed it.  This seems 
to have fixed the issue when manually starting the connection after 
ModemManager has already successfully registered the modem. I am connecting and 
obtaining an IP address on the cell connection within 3 seconds in this 
situation.

There is still an issue that 

Re: Using u-blox TOBY-R200, ModemManager not detecting already registered with network

2018-02-06 Thread Dan Williams
Try this patch instead...

Dan

---
 src/mm-iface-modem-3gpp.c | 28 +++-
 1 file changed, 15 insertions(+), 13 deletions(-)

diff --git a/src/mm-iface-modem-3gpp.c b/src/mm-iface-modem-3gpp.c
index baf743fb..77b502c0 100644
--- a/src/mm-iface-modem-3gpp.c
+++ b/src/mm-iface-modem-3gpp.c
@@ -119,6 +119,13 @@ get_registration_state_context (MMIfaceModem3gpp *self)
 return ctx;
 }
 
+static gboolean
+reg_state_is_registered (MMModem3gppRegistrationState state)
+{
+return state == MM_MODEM_3GPP_REGISTRATION_STATE_HOME ||
+state == MM_MODEM_3GPP_REGISTRATION_STATE_ROAMING;
+}
+
 static MMModem3gppRegistrationState
 get_consolidated_reg_state (RegistrationStateContext *ctx)
 {
@@ -268,8 +275,7 @@ run_registration_checks_ready (MMIfaceModem3gpp *self,
 }
 
 /* If we got registered, end registration checks */
-if (current_registration_state == MM_MODEM_3GPP_REGISTRATION_STATE_HOME ||
-current_registration_state == 
MM_MODEM_3GPP_REGISTRATION_STATE_ROAMING) {
+if (reg_state_is_registered (current_registration_state)) {
 /* Request immediate access tech update */
 mm_iface_modem_refresh_access_technologies (MM_IFACE_MODEM 
(ctx->self));
 mm_dbg ("Modem is currently registered in a 3GPP network");
@@ -391,9 +397,11 @@ mm_iface_modem_3gpp_register_in_network (MMIfaceModem3gpp 
*self,
 }
 /* Automatic registration requested? */
 else {
+MMModem3gppRegistrationState reg_state = 
mm_gdbus_modem3gpp_get_registration_state (ctx->skeleton);
+
 /* If the modem is already registered and the last time it was asked
  * automatic registration, we're done */
-if (current_operator_code &&
+if ((current_operator_code || reg_state_is_registered (reg_state)) &&
 !registration_state_context->manual_registration) {
 mm_dbg ("Already registered in network '%s',"
 " automatic registration not launched...",
@@ -1033,9 +1041,7 @@ mm_iface_modem_3gpp_update_access_technologies 
(MMIfaceModem3gpp *self,
 
 /* Even if registration state didn't change, report access technology,
  * but only if something valid to report */
-if (state == MM_MODEM_3GPP_REGISTRATION_STATE_HOME ||
-state == MM_MODEM_3GPP_REGISTRATION_STATE_ROAMING ||
-ctx->reloading_registration_info) {
+if (reg_state_is_registered (state) || ctx->reloading_registration_info) {
 if (access_tech != MM_MODEM_ACCESS_TECHNOLOGY_UNKNOWN)
 mm_iface_modem_update_access_technologies (MM_IFACE_MODEM (self),
access_tech,
@@ -1068,9 +1074,7 @@ mm_iface_modem_3gpp_update_location (MMIfaceModem3gpp 
*self,
  * location updates, but only if something valid to report. For the case
  * where we're registering (loading current registration info after a state
  * change to registered), we also allow LAC/CID updates. */
-if (ctx->reloading_registration_info ||
-state == MM_MODEM_3GPP_REGISTRATION_STATE_HOME ||
-state == MM_MODEM_3GPP_REGISTRATION_STATE_ROAMING) {
+if (reg_state_is_registered (state) || ctx->reloading_registration_info) {
 if (location_area_code > 0 && cell_id > 0)
 mm_iface_modem_location_3gpp_update_lac_ci 
(MM_IFACE_MODEM_LOCATION (self),
 location_area_code,
@@ -1122,8 +1126,7 @@ update_non_registered_state (MMIfaceModem3gpp *self,
  * sent by the carrier during registration or b) by looking at the
  * registration reject error code.  If b), we want to make sure we
  * preserve the subscription state */
-if (old_state == MM_MODEM_3GPP_REGISTRATION_STATE_HOME ||
-old_state == MM_MODEM_3GPP_REGISTRATION_STATE_ROAMING)
+if (reg_state_is_registered (old_state))
 clear_subscription_state (self);
 
 /* The property in the interface is bound to the property
@@ -1160,8 +1163,7 @@ update_registration_state (MMIfaceModem3gpp *self,
 if (new_state == old_state)
 return;
 
-if (new_state == MM_MODEM_3GPP_REGISTRATION_STATE_HOME ||
-new_state == MM_MODEM_3GPP_REGISTRATION_STATE_ROAMING) {
+if (reg_state_is_registered (new_state)) {
 /* If already reloading registration info, skip it */
 if (ctx->reloading_registration_info)
 return;
-- 
2.14.3
___
ModemManager-devel mailing list
ModemManager-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel


Re: Using u-blox TOBY-R200, ModemManager not detecting already registered with network

2018-02-05 Thread Dan Williams
On Mon, 2018-02-05 at 17:47 +, Matthew Starr wrote:
> > On Mon, 2018-02-05 at 15:45 +, Matthew Starr wrote:
> > > > On Thu, 2018-02-01 at 22:09 +, Matthew Starr wrote:
> > > > > I am using a TOBY-R200 which does not support USB Ethernet
> > > > > like
> > > > > TOBY-
> > > > > L2 models, but only supports AT interface over USB
> > > > > serial.  When I
> > > > > use a NetworkManager profile to start a 3G/4G connection
> > > > > using
> > > > > ModemManager with the TOBY-R200, the registration step takes
> > > > > a
> > > > > long time (~37 seconds).  The modem does eventually connect
> > > > > and
> > > > > everything work, but it takes too long for my use case.  When
> > > > > I
> > > > > use a u-blox LISA
> > > > > U230 modem with the same software configuration, hardware
> > > > > platform, and SIM card, I get a connection quickly (~5
> > > > > second).
> > > > > When I put ModemManager in debug mode there is a difference
> > > > > in the
> > > > > connection between the two at the registration step as shown
> > > > > below. I have the same issue on ModemManager versions 1.4.14,
> > > > > 1.6.4, and 1.6.12.
> > > > 
> > > > 
> > > > 
> > > > > On the TOBY R200, instead of realizing that the modem is
> > > > > already
> > > > > registered with the network, it runs AT+COPS=0 to reregister
> > > > > with
> > > > > the network.  I confirmed that the modem registered with the
> > > > > network by checking the AT+CREG?, AT+CEREG?, and AT+CGREG?
> > > > > commands.  Here is what ModemManager is outputting when
> > 
> > connecting
> > > > > to the network:
> > > > 
> > > > Do you see this line at all?
> > > > 
> > > > Modem XXX: 3GPP Registration state changed (XXX -> registering)
> > > > 
> > > > Basically, right after enabling the modem, ModemManager should
> > > > be
> > > > running initial registration checks.  That will run a sequence
> > > > of
> > > > AT+CREG?, AT+CGREG?, and AT+CEREG? requests which should report
> > > > the
> > > > operator ID (eg MCC/MNC).  This should all happen before the
> > > > connect, but perhaps the NM connect request is happening to
> > > > quickly.
> > > 
> > > I see that line and waited until that line was output to command
> > > Network Manager to bring up the GSM connection. See log below
> > > 
> > > > 
> > > > Can you include a bit more of the ModemManager debug output
> > > > from
> > 
> > the
> > > > time the modem is "enabling" until what you show below?
> > 
> > Thanks; this is a bug in ModemManager but also odd behavior in the
> > modem.  This could actually be triggered by your SIM though, given
> > the
> > description of the TOBY-R2 series response to the +COPS command in
> > ublox
> > document UBX-13002752 (R56).  Anyway:
> > 
> > (ttyACM1): <-- '+CGREG:
> > 1,"","",6,"6C"+CIEV:
> > 9,2+CEREG: 4'
> > (ttyACM0): --> 'AT+COPS=3,2;+COPS?'
> > (ttyACM0): <-- '+COPS: 0OK'
> > modem_3gpp_load_operator_name(): loading Operator Name...
> > (ttyACM0): --> 'AT+COPS=3,0;+COPS?'
> > (ttyACM0): <-- '+COPS: 0OK'
> > 
> > Here MM is requesting the "set format only" COPS response, then
> > asking for
> > the current operator name and number.  The modem replies with "0"
> > both times; usually devices are supposed to reply with the MCC/MNC
> > and
> > the operator name.  Might be worth asking ublox why the device
> > responds
> > this way, but again it could be due to the SIM card.
> > 
> > Anyway, the modem just isn't giving us any information about the
> > MCC/MNC and operator name, despite the fact that it's registered
> > with the
> > network and must already know these things.  But MM currently looks
> > to
> > see if it has a valid operator MCC/MNC before short-circuiting the
> > automatic
> > registration AT+COPS=0 that you're running into.
> > 
> > Could you try patch below and see if that makes things work better?
> > (Attached too just in case my mailer screws up the formatting...)
> > 
> > Dan
> > 
> 
> What version of ModemManager is that patch for?  I tried to apply it
> to version 1.6.12 (the newest version I have) and it failed on
> several hunks.

Was for git master, I'll do a backport to 1.6.12 for you tomorrow.

Dan
___
ModemManager-devel mailing list
ModemManager-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel


Re: Using u-blox TOBY-R200, ModemManager not detecting already registered with network

2018-02-01 Thread Dan Williams
On Thu, 2018-02-01 at 22:09 +, Matthew Starr wrote:
> I am using a TOBY-R200 which does not support USB Ethernet like TOBY-
> L2 models, but only supports AT interface over USB serial.  When I
> use a NetworkManager profile to start a 3G/4G connection using
> ModemManager with the TOBY-R200, the registration step takes a long
> time (~37 seconds).  The modem does eventually connect and everything
> work, but it takes too long for my use case.  When I use a u-blox
> LISA U230 modem with the same software configuration, hardware
> platform, and SIM card, I get a connection quickly (~5 second).  When
> I put ModemManager in debug mode there is a difference in the
> connection between the two at the registration step as shown below. I
> have the same issue on ModemManager versions 1.4.14, 1.6.4, and
> 1.6.12.



> On the TOBY R200, instead of realizing that the modem is already
> registered with the network, it runs AT+COPS=0 to reregister with the
> network.  I confirmed that the modem registered with the network by
> checking the AT+CREG?, AT+CEREG?, and AT+CGREG? commands.  Here is
> what ModemManager is outputting when connecting to the network:
 
Do you see this line at all?

Modem XXX: 3GPP Registration state changed (XXX -> registering)

Basically, right after enabling the modem, ModemManager should be
running initial registration checks.  That will run a sequence of
AT+CREG?, AT+CGREG?, and AT+CEREG? requests which should report the
operator ID (eg MCC/MNC).  This should all happen before the connect,
but perhaps the NM connect request is happening to quickly.

Can you include a bit more of the ModemManager debug output from the
time the modem is "enabling" until what you show below?

Dan

> Feb 18 17:32:29 canect2 daemon.info NetworkManager[307]:   [-
> 185178451.8116] device (ttyACM0): Activation: starting connection
> 'Aeris' (83187ceb-ad3a-4af8-92d8-7a255d9c5e3f)
> Feb 18 17:32:29 canect2 daemon.info NetworkManager[307]:   [-
> 185178451.8155] audit: op="connection-activate" uuid="83187ceb-ad3a-
> 4af8-92d8-7a255d9c5e3f" name="Aeris" pid=1021 uid=0 result="success"
> Feb 18 17:32:29 canect2 daemon.info NetworkManager[307]:   [-
> 185178451.8230] device (ttyACM0): state change: disconnected ->
> prepare (reason 'none') [30 40 0]
> Feb 18 17:32:29 canect2 daemon.info NetworkManager[307]:   [-
> 185178451.8302] manager: NetworkManager state is now CONNECTING
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:   [-
> 185178451.838433] [mm-iface-modem-simple.c:641] connect_auth_ready():
> Simple connect started...
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:  [-
> 185178451.838916] [mm-iface-modem-simple.c:651]
> connect_auth_ready():PIN: unspecified
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:  [-
> 185178451.839073] [mm-iface-modem-simple.c:653]
> connect_auth_ready():Operator ID: unspecified
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:  [-
> 185178451.839171] [mm-iface-modem-simple.c:655]
> connect_auth_ready():Allowed roaming: yes
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:  [-
> 185178451.839254] [mm-iface-modem-simple.c:657]
> connect_auth_ready():APN: iot.aer.net
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:  [-
> 185178451.839353] [mm-iface-modem-simple.c:662]
> connect_auth_ready():IP family: ipv4v6
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:  [-
> 185178451.839440] [mm-iface-modem-simple.c:673]
> connect_auth_ready():Allowed authentication: unspecified
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:  [-
> 185178451.839522] [mm-iface-modem-simple.c:675]
> connect_auth_ready():User: unspecified
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:  [-
> 185178451.839602] [mm-iface-modem-simple.c:677]
> connect_auth_ready():Password: unspecified
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:  [-
> 185178451.839679] [mm-iface-modem-simple.c:679]
> connect_auth_ready():Number: *99#
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:   [-
> 185178451.839743] [mm-iface-modem-simple.c:469] connection_step():
> Simple connect state (4/8): Wait to get fully enabled
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:   [-
> 185178451.840022] [mm-iface-modem-simple.c:478] connection_step():
> Simple connect state (5/8): Register
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:  [-
> 185178451.840252] [mm-iface-modem-3gpp.c:407]
> mm_iface_modem_3gpp_register_in_network(): Launching automatic
> network registration...
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:  [-
> 185178451.841569] [mm-port-serial.c:1296] mm_port_serial_open():
> (ttyACM0) device open count is 2 (open)
> Feb 18 17:32:29 canect2 daemon.info ModemManager[300]:  [-
> 185178451.842205] [mm-port-serial-at.c:460] debug_log(): (ttyACM0):
> --> 'AT+COPS=0'
> Feb 18 17:32:42 canect2 user.alert kernel: [ 1806.015885] wlan: mlan0
> START SCAN
> Feb 18 17:32:44 canect2 user.warn