[PATCH v2 1/1] ublox: rework device initialization sequence

[PATCH v2 1/1] ublox: rework device initialization sequence

[Jonas Bonn]

[-- Attachment #1: Type: text/plain, Size: 6266 bytes --]

uBlox devices present their USB interfaces well before those interfaces
are ready to respond to any commands.  The documentation says to monitor
the 'greeting text' to detect readiness, but this 'greeting text' is not
actually specified for any device other than the TOBY L4.

What seems to work is to probe the device with 'AT' commands until the
device responds, and then to wait an additional second before
proceeding.  The TOBY L4 reliably sends its 'greeting text' (+AT: READY)
within this interval.

It would be more rigorous to actually wait for the 'READY' indication
for the TOBY L4, but that would require knowing the device model before
the device model is actually queried.  This is doable via the USB
product ID, but overkill when the above heuristic seems to work
reliably.

Before this patch, the ublox plugin was trying to achieve something like
the above with the g_at_chat_set_wakeup_command() function, but that had
some issues:

i)  it did not work reliably, in particular failing badly on the TOBY L4
with responses getting out of sync with commands
ii) it was an inappropriate use of the wakeup_command which is intended
for devices that may sleep when there is no communication during some
interval

This patch adds an init sequence that probes the device for readiness
before continuing with initialization.
---

Changed in v2:
- drop return statement
- drop superfluous empty line

 plugins/ublox.c | 119 ++++++++++++++++++++++++++++++++++++++++++------
 1 file changed, 105 insertions(+), 14 deletions(-)

diff --git a/plugins/ublox.c b/plugins/ublox.c
index 9ee38a6b..5be9d4cc 100644
--- a/plugins/ublox.c
+++ b/plugins/ublox.c
@@ -29,6 +29,7 @@
 #include <glib.h>
 #include <gatchat.h>
 #include <gattty.h>
+#include <ell/ell.h>
 
 #define OFONO_API_SUBJECT_TO_CHANGE
 #include <ofono/plugin.h>
@@ -66,6 +67,10 @@ struct ublox_data {
 
 	const struct ublox_model *model;
 	int flags;
+
+	struct l_timeout *init_timeout;
+	int init_count;
+	guint init_cmd;
 };
 
 static void ublox_debug(const char *str, void *user_data)
@@ -223,6 +228,80 @@ fail:
 	ofono_modem_set_powered(modem, FALSE);
 }
 
+static void init_cmd_cb(gboolean ok, GAtResult *result, void *user_data)
+{
+	struct ofono_modem *modem = user_data;
+	struct ublox_data *data = ofono_modem_get_data(modem);
+
+	DBG("%p", modem);
+
+	if (!ok)
+		goto fail;
+
+	/* When the 'init command' succeeds, we insert an additional
+	 * delay of 1 second before proceeding with the actual
+	 * intialization of the device.  We reuse the init_timeout
+	 * instance for this, just clearing the command to indicate
+	 * that additional retries aren't necessary.
+	 */
+	data->init_cmd = 0;
+	data->init_count = 0;
+	l_timeout_modify_ms(data->init_timeout, 1000);
+
+	return;
+
+fail:
+	l_timeout_remove(data->init_timeout);
+	data->init_timeout = NULL;
+
+	g_at_chat_unref(data->aux);
+	data->aux = NULL;
+	g_at_chat_unref(data->modem);
+	data->modem = NULL;
+	ofono_modem_set_powered(modem, FALSE);
+}
+
+static void init_timeout_cb(struct l_timeout *timeout, void *user_data)
+{
+	struct ofono_modem *modem = user_data;
+	struct ublox_data *data = ofono_modem_get_data(modem);
+
+	DBG("%p", modem);
+
+	/* As long as init_cmd is set we need to either keep retrying
+	 * or fail everything after excessive retries
+	 */
+	if (data->init_cmd && data->init_count++ < 20) {
+		g_at_chat_retry(data->aux, data->init_cmd);
+		l_timeout_modify_ms(timeout, 1000);
+		return;
+	}
+
+	l_timeout_remove(data->init_timeout);
+	data->init_timeout = NULL;
+
+	if (data->init_cmd) {
+		ofono_error("failed to init modem after 20 attempts");
+		goto fail;
+	}
+
+	g_at_chat_send(data->aux, "ATE0", none_prefix,
+					NULL, NULL, NULL);
+	g_at_chat_send(data->aux, "AT+CMEE=1", none_prefix,
+					NULL, NULL, NULL);
+
+	if (g_at_chat_send(data->aux, "AT+CGMM", NULL,
+				query_model_cb, modem, NULL) > 0)
+		return;
+
+fail:
+	g_at_chat_unref(data->aux);
+	data->aux = NULL;
+	g_at_chat_unref(data->modem);
+	data->modem = NULL;
+	ofono_modem_set_powered(modem, FALSE);
+}
+
 static int ublox_enable(struct ofono_modem *modem)
 {
 	struct ublox_data *data = ofono_modem_get_data(modem);
@@ -250,22 +329,34 @@ static int ublox_enable(struct ofono_modem *modem)
 		g_at_chat_send(data->modem, "AT&C0", NULL, NULL, NULL, NULL);
 	}
 
-	/* The modem can take a while to wake up if just powered on. */
-	g_at_chat_set_wakeup_command(data->aux, "AT\r", 1000, 11000);
-
-	g_at_chat_send(data->aux, "ATE0", none_prefix,
-					NULL, NULL, NULL);
-	g_at_chat_send(data->aux, "AT+CMEE=1", none_prefix,
-					NULL, NULL, NULL);
-
-	if (g_at_chat_send(data->aux, "AT+CGMM", NULL,
-				query_model_cb, modem, NULL) > 0)
-		return -EINPROGRESS;
+	/*
+	 * uBlox devices present their USB interfaces well before those
+	 * interfaces are actually ready to use.  The specs say to monitor
+	 * the 'greeting text' to detect whether the device is ready to use;
+	 * unfortunately, other than for the TOBY L4, the greeting text is
+	 * not actually specified.
+	 *
+	 * What has been determined experimentally to work is to probe with
+	 * an 'AT' command until it responds and then wait an additional
+	 * second before continuing with device initialization.  Even for
+	 * the TOBY L4 where one should wait for the '+AT: READY' URC
+	 * before intialization, this seems to be sufficient; the 'READY'
+	 * indication always arrives within this time.
+	 *
+	 * (It would be more rigorous to actually wait for the 'READY'
+	 * indication, but that would require knowing the device model
+	 * before the device model is actually queried.  Do-able via
+	 * USB Product ID, but overkill when the above seems to work
+	 * reliably.)
+	 */
 
-	g_at_chat_unref(data->aux);
-	data->aux = NULL;
+	data->init_count = 0;
+	data->init_cmd = g_at_chat_send(data->aux, "AT", none_prefix,
+					init_cmd_cb, modem, NULL);
+	data->init_timeout = l_timeout_create_ms(500, init_timeout_cb, modem,
+							NULL);
 
-	return -EINVAL;
+	return -EINPROGRESS;
 }
 
 static void cfun_disable(gboolean ok, GAtResult *result, gpointer user_data)
-- 
2.20.1

Re: [PATCH v2 1/1] ublox: rework device initialization sequence

[Richard =?unknown-8bit?q?R=C3=B6jfors?=]

[-- Attachment #1: Type: text/plain, Size: 8033 bytes --]

Hi Jonas,

Den tis 24 sep. 2019 kl 18:01 skrev Jonas Bonn <jonas@norrbonn.se>:

> uBlox devices present their USB interfaces well before those interfaces
> are ready to respond to any commands.  The documentation says to monitor
> the 'greeting text' to detect readiness, but this 'greeting text' is not
> actually specified for any device other than the TOBY L4.
>
> What seems to work is to probe the device with 'AT' commands until the
> device responds, and then to wait an additional second before
> proceeding.  The TOBY L4 reliably sends its 'greeting text' (+AT: READY)
> within this interval.
>
> It would be more rigorous to actually wait for the 'READY' indication
> for the TOBY L4, but that would require knowing the device model before
> the device model is actually queried.  This is doable via the USB
> product ID, but overkill when the above heuristic seems to work
> reliably.
>
> Before this patch, the ublox plugin was trying to achieve something like
> the above with the g_at_chat_set_wakeup_command() function, but that had
> some issues:
>
> i)  it did not work reliably, in particular failing badly on the TOBY L4
> with responses getting out of sync with commands
> ii) it was an inappropriate use of the wakeup_command which is intended
> for devices that may sleep when there is no communication during some
> interval
>
> This patch adds an init sequence that probes the device for readiness
> before continuing with initialization.
> ---
>
> Changed in v2:
> - drop return statement
> - drop superfluous empty line
>
>  plugins/ublox.c | 119 ++++++++++++++++++++++++++++++++++++++++++------
>  1 file changed, 105 insertions(+), 14 deletions(-)
>
> diff --git a/plugins/ublox.c b/plugins/ublox.c
> index 9ee38a6b..5be9d4cc 100644
> --- a/plugins/ublox.c
> +++ b/plugins/ublox.c
> @@ -29,6 +29,7 @@
>  #include <glib.h>
>  #include <gatchat.h>
>  #include <gattty.h>
> +#include <ell/ell.h>
>
>  #define OFONO_API_SUBJECT_TO_CHANGE
>  #include <ofono/plugin.h>
> @@ -66,6 +67,10 @@ struct ublox_data {
>
>         const struct ublox_model *model;
>         int flags;
> +
> +       struct l_timeout *init_timeout;
>

Shouldn't this should be removed in disable in case its still available..


> +       int init_count;
> +       guint init_cmd;
>  };
>
>  static void ublox_debug(const char *str, void *user_data)
> @@ -223,6 +228,80 @@ fail:
>         ofono_modem_set_powered(modem, FALSE);
>  }
>
> +static void init_cmd_cb(gboolean ok, GAtResult *result, void *user_data)
> +{
> +       struct ofono_modem *modem = user_data;
> +       struct ublox_data *data = ofono_modem_get_data(modem);
> +
> +       DBG("%p", modem);
> +
> +       if (!ok)
> +               goto fail;
> +
> +       /* When the 'init command' succeeds, we insert an additional
> +        * delay of 1 second before proceeding with the actual
> +        * intialization of the device.  We reuse the init_timeout
> +        * instance for this, just clearing the command to indicate
> +        * that additional retries aren't necessary.
> +        */
> +       data->init_cmd = 0;
> +       data->init_count = 0;
> +       l_timeout_modify_ms(data->init_timeout, 1000);
> +
> +       return;
> +
> +fail:
> +       l_timeout_remove(data->init_timeout);
> +       data->init_timeout = NULL;
> +
> +       g_at_chat_unref(data->aux);
> +       data->aux = NULL;
> +       g_at_chat_unref(data->modem);
> +       data->modem = NULL;
> +       ofono_modem_set_powered(modem, FALSE);
> +}
> +
> +static void init_timeout_cb(struct l_timeout *timeout, void *user_data)
> +{
> +       struct ofono_modem *modem = user_data;
> +       struct ublox_data *data = ofono_modem_get_data(modem);
> +
> +       DBG("%p", modem);
> +
> +       /* As long as init_cmd is set we need to either keep retrying
> +        * or fail everything after excessive retries
> +        */
> +       if (data->init_cmd && data->init_count++ < 20) {
> +               g_at_chat_retry(data->aux, data->init_cmd);
> +               l_timeout_modify_ms(timeout, 1000);
> +               return;
> +       }
> +
> +       l_timeout_remove(data->init_timeout);
> +       data->init_timeout = NULL;
> +
> +       if (data->init_cmd) {
> +               ofono_error("failed to init modem after 20 attempts");
> +               goto fail;
> +       }
> +
> +       g_at_chat_send(data->aux, "ATE0", none_prefix,
> +                                       NULL, NULL, NULL);
> +       g_at_chat_send(data->aux, "AT+CMEE=1", none_prefix,
> +                                       NULL, NULL, NULL);
> +
> +       if (g_at_chat_send(data->aux, "AT+CGMM", NULL,
> +                               query_model_cb, modem, NULL) > 0)
> +               return;
> +
> +fail:
> +       g_at_chat_unref(data->aux);
> +       data->aux = NULL;
> +       g_at_chat_unref(data->modem);
> +       data->modem = NULL;
> +       ofono_modem_set_powered(modem, FALSE);
> +}
> +
>  static int ublox_enable(struct ofono_modem *modem)
>  {
>         struct ublox_data *data = ofono_modem_get_data(modem);
> @@ -250,22 +329,34 @@ static int ublox_enable(struct ofono_modem *modem)
>                 g_at_chat_send(data->modem, "AT&C0", NULL, NULL, NULL,
> NULL);
>         }
>
> -       /* The modem can take a while to wake up if just powered on. */
> -       g_at_chat_set_wakeup_command(data->aux, "AT\r", 1000, 11000);
> -
> -       g_at_chat_send(data->aux, "ATE0", none_prefix,
> -                                       NULL, NULL, NULL);
> -       g_at_chat_send(data->aux, "AT+CMEE=1", none_prefix,
> -                                       NULL, NULL, NULL);
> -
> -       if (g_at_chat_send(data->aux, "AT+CGMM", NULL,
> -                               query_model_cb, modem, NULL) > 0)
> -               return -EINPROGRESS;
> +       /*
> +        * uBlox devices present their USB interfaces well before those
> +        * interfaces are actually ready to use.  The specs say to monitor
> +        * the 'greeting text' to detect whether the device is ready to
> use;
> +        * unfortunately, other than for the TOBY L4, the greeting text is
> +        * not actually specified.
> +        *
> +        * What has been determined experimentally to work is to probe with
> +        * an 'AT' command until it responds and then wait an additional
> +        * second before continuing with device initialization.  Even for
> +        * the TOBY L4 where one should wait for the '+AT: READY' URC
> +        * before intialization, this seems to be sufficient; the 'READY'
> +        * indication always arrives within this time.
> +        *
> +        * (It would be more rigorous to actually wait for the 'READY'
> +        * indication, but that would require knowing the device model
> +        * before the device model is actually queried.  Do-able via
> +        * USB Product ID, but overkill when the above seems to work
> +        * reliably.)
> +        */
>
> -       g_at_chat_unref(data->aux);
> -       data->aux = NULL;
> +       data->init_count = 0;
> +       data->init_cmd = g_at_chat_send(data->aux, "AT", none_prefix,
> +                                       init_cmd_cb, modem, NULL);
> +       data->init_timeout = l_timeout_create_ms(500, init_timeout_cb,
> modem,
> +                                                       NULL);
>

Is 500ms enough? What happens if the modem buffers the at commands for a
while
and sends out two "OK"? Won't the second be in the queue and considered
being
the response to the next command?


>
> -       return -EINVAL;
> +       return -EINPROGRESS;
>  }
>
>  static void cfun_disable(gboolean ok, GAtResult *result, gpointer
> user_data)
> --
> 2.20.1
>
> _______________________________________________
> ofono mailing list
> ofono(a)ofono.org
> https://lists.ofono.org/mailman/listinfo/ofono
>

[-- Attachment #2: attachment.html --]
[-- Type: text/html, Size: 9962 bytes --]

Re: [PATCH v2 1/1] ublox: rework device initialization sequence

[Jonas Bonn]

[-- Attachment #1: Type: text/plain, Size: 10157 bytes --]



On 24/09/2019 18:32, Richard Röjfors wrote:
> Hi Jonas,
> 
> Den tis 24 sep. 2019 kl 18:01 skrev Jonas Bonn <jonas@norrbonn.se 
> <mailto:jonas@norrbonn.se>>:
> 
>     uBlox devices present their USB interfaces well before those interfaces
>     are ready to respond to any commands.  The documentation says to monitor
>     the 'greeting text' to detect readiness, but this 'greeting text' is not
>     actually specified for any device other than the TOBY L4.
> 
>     What seems to work is to probe the device with 'AT' commands until the
>     device responds, and then to wait an additional second before
>     proceeding.  The TOBY L4 reliably sends its 'greeting text' (+AT: READY)
>     within this interval.
> 
>     It would be more rigorous to actually wait for the 'READY' indication
>     for the TOBY L4, but that would require knowing the device model before
>     the device model is actually queried.  This is doable via the USB
>     product ID, but overkill when the above heuristic seems to work
>     reliably.
> 
>     Before this patch, the ublox plugin was trying to achieve something like
>     the above with the g_at_chat_set_wakeup_command() function, but that had
>     some issues:
> 
>     i)  it did not work reliably, in particular failing badly on the TOBY L4
>     with responses getting out of sync with commands
>     ii) it was an inappropriate use of the wakeup_command which is intended
>     for devices that may sleep when there is no communication during some
>     interval
> 
>     This patch adds an init sequence that probes the device for readiness
>     before continuing with initialization.
>     ---
> 
>     Changed in v2:
>     - drop return statement
>     - drop superfluous empty line
> 
>       plugins/ublox.c | 119 ++++++++++++++++++++++++++++++++++++++++++------
>       1 file changed, 105 insertions(+), 14 deletions(-)
> 
>     diff --git a/plugins/ublox.c b/plugins/ublox.c
>     index 9ee38a6b..5be9d4cc 100644
>     --- a/plugins/ublox.c
>     +++ b/plugins/ublox.c
>     @@ -29,6 +29,7 @@
>       #include <glib.h>
>       #include <gatchat.h>
>       #include <gattty.h>
>     +#include <ell/ell.h>
> 
>       #define OFONO_API_SUBJECT_TO_CHANGE
>       #include <ofono/plugin.h>
>     @@ -66,6 +67,10 @@ struct ublox_data {
> 
>              const struct ublox_model *model;
>              int flags;
>     +
>     +       struct l_timeout *init_timeout;
> 
> 
> Shouldn't this should be removed in disable in case its still available..
> 
>     +       int init_count;
>     +       guint init_cmd;
>       };
> 
>       static void ublox_debug(const char *str, void *user_data)
>     @@ -223,6 +228,80 @@ fail:
>              ofono_modem_set_powered(modem, FALSE);
>       }
> 
>     +static void init_cmd_cb(gboolean ok, GAtResult *result, void
>     *user_data)
>     +{
>     +       struct ofono_modem *modem = user_data;
>     +       struct ublox_data *data = ofono_modem_get_data(modem);
>     +
>     +       DBG("%p", modem);
>     +
>     +       if (!ok)
>     +               goto fail;
>     +
>     +       /* When the 'init command' succeeds, we insert an additional
>     +        * delay of 1 second before proceeding with the actual
>     +        * intialization of the device.  We reuse the init_timeout
>     +        * instance for this, just clearing the command to indicate
>     +        * that additional retries aren't necessary.
>     +        */
>     +       data->init_cmd = 0;
>     +       data->init_count = 0;
>     +       l_timeout_modify_ms(data->init_timeout, 1000);
>     +
>     +       return;
>     +
>     +fail:
>     +       l_timeout_remove(data->init_timeout);
>     +       data->init_timeout = NULL;
>     +
>     +       g_at_chat_unref(data->aux);
>     +       data->aux = NULL;
>     +       g_at_chat_unref(data->modem);
>     +       data->modem = NULL;
>     +       ofono_modem_set_powered(modem, FALSE);
>     +}
>     +
>     +static void init_timeout_cb(struct l_timeout *timeout, void *user_data)
>     +{
>     +       struct ofono_modem *modem = user_data;
>     +       struct ublox_data *data = ofono_modem_get_data(modem);
>     +
>     +       DBG("%p", modem);
>     +
>     +       /* As long as init_cmd is set we need to either keep retrying
>     +        * or fail everything after excessive retries
>     +        */
>     +       if (data->init_cmd && data->init_count++ < 20) {
>     +               g_at_chat_retry(data->aux, data->init_cmd);
>     +               l_timeout_modify_ms(timeout, 1000);
>     +               return;
>     +       }
>     +
>     +       l_timeout_remove(data->init_timeout);
>     +       data->init_timeout = NULL;
>     +
>     +       if (data->init_cmd) {
>     +               ofono_error("failed to init modem after 20 attempts");
>     +               goto fail;
>     +       }
>     +
>     +       g_at_chat_send(data->aux, "ATE0", none_prefix,
>     +                                       NULL, NULL, NULL);
>     +       g_at_chat_send(data->aux, "AT+CMEE=1", none_prefix,
>     +                                       NULL, NULL, NULL);
>     +
>     +       if (g_at_chat_send(data->aux, "AT+CGMM", NULL,
>     +                               query_model_cb, modem, NULL) > 0)
>     +               return;
>     +
>     +fail:
>     +       g_at_chat_unref(data->aux);
>     +       data->aux = NULL;
>     +       g_at_chat_unref(data->modem);
>     +       data->modem = NULL;
>     +       ofono_modem_set_powered(modem, FALSE);
>     +}
>     +
>       static int ublox_enable(struct ofono_modem *modem)
>       {
>              struct ublox_data *data = ofono_modem_get_data(modem);
>     @@ -250,22 +329,34 @@ static int ublox_enable(struct ofono_modem *modem)
>                      g_at_chat_send(data->modem, "AT&C0", NULL, NULL,
>     NULL, NULL);
>              }
> 
>     -       /* The modem can take a while to wake up if just powered on. */
>     -       g_at_chat_set_wakeup_command(data->aux, "AT\r", 1000, 11000);
>     -
>     -       g_at_chat_send(data->aux, "ATE0", none_prefix,
>     -                                       NULL, NULL, NULL);
>     -       g_at_chat_send(data->aux, "AT+CMEE=1", none_prefix,
>     -                                       NULL, NULL, NULL);
>     -
>     -       if (g_at_chat_send(data->aux, "AT+CGMM", NULL,
>     -                               query_model_cb, modem, NULL) > 0)
>     -               return -EINPROGRESS;
>     +       /*
>     +        * uBlox devices present their USB interfaces well before those
>     +        * interfaces are actually ready to use.  The specs say to
>     monitor
>     +        * the 'greeting text' to detect whether the device is ready
>     to use;
>     +        * unfortunately, other than for the TOBY L4, the greeting
>     text is
>     +        * not actually specified.
>     +        *
>     +        * What has been determined experimentally to work is to
>     probe with
>     +        * an 'AT' command until it responds and then wait an additional
>     +        * second before continuing with device initialization. 
>     Even for
>     +        * the TOBY L4 where one should wait for the '+AT: READY' URC
>     +        * before intialization, this seems to be sufficient; the
>     'READY'
>     +        * indication always arrives within this time.
>     +        *
>     +        * (It would be more rigorous to actually wait for the 'READY'
>     +        * indication, but that would require knowing the device model
>     +        * before the device model is actually queried.  Do-able via
>     +        * USB Product ID, but overkill when the above seems to work
>     +        * reliably.)
>     +        */
> 
>     -       g_at_chat_unref(data->aux);
>     -       data->aux = NULL;
>     +       data->init_count = 0;
>     +       data->init_cmd = g_at_chat_send(data->aux, "AT", none_prefix,
>     +                                       init_cmd_cb, modem, NULL);
>     +       data->init_timeout = l_timeout_create_ms(500,
>     init_timeout_cb, modem,
>     +                                                       NULL);
> 
> 
> Is 500ms enough? What happens if the modem buffers the at commands for a 
> while
> and sends out two "OK"? Won't the second be in the queue and considered 
> being
> the response to the next command?

That's the beauty with the extra second delay.  During this dead period 
we can pick up all the extra OK's we receive and ignore them.  That way, 
the next command in the init sequence doesn't get fooled by the spurious 
OK and get the commands out of sync with the responses.

Also, the TOBY L4 wants the extra second to finish its intialisation.

Furthermore, there's not an AT command sent every 500 ms.  The command 
gets requeued after 500ms, but it doesn't actually go out until the 
modem responds to the first one... not quite sure why this works, to be 
honest.

/Jonas

> 
> 
>     -       return -EINVAL;
>     +       return -EINPROGRESS;
>       }
> 
>       static void cfun_disable(gboolean ok, GAtResult *result, gpointer
>     user_data)
>     -- 
>     2.20.1
> 
>     _______________________________________________
>     ofono mailing list
>     ofono(a)ofono.org <mailto:ofono@ofono.org>
>     https://lists.ofono.org/mailman/listinfo/ofono
> 

Re: [PATCH v2 1/1] ublox: rework device initialization sequence

[Denis Kenzior]

[-- Attachment #1: Type: text/plain, Size: 377 bytes --]

Hi Jonas,

> 
> Furthermore, there's not an AT command sent every 500 ms.  The command 
> gets requeued after 500ms, but it doesn't actually go out until the 
> modem responds to the first one... not quite sure why this works, to be 
> honest.
> 

Funny.  But not real confidence inspiring :)

Martin, any ideas what could be going wrong here?

Regards,
-Denis

Re: [PATCH v2 1/1] ublox: rework device initialization sequence

[Martin =?unknown-8bit?q?Hundeb=C3=B8ll?=]

[-- Attachment #1: Type: text/plain, Size: 507 bytes --]

Hi,

On 24/09/2019 19.23, Denis Kenzior wrote:
>> Furthermore, there's not an AT command sent every 500 ms.  The command 
>> gets requeued after 500ms, but it doesn't actually go out until the 
>> modem responds to the first one... not quite sure why this works, to 
>> be honest.
>>
> 
> Funny.  But not real confidence inspiring :)
> 
> Martin, any ideas what could be going wrong here?

The code looks quite familiar :)

Jonas, do you have a log with OFONO_AT_DEBUG=1 set?

// Martin

Re: [PATCH v2 1/1] ublox: rework device initialization sequence

[Martin =?unknown-8bit?q?Hundeb=C3=B8ll?=]

[-- Attachment #1: Type: text/plain, Size: 923 bytes --]

Hi,

On 24/09/2019 20.09, Martin Hundebøll wrote:
> On 24/09/2019 19.23, Denis Kenzior wrote:
>>> Furthermore, there's not an AT command sent every 500 ms.  The 
>>> command gets requeued after 500ms, but it doesn't actually go out 
>>> until the modem responds to the first one... not quite sure why this 
>>> works, to be honest.
>>>
>>
>> Funny.  But not real confidence inspiring :)
>>
>> Martin, any ideas what could be going wrong here?
> 
> The code looks quite familiar :)
> 
> Jonas, do you have a log with OFONO_AT_DEBUG=1 set?

For the record, here one from my setup:

UART: > AT\r
UART: < \371\013s\001\222\371
../git/plugins/quectel.c:init_timeout_cb() 0x610000000d40
UART: > AT\r
UART: < \r\nOK\r\n
../git/plugins/quectel.c:init_cmd_cb() 0x610000000d40
../git/src/modem.c:get_modem_property() modem 0x610000000d40 property RtsCts
UART: > ATE0\r
UART: < \r\nOK\r\n

// Martin

Re: [PATCH v2 1/1] ublox: rework device initialization sequence

[Jonas Bonn]

[-- Attachment #1: Type: text/plain, Size: 2567 bytes --]

Hi Martin,

On 24/09/2019 21:20, Martin Hundebøll wrote:
> Hi,
> 
> On 24/09/2019 20.09, Martin Hundebøll wrote:
>> On 24/09/2019 19.23, Denis Kenzior wrote:
>>>> Furthermore, there's not an AT command sent every 500 ms.  The 
>>>> command gets requeued after 500ms, but it doesn't actually go out 
>>>> until the modem responds to the first one... not quite sure why this 
>>>> works, to be honest.
>>>>
>>>
>>> Funny.  But not real confidence inspiring :)
>>>
>>> Martin, any ideas what could be going wrong here?
>>
>> The code looks quite familiar :)

For good reason! :)

>>
>> Jonas, do you have a log with OFONO_AT_DEBUG=1 set?
> 

ofonod[31545]: Aux: > AT\r
ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
ofonod[31545]: Aux: > AT\r
ofonod[31545]: Aux: < AT\r
ofonod[31545]: Aux: < AT\r
ofonod[31545]: Aux: < \r\nOK\r\n
ofonod[31545]: plugins/ublox.c:init_cmd_cb() 0x563f7c2cebc0
ofonod[31545]: Aux: < \r\nOK\r\n
ofonod[31545]: Aux: < \r\n+AT: READY\r\n
ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
ofonod[31545]: Aux: > ATE0\r
ofonod[31545]: Aux: < ATE0
ofonod[31545]: Aux: < \r\r\nOK\r\n


> For the record, here one from my setup:
> 
> UART: > AT\r
> UART: < \371\013s\001\222\371
> ../git/plugins/quectel.c:init_timeout_cb() 0x610000000d40
> UART: > AT\r
> UART: < \r\nOK\r\n
> ../git/plugins/quectel.c:init_cmd_cb() 0x610000000d40
> ../git/src/modem.c:get_modem_property() modem 0x610000000d40 property 
> RtsCts
> UART: > ATE0\r
> UART: < \r\nOK\r\n
> 

So yours looks a bit different... you really do lose the first AT 
command into a black hole.  The uBlox modem seems to not lose anything 
sent over the USB bus but rather buffers it up and responds later.  That 
said, according to the documentation it _could_ lose the AT command so 
one cannot rely on the response just turning up eventually.

The thing that wasn't clear to me, though, was why every invocation of 
init_timeout_cb doesn't result in a new AT command being sent?  It's 
like the command is set to be retried in the first invocation, but it 
never gets sent so the subsequent retries amount to no-ops.  This 
behaviour is agreeable in this case, but I don't quite understand why it 
works this way...

/Jonas

Re: [PATCH v2 1/1] ublox: rework device initialization sequence

[Martin =?unknown-8bit?q?Hundeb=C3=B8ll?=]

[-- Attachment #1: Type: text/plain, Size: 3316 bytes --]

Hi Jonas,

On 9/25/19 5:44 AM, Jonas Bonn wrote:
> On 24/09/2019 21:20, Martin Hundebøll wrote:
>> On 24/09/2019 20.09, Martin Hundebøll wrote:
>>> On 24/09/2019 19.23, Denis Kenzior wrote:
>>>>> Furthermore, there's not an AT command sent every 500 ms.  The 
>>>>> command gets requeued after 500ms, but it doesn't actually go out 
>>>>> until the modem responds to the first one... not quite sure why 
>>>>> this works, to be honest.
>>>>>
>>>>
>>>> Funny.  But not real confidence inspiring :)
>>>>
>>>> Martin, any ideas what could be going wrong here?
>>>
>>> The code looks quite familiar :)
> 
> For good reason! :)
> 
>>>
>>> Jonas, do you have a log with OFONO_AT_DEBUG=1 set?
>>
> 
> ofonod[31545]: Aux: > AT\r
> ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
> ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
> ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
> ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
> ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
> ofonod[31545]: Aux: > AT\r
> ofonod[31545]: Aux: < AT\r
> ofonod[31545]: Aux: < AT\r
> ofonod[31545]: Aux: < \r\nOK\r\n
> ofonod[31545]: plugins/ublox.c:init_cmd_cb() 0x563f7c2cebc0
> ofonod[31545]: Aux: < \r\nOK\r\n
> ofonod[31545]: Aux: < \r\n+AT: READY\r\n
> ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
> ofonod[31545]: Aux: > ATE0\r
> ofonod[31545]: Aux: < ATE0
> ofonod[31545]: Aux: < \r\r\nOK\r\n
> 
> 
>> For the record, here one from my setup:
>>
>> UART: > AT\r
>> UART: < \371\013s\001\222\371
>> ../git/plugins/quectel.c:init_timeout_cb() 0x610000000d40
>> UART: > AT\r
>> UART: < \r\nOK\r\n
>> ../git/plugins/quectel.c:init_cmd_cb() 0x610000000d40
>> ../git/src/modem.c:get_modem_property() modem 0x610000000d40 property 
>> RtsCts
>> UART: > ATE0\r
>> UART: < \r\nOK\r\n
>>
> 
> So yours looks a bit different... you really do lose the first AT 
> command into a black hole.  The uBlox modem seems to not lose anything 
> sent over the USB bus but rather buffers it up and responds later.  That 
> said, according to the documentation it _could_ lose the AT command so 
> one cannot rely on the response just turning up eventually.

Could it be safe to assume that it will lose only a single AT command? 
In that case, it should be enough to send just two AT's. Once the first 
OK is received, you could wait 500 ms for the second OK, or retry the 
second AT in case of a timeout?

No lost AT:
  > AT   // Send first
  > AT   // Send second and wait
  < OK   // Wait 500 ms
  < OK   // Start initialization

One lost AT
  > AT   // Send first
  > AT   // Send second and wait
  < OK   // Wait 500 ms
  > AT   // Retry second
  < OK   // Start initialization

> The thing that wasn't clear to me, though, was why every invocation of 
> init_timeout_cb doesn't result in a new AT command being sent?  It's 
> like the command is set to be retried in the first invocation, but it 
> never gets sent so the subsequent retries amount to no-ops.  This 
> behaviour is agreeable in this case, but I don't quite understand why it 
> works this way...

Can the usb-to-serial driver block further writes until the modem is ready?

// Martin

Re: [PATCH v2 1/1] ublox: rework device initialization sequence

[Jonas Bonn]

[-- Attachment #1: Type: text/plain, Size: 4258 bytes --]

Hi Martin,

On 25/09/2019 09:27, Martin Hundebøll wrote:
> Hi Jonas,
> 
> On 9/25/19 5:44 AM, Jonas Bonn wrote:
>> On 24/09/2019 21:20, Martin Hundebøll wrote:
>>> On 24/09/2019 20.09, Martin Hundebøll wrote:
>>>> On 24/09/2019 19.23, Denis Kenzior wrote:
>>>>>> Furthermore, there's not an AT command sent every 500 ms.  The 
>>>>>> command gets requeued after 500ms, but it doesn't actually go out 
>>>>>> until the modem responds to the first one... not quite sure why 
>>>>>> this works, to be honest.
>>>>>>
>>>>>
>>>>> Funny.  But not real confidence inspiring :)
>>>>>
>>>>> Martin, any ideas what could be going wrong here?
>>>>
>>>> The code looks quite familiar :)
>>
>> For good reason! :)
>>
>>>>
>>>> Jonas, do you have a log with OFONO_AT_DEBUG=1 set?
>>>
>>
>> ofonod[31545]: Aux: > AT\r
>> ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
>> ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
>> ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
>> ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
>> ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
>> ofonod[31545]: Aux: > AT\r
>> ofonod[31545]: Aux: < AT\r
>> ofonod[31545]: Aux: < AT\r
>> ofonod[31545]: Aux: < \r\nOK\r\n
>> ofonod[31545]: plugins/ublox.c:init_cmd_cb() 0x563f7c2cebc0
>> ofonod[31545]: Aux: < \r\nOK\r\n
>> ofonod[31545]: Aux: < \r\n+AT: READY\r\n
>> ofonod[31545]: plugins/ublox.c:init_timeout_cb() 0x563f7c2cebc0
>> ofonod[31545]: Aux: > ATE0\r
>> ofonod[31545]: Aux: < ATE0
>> ofonod[31545]: Aux: < \r\r\nOK\r\n
>>
>>
>>> For the record, here one from my setup:
>>>
>>> UART: > AT\r
>>> UART: < \371\013s\001\222\371
>>> ../git/plugins/quectel.c:init_timeout_cb() 0x610000000d40
>>> UART: > AT\r
>>> UART: < \r\nOK\r\n
>>> ../git/plugins/quectel.c:init_cmd_cb() 0x610000000d40
>>> ../git/src/modem.c:get_modem_property() modem 0x610000000d40 property 
>>> RtsCts
>>> UART: > ATE0\r
>>> UART: < \r\nOK\r\n
>>>
>>
>> So yours looks a bit different... you really do lose the first AT 
>> command into a black hole.  The uBlox modem seems to not lose anything 
>> sent over the USB bus but rather buffers it up and responds later.  
>> That said, according to the documentation it _could_ lose the AT 
>> command so one cannot rely on the response just turning up eventually.
> 
> Could it be safe to assume that it will lose only a single AT command? 
> In that case, it should be enough to send just two AT's. Once the first 
> OK is received, you could wait 500 ms for the second OK, or retry the 
> second AT in case of a timeout?
> 
> No lost AT:
>   > AT   // Send first
>   > AT   // Send second and wait
>   < OK   // Wait 500 ms
>   < OK   // Start initialization
> 
> One lost AT
>   > AT   // Send first
>   > AT   // Send second and wait
>   < OK   // Wait 500 ms
>   > AT   // Retry second
>   < OK   // Start initialization

That's pretty much what we've got, isn't it?


> 
>> The thing that wasn't clear to me, though, was why every invocation of 
>> init_timeout_cb doesn't result in a new AT command being sent?  It's 
>> like the command is set to be retried in the first invocation, but it 
>> never gets sent so the subsequent retries amount to no-ops.  This 
>> behaviour is agreeable in this case, but I don't quite understand why 
>> it works this way...
> 
> Can the usb-to-serial driver block further writes until the modem is ready?

Not the driver but the modem.  If the USB bulk endpoint on the modem 
side decides it is busy (for example, because it's buffers are full), it 
can NAK subsequent packets until it's ready to receive again.  It's not 
out of the question that Linux is smart enough to return EAGAIN for a 
write in that case... but I would suspect that the OS would normally 
buffer the write() for more than one AT command before this happened. 
For that reason, I can't see why ofono would be able to detect this... 
from ofono's point of view it should just look like there's a series of 
AT commands going out and no responses coming back.  There must be some 
magic in g_io_...???

/Jonas

> 
> // Martin

Re: [PATCH v2 1/1] ublox: rework device initialization sequence

[Pavel Machek]

[-- Attachment #1: Type: text/plain, Size: 605 bytes --]

On Tue 2019-09-24 18:01:26, Jonas Bonn wrote:
> uBlox devices present their USB interfaces well before those interfaces
> are ready to respond to any commands.  The documentation says to monitor
> the 'greeting text' to detect readiness, but this 'greeting text' is not
> actually specified for any device other than the TOBY L4.

Collecting "greeting texts" from all the modems we want to support
should not be hard, right?

Best regards,
									Pavel
-- 
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 181 bytes --]

Re: [PATCH v2 1/1] ublox: rework device initialization sequence

[Richard =?unknown-8bit?q?R=C3=B6jfors?=]

[-- Attachment #1: Type: text/plain, Size: 628 bytes --]

Den tis 24 sep. 2019 kl 21:55 skrev Pavel Machek <pavel@ucw.cz>:

> On Tue 2019-09-24 18:01:26, Jonas Bonn wrote:
> > uBlox devices present their USB interfaces well before those interfaces
> > are ready to respond to any commands.  The documentation says to monitor
> > the 'greeting text' to detect readiness, but this 'greeting text' is not
> > actually specified for any device other than the TOBY L4.
>
> Collecting "greeting texts" from all the modems we want to support
> should not be hard, right?
>

I don't think that's a good idea. What if ofono is restated and the modem
is still running?

--Richard

[-- Attachment #2: attachment.html --]
[-- Type: text/html, Size: 971 bytes --]

Re: [PATCH v2 1/1] ublox: rework device initialization sequence

[Jonas Bonn]

[-- Attachment #1: Type: text/plain, Size: 1089 bytes --]



On 25/09/2019 08:40, Richard Röjfors wrote:
> Den tis 24 sep. 2019 kl 21:55 skrev Pavel Machek <pavel@ucw.cz 
> <mailto:pavel@ucw.cz>>:
> 
>     On Tue 2019-09-24 18:01:26, Jonas Bonn wrote:
>      > uBlox devices present their USB interfaces well before those
>     interfaces
>      > are ready to respond to any commands.  The documentation says to
>     monitor
>      > the 'greeting text' to detect readiness, but this 'greeting text'
>     is not
>      > actually specified for any device other than the TOBY L4.
> 
>     Collecting "greeting texts" from all the modems we want to support
>     should not be hard, right?

...given that one has access to all the devices!

Honestly, I suspect the documentation is garbage.  There are no greeting 
texts for devices other than the L4; probing is just a matter of waiting 
for AT to respond to with OK.

> 
> 
> I don't think that's a good idea. What if ofono is restated and the 
> modem is still running?

In this case, the TOBY-L4 does not provide a greeting text.

/Jonas


> 
> --Richard