Hi Aleksander,

You'll be able to reproduce it with the two patches attached to this email.
The first is basically the one you proposed for tracing #QSS: 3, while the
latter is a work in progress to fix the problem of sim locked with some
logic to manage QSS transitions and some debug logs

On Fri, 17 Mar 2017 at 21:03 Aleksander Morgado <aleksan...@aleksander.es>
wrote:

> On Fri, Mar 17, 2017 at 4:55 PM, Carlo Lobrano <c.lobr...@gmail.com>
> wrote:
> > mar 17 16:45:15 D2040 ModemManager[3946]: <debug> (ttyACM0): -->
> > 'AT+GCAP<CR>'
> > mar 17 16:45:15 D2040 ModemManager[3946]: <debug> (ttyACM0): <--
> '<CR><LF>'
> > mar 17 16:45:15 D2040 ModemManager[3946]: <debug> (ttyACM0): <-- '+GCAP:
> > +CGSM,+DS,+FCLASS,+MS,+ES<CR><LF><CR><LF>OK<CR><LF>'
>
> Ah, ok, I see the <CR><LF> here now.
>
> > mar 17 16:45:16 D2040 ModemManager[3946]: <debug> parse_caps_gcap on
> > '(null)'
>
> This is very very weird.
>
> I really would like to try to reproduce this myself...
>
> --
> Aleksander
> https://aleksander.es
>
From 77b0f2482d23b6be90f98397229ac8070771fd29 Mon Sep 17 00:00:00 2001
From: Carlo Lobrano <carlo.lobr...@telit.com>
Date: Thu, 16 Mar 2017 14:36:18 +0100
Subject: [PATCH 1/2] Add QSS=3 management

---
 plugins/telit/mm-broadband-modem-telit.c | 106 ++++++++++++++++++++++++++-----
 plugins/telit/mm-broadband-modem-telit.h |   2 +
 2 files changed, 91 insertions(+), 17 deletions(-)

diff --git a/plugins/telit/mm-broadband-modem-telit.c b/plugins/telit/mm-broadband-modem-telit.c
index b1679ae..843d130 100644
--- a/plugins/telit/mm-broadband-modem-telit.c
+++ b/plugins/telit/mm-broadband-modem-telit.c
@@ -42,40 +42,83 @@ G_DEFINE_TYPE_EXTENDED (MMBroadbandModemTelit, mm_broadband_modem_telit, MM_TYPE
                         G_IMPLEMENT_INTERFACE (MM_TYPE_IFACE_MODEM, iface_modem_init)
                         G_IMPLEMENT_INTERFACE (MM_TYPE_IFACE_MODEM_3GPP, iface_modem_3gpp_init));
 
+struct _MMBroadbandModemTelitPrivate {
+    /* Whether the SIM ready notification has been received */
+    gboolean  sim_ready;
+    GTask    *sim_ready_task;
+    guint     sim_ready_timeout_id;
+};
 
 /*****************************************************************************/
 /* After Sim Unlock (Modem interface) */
+
+/* A short delay is necessary with some SIMs when they have just been
+ * unlocked. Using up to 1 second as secure margin. */
+#define SIM_READY_TIMEOUT_SECS 1
+
 static gboolean
 modem_after_sim_unlock_finish (MMIfaceModem *self,
                                GAsyncResult *res,
                                GError **error)
 {
-    return TRUE;
+    return g_task_propagate_boolean (G_TASK (res), error);
 }
 
 static gboolean
-after_sim_unlock_ready (GSimpleAsyncResult *result)
+after_sim_unlock_ready (MMBroadbandModemTelit *self)
 {
-    g_simple_async_result_complete (result);
-    g_object_unref (result);
+    g_assert (self->priv->sim_ready_timeout_id);
+    g_assert (self->priv->sim_ready_task);
+
+    self->priv->sim_ready_timeout_id = 0;
+
+    g_task_return_boolean (self->priv->sim_ready_task, TRUE);
+    g_clear_object (&self->priv->sim_ready_task);
+
     return G_SOURCE_REMOVE;
 }
 
 static void
-modem_after_sim_unlock (MMIfaceModem *self,
-                        GAsyncReadyCallback callback,
-                        gpointer user_data)
+modem_after_sim_unlock_cancel (MMBroadbandModemTelit *self)
 {
-    GSimpleAsyncResult *result;
+    /* Cancel the after-sim-unlock wait timeout */
+    if (self->priv->sim_ready_timeout_id) {
+        g_source_remove (self->priv->sim_ready_timeout_id);
+        self->priv->sim_ready_timeout_id = 0;
+    }
 
-    result = g_simple_async_result_new (G_OBJECT (self),
-                                        callback,
-                                        user_data,
-                                        modem_after_sim_unlock);
+    /* Complete after-sim-unlock wait task with error */
+    if (self->priv->sim_ready_task) {
+        g_task_return_new_error (self->priv->sim_ready_task, MM_CORE_ERROR, MM_CORE_ERROR_FAILED, "SIM removed");
+        g_clear_object (&self->priv->sim_ready_task);
+    }
+}
+
+static void
+modem_after_sim_unlock (MMIfaceModem        *_self,
+                        GAsyncReadyCallback  callback,
+                        gpointer             user_data)
+{
+    MMBroadbandModemTelit *self;
+
+    self = MM_BROADBAND_MODEM_TELIT (_self);
+
+    g_assert (!self->priv->sim_ready_task);
+    g_assert (!self->priv->sim_ready_timeout_id);
+
+    /* Create new task that we store in the private info, so that it can be
+     * completed early when unsolicited messages arrive. */
+    self->priv->sim_ready_task = g_task_new (self, NULL, callback, user_data);
 
-    /* A short delay is necessary with some SIMs when
-    they have just been unlocked. Using 1 second as secure margin. */
-    g_timeout_add_seconds (1, (GSourceFunc) after_sim_unlock_ready, result);
+    /* If SIM ready already reported, we're done */
+    if (self->priv->sim_ready) {
+        g_task_return_boolean (self->priv->sim_ready_task, TRUE);
+        g_clear_object (&self->priv->sim_ready_task);
+        return;
+    }
+
+    /* Wait for SIM readiness */
+    self->priv->sim_ready_timeout_id = g_timeout_add_seconds (SIM_READY_TIMEOUT_SECS, (GSourceFunc) after_sim_unlock_ready, self);
 }
 
 /*****************************************************************************/
@@ -94,6 +137,10 @@ telit_qss_unsolicited_handler (MMPortSerialAt *port,
     switch (qss) {
         case 0:
             mm_info ("QSS: SIM removed");
+
+            /* Flag as not ready */
+            self->priv->sim_ready = FALSE;
+            modem_after_sim_unlock_cancel (self);
             break;
         case 1:
             mm_info ("QSS: SIM inserted");
@@ -102,7 +149,8 @@ telit_qss_unsolicited_handler (MMPortSerialAt *port,
             mm_info ("QSS: SIM inserted and PIN unlocked");
             break;
         case 3:
-            mm_info ("QSS: SIM inserted and PIN locked");
+            mm_info ("QSS: SIM inserted and Ready");
+            self->priv->sim_ready = TRUE;
             break;
         default:
             mm_warn ("QSS: unknown QSS value %d", qss);
@@ -203,9 +251,12 @@ modem_setup_sim_hot_swap (MMIfaceModem *self,
     if (!port)
         port = mm_base_modem_peek_port_primary (MM_BASE_MODEM (self));
 
+    /* We enable QSS=2 so that we get notifications not only of SIM inserted or
+     * not inserted, but also when the SIM is unlocked and ready for SMS and
+     * phonebook access */
     mm_base_modem_at_command_full (MM_BASE_MODEM (self),
                                    port,
-                                   "#QSS=1",
+                                   "#QSS=2",
                                    3,
                                    FALSE,
                                    FALSE, /* raw */
@@ -1199,6 +1250,22 @@ mm_broadband_modem_telit_new (const gchar *device,
 static void
 mm_broadband_modem_telit_init (MMBroadbandModemTelit *self)
 {
+    /* Initialize private data */
+    self->priv = G_TYPE_INSTANCE_GET_PRIVATE (self, MM_TYPE_BROADBAND_MODEM_TELIT, MMBroadbandModemTelitPrivate);
+}
+
+static void
+finalize (GObject *object)
+{
+    MMBroadbandModemTelit *self = MM_BROADBAND_MODEM_TELIT (object);
+
+    /* The after sim unlock step takes a full reference of the modem object in
+     * the GTask, and therefore, the object will never be unref-ed while this
+     * operation is pending */
+    g_assert (!self->priv->sim_ready_timeout_id);
+    g_assert (!self->priv->sim_ready_task);
+
+    G_OBJECT_CLASS (mm_broadband_modem_telit_parent_class)->finalize (object);
 }
 
 static void
@@ -1244,4 +1311,9 @@ iface_modem_3gpp_init (MMIfaceModem3gpp *iface)
 static void
 mm_broadband_modem_telit_class_init (MMBroadbandModemTelitClass *klass)
 {
+    GObjectClass *object_class = G_OBJECT_CLASS (klass);
+
+    g_type_class_add_private (object_class, sizeof (MMBroadbandModemTelitPrivate));
+
+    object_class->finalize = finalize;
 }
diff --git a/plugins/telit/mm-broadband-modem-telit.h b/plugins/telit/mm-broadband-modem-telit.h
index 50e6365..f68465e 100644
--- a/plugins/telit/mm-broadband-modem-telit.h
+++ b/plugins/telit/mm-broadband-modem-telit.h
@@ -29,9 +29,11 @@
 
 typedef struct _MMBroadbandModemTelit MMBroadbandModemTelit;
 typedef struct _MMBroadbandModemTelitClass MMBroadbandModemTelitClass;
+typedef struct _MMBroadbandModemTelitPrivate MMBroadbandModemTelitPrivate;
 
 struct _MMBroadbandModemTelit {
     MMBroadbandModem parent;
+    MMBroadbandModemTelitPrivate *priv;
 };
 
 struct _MMBroadbandModemTelitClass{
-- 
2.7.4

From 2fd60708481b14528831c243742696b3ccf7864b Mon Sep 17 00:00:00 2001
From: Carlo Lobrano <carlo.lobr...@telit.com>
Date: Mon, 20 Mar 2017 09:03:08 +0100
Subject: [PATCH 2/2] wip

---
 plugins/telit/mm-broadband-modem-telit.c | 23 ++++++++++++++++++++++-
 src/mm-base-modem-at.c                   |  3 +++
 src/mm-broadband-modem.c                 | 14 ++++++++++----
 src/mm-port-serial.c                     |  2 ++
 4 files changed, 37 insertions(+), 5 deletions(-)

diff --git a/plugins/telit/mm-broadband-modem-telit.c b/plugins/telit/mm-broadband-modem-telit.c
index 843d130..d611f27 100644
--- a/plugins/telit/mm-broadband-modem-telit.c
+++ b/plugins/telit/mm-broadband-modem-telit.c
@@ -41,9 +41,16 @@ static MMIfaceModem *iface_modem_parent;
 G_DEFINE_TYPE_EXTENDED (MMBroadbandModemTelit, mm_broadband_modem_telit, MM_TYPE_BROADBAND_MODEM, 0,
                         G_IMPLEMENT_INTERFACE (MM_TYPE_IFACE_MODEM, iface_modem_init)
                         G_IMPLEMENT_INTERFACE (MM_TYPE_IFACE_MODEM_3GPP, iface_modem_3gpp_init));
+typedef enum {
+    MM_TELIT_SIM_NOT_INSERTED,
+    MM_TELIT_SIM_INSERTED,
+    MM_TELIT_SIM_INSERTED_UNLOCKED,
+    MM_TELIT_SIM_INSERTED_READY
+} MM_TELIT_SIM_STATUS;
 
 struct _MMBroadbandModemTelitPrivate {
     /* Whether the SIM ready notification has been received */
+    MM_TELIT_SIM_STATUS sim_status;
     gboolean  sim_ready;
     GTask    *sim_ready_task;
     guint     sim_ready_timeout_id;
@@ -70,7 +77,10 @@ after_sim_unlock_ready (MMBroadbandModemTelit *self)
     g_assert (self->priv->sim_ready_timeout_id);
     g_assert (self->priv->sim_ready_task);
 
+    mm_dbg ("After SIM unlock: SIM readiness timeout %d expired. Continuing...", SIM_READY_TIMEOUT_SECS);
+
     self->priv->sim_ready_timeout_id = 0;
+    self->priv->sim_status = MM_TELIT_SIM_INSERTED;
 
     g_task_return_boolean (self->priv->sim_ready_task, TRUE);
     g_clear_object (&self->priv->sim_ready_task);
@@ -118,6 +128,7 @@ modem_after_sim_unlock (MMIfaceModem        *_self,
     }
 
     /* Wait for SIM readiness */
+    mm_dbg ("Waiting up to %d seconds for SIM readiness (#QSS: 3)", SIM_READY_TIMEOUT_SECS);
     self->priv->sim_ready_timeout_id = g_timeout_add_seconds (SIM_READY_TIMEOUT_SECS, (GSourceFunc) after_sim_unlock_ready, self);
 }
 
@@ -130,6 +141,8 @@ telit_qss_unsolicited_handler (MMPortSerialAt *port,
                                MMBroadbandModemTelit *self)
 {
     guint qss;
+    MM_TELIT_SIM_STATUS prev_status = self->priv->sim_status;
+    mm_info ("Prev QSS %d", prev_status);
 
     if (!mm_get_uint_from_match_info (match_info, 1, &qss))
         return;
@@ -140,16 +153,20 @@ telit_qss_unsolicited_handler (MMPortSerialAt *port,
 
             /* Flag as not ready */
             self->priv->sim_ready = FALSE;
+            self->priv->sim_status = MM_TELIT_SIM_NOT_INSERTED;
             modem_after_sim_unlock_cancel (self);
             break;
         case 1:
             mm_info ("QSS: SIM inserted");
+            self->priv->sim_status = MM_TELIT_SIM_INSERTED;
             break;
         case 2:
             mm_info ("QSS: SIM inserted and PIN unlocked");
+            self->priv->sim_status = MM_TELIT_SIM_INSERTED_UNLOCKED;
             break;
         case 3:
             mm_info ("QSS: SIM inserted and Ready");
+            self->priv->sim_status = MM_TELIT_SIM_INSERTED_READY;
             self->priv->sim_ready = TRUE;
             break;
         default:
@@ -157,7 +174,11 @@ telit_qss_unsolicited_handler (MMPortSerialAt *port,
             break;
     }
 
-    mm_broadband_modem_update_sim_hot_swap_detected (MM_BROADBAND_MODEM (self));
+    if ((prev_status == MM_TELIT_SIM_NOT_INSERTED && self->priv->sim_status >= MM_TELIT_SIM_INSERTED) ||
+        (prev_status >= MM_TELIT_SIM_INSERTED && self->priv->sim_status == MM_TELIT_SIM_NOT_INSERTED))
+        mm_broadband_modem_update_sim_hot_swap_detected (MM_BROADBAND_MODEM (self));
+    else
+        mm_dbg ("QSS: Nothing to do");
 }
 
 typedef struct {
diff --git a/src/mm-base-modem-at.c b/src/mm-base-modem-at.c
index 77661e5..215696e 100644
--- a/src/mm-base-modem-at.c
+++ b/src/mm-base-modem-at.c
@@ -20,6 +20,7 @@
 
 #include "mm-base-modem-at.h"
 #include "mm-errors-types.h"
+#include "mm-log.h"
 
 static gboolean
 abort_async_if_port_unusable (MMBaseModem *self,
@@ -342,6 +343,8 @@ mm_base_modem_at_sequence (MMBaseModem *self,
         return;
     }
 
+    mm_dbg("Using port %s",  mm_port_get_device (MM_PORT (port)));
+
     mm_base_modem_at_sequence_full (
         self,
         port,
diff --git a/src/mm-broadband-modem.c b/src/mm-broadband-modem.c
index 17b3253..cde0e21 100644
--- a/src/mm-broadband-modem.c
+++ b/src/mm-broadband-modem.c
@@ -434,6 +434,7 @@ parse_caps_gcap (MMBaseModem *self,
     const ModemCaps *cap = modem_caps;
     guint32 ret = 0;
 
+    mm_dbg ("parse_caps_gcap on '%s'", response);
     if (!response)
         return FALSE;
 
@@ -454,6 +455,7 @@ parse_caps_gcap (MMBaseModem *self,
         return FALSE;
 
     *variant = g_variant_new_uint32 (ret);
+    mm_dbg ("parse_caps_gcap on '%s' returning TRUE", response);
     return TRUE;
 }
 
@@ -519,8 +521,8 @@ parse_caps_cgmm (MMBaseModem *self,
 }
 
 static const MMBaseModemAtCommand capabilities[] = {
-    { "+GCAP",  2, TRUE,  parse_caps_gcap },
-    { "I",      1, TRUE,  parse_caps_gcap }, /* yes, really parse as +GCAP */
+    { "+GCAP",  1, FALSE,  parse_caps_gcap },
+    { "I",      1, FALSE,  parse_caps_gcap }, /* yes, really parse as +GCAP */
     { "+CPIN?", 1, FALSE, parse_caps_cpin },
     { "+CGMM",  1, TRUE,  parse_caps_cgmm },
     { NULL }
@@ -536,9 +538,11 @@ capabilities_sequence_ready (MMBaseModem *self,
 
     result = mm_base_modem_at_sequence_finish (self, res, NULL, &error);
     if (!result) {
-        if (error)
+        if (error) {
+            mm_dbg ("Caps sequence no result and error");
             g_simple_async_result_take_error (ctx->result, error);
-        else {
+        } else {
+            mm_dbg ("Caps sequence no result and no error");
             g_simple_async_result_set_error (ctx->result,
                                              MM_CORE_ERROR,
                                              MM_CORE_ERROR_FAILED,
@@ -551,6 +555,7 @@ capabilities_sequence_ready (MMBaseModem *self,
 
     ctx->caps = (MMModemCapability)g_variant_get_uint32 (result);
 
+
     /* Some modems (e.g. Sierra Wireless MC7710 or ZTE MF820D) won't report LTE
      * capabilities even if they have them. So just run AT+WS46=? as well to see
      * if the current supported modes includes any LTE-specific mode.
@@ -563,6 +568,7 @@ capabilities_sequence_ready (MMBaseModem *self,
      *   OK
      *
      */
+    mm_dbg ("Done with sequence, let's check ws46");
     if (ctx->caps & MM_MODEM_CAPABILITY_GSM_UMTS &&
         !(ctx->caps & MM_MODEM_CAPABILITY_LTE)) {
         mm_base_modem_at_command (
diff --git a/src/mm-port-serial.c b/src/mm-port-serial.c
index 470de03..a5f1626 100644
--- a/src/mm-port-serial.c
+++ b/src/mm-port-serial.c
@@ -700,6 +700,8 @@ port_serial_got_response (MMPortSerial *self,
     /* Either one or the other, not both */
     g_assert ((parsed_response && !error) || (!parsed_response && error));
 
+    mm_dbg ("Got response on port %s",  mm_port_get_device (MM_PORT (self)));
+
     if (self->priv->timeout_id) {
         g_source_remove (self->priv->timeout_id);
         self->priv->timeout_id = 0;
-- 
2.7.4

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

Reply via email to