<div dir="ltr">lgtm</div><div class="gmail_extra"> <div class="gmail_quote">On Sun, Aug 6, 2017 at 8:08 AM, Aleksander Morgado <<a href="mailto:aleksander@aleksander.es" target="_blank">aleksander@aleksander.es</a>> wrote: <blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">If we try to 'MBIM open' the channel with a Sierra Wireless EM7345 (FIH7160_V1.1_MODEM_01.1349.12) and the channel is already open in the device (e.g. mbim-proxy crashed and we try to reopen, or just running consecutive mbimcli commands with --no-close), the device returns a 'MBIM close done' message for every 'MBIM open' request we send. We update the logic to try to detect this case, and if we do, we launch an explicit 'MBIM close' operation before retrying the 'MBIM open' again. E.g. this is the flow when trying to run mbimcli command while the MBIM channel is already open in the device side: $ mbimcli -d /dev/cdc-wdm1 --query-device-caps --no-close --verbose [06 ago 2017, 16:58:21] [Debug] opening device... [06 ago 2017, 16:58:21] [Debug] [/dev/cdc-wdm1] Queried max control message size: 512 [06 ago 2017, 16:58:21] [Debug] [/dev/cdc-wdm1] Sent message... <<<<<< RAW: <<<<<< length = 16 <<<<<< data = 01:00:00:00:10:00:00:00:01:00:00:00:00:02:00:00 [06 ago 2017, 16:58:21] [Debug] [/dev/cdc-wdm1] Sent message (translated)... <<<<<< Header: <<<<<< length = 16 <<<<<< type = open (0x00000001) <<<<<< transaction = 1 <<<<<< Contents: <<<<<< max_control_transfer = 512 [06 ago 2017, 16:58:21] [Debug] [/dev/cdc-wdm1] Received message... >>>>>> RAW: >>>>>> length = 16 >>>>>> data = 02:00:00:80:10:00:00:00:02:00:00:00:00:00:00:00 [06 ago 2017, 16:58:21] [Debug] [/dev/cdc-wdm1] No transaction matched in received message [06 ago 2017, 16:58:21] [Debug] [/dev/cdc-wdm1] Received unexpected message (translated)... >>>>>> Header: >>>>>> length = 16 >>>>>> type = close-done (0x80000002) >>>>>> transaction = 2 >>>>>> Contents: >>>>>> status error = 'None' (0x00000000) [06 ago 2017, 16:58:21] [Debug] [/dev/cdc-wdm1] Sent message... <<<<<< RAW: <<<<<< length = 12 <<<<<< data = 02:00:00:00:0C:00:00:00:02:00:00:00 [06 ago 2017, 16:58:21] [Debug] [/dev/cdc-wdm1] Sent message (translated)... <<<<<< Header: <<<<<< length = 12 <<<<<< type = close (0x00000002) <<<<<< transaction = 2 [06 ago 2017, 16:58:21] [Debug] [/dev/cdc-wdm1] Received message... >>>>>> RAW: >>>>>> length = 16 >>>>>> data = 02:00:00:80:10:00:00:00:02:00:00:00:00:00:00:00 [06 ago 2017, 16:58:21] [Debug] [/dev/cdc-wdm1] Sent message... <<<<<< RAW: <<<<<< length = 16 <<<<<< data = 01:00:00:00:10:00:00:00:03:00:00:00:00:02:00:00 [06 ago 2017, 16:58:21] [Debug] [/dev/cdc-wdm1] Sent message (translated)... <<<<<< Header: <<<<<< length = 16 <<<<<< type = open (0x00000001) <<<<<< transaction = 3 <<<<<< Contents: <<<<<< max_control_transfer = 512 [06 ago 2017, 16:58:21] [Debug] [/dev/cdc-wdm1] Received message... >>>>>> RAW: >>>>>> length = 16 >>>>>> data = 01:00:00:80:10:00:00:00:03:00:00:00:00:00:00:00 [06 ago 2017, 16:58:21] [Debug] MBIM Device at '/dev/cdc-wdm1' ready --- src/libmbim-glib/mbim-device.c | 114 +++++++++++++++++++++++++++++++++++++++-- src/libmbim-glib/mbim-errors.h | 6 ++- 2 files changed, 115 insertions(+), 5 deletions(-) diff --git a/src/libmbim-glib/mbim-device.c b/src/libmbim-glib/mbim-device.c index 775c2fd..3c20bd8 100644 --- a/src/libmbim-glib/mbim-device.c +++ b/src/libmbim-glib/mbim-device.c @@ -37,7 +37,9 @@ #include <gio/gunixsocketaddress.h> #include <sys/ioctl.h> #define IOCTL_WDM_MAX_COMMAND _IOR('H', 0xA0, guint16) -#define RETRY_TIMEOUT_SECS 5 + +#define OPEN_RETRY_TIMEOUT_SECS 5 +#define OPEN_CLOSE_TIMEOUT_SECS 2 #if defined WITH_UDEV # include <gudev/gudev.h> @@ -111,6 +113,7 @@ struct _MbimDevicePrivate { GSource *iochannel_source; GByteArray *response; OpenStatus open_status; + guint32 open_transaction_id; /* Support for mbim-proxy */ GSocketClient *socket_client; @@ -485,6 +488,33 @@ indication_ready (MbimDevice *self, } static void +finalize_pending_open_request (MbimDevice *self) +{ + Transaction *tr; + GError *error = NULL; + + if (!self->priv->open_transaction_id) + return; + + /* Grab transaction. This is a _DONE message, so look for the request + * that generated the _DONE */ + tr = device_release_transaction (self, + TRANSACTION_TYPE_HOST, + MBIM_MESSAGE_TYPE_OPEN, + self->priv->open_transaction_id); + + /* If there is a valid open_transaction_id, there must be a valid transaction */ + g_assert (tr); + + /* Clear right away before completing the transaction */ + self->priv->open_transaction_id = 0; + + error = g_error_new (MBIM_CORE_ERROR, MBIM_CORE_ERROR_UNKNOWN_STATE, "device state is unknown"); + transaction_complete_and_free (tr, error); + g_error_free (error); +} + +static void process_message (MbimDevice *self, const MbimMessage *message) { @@ -561,6 +591,14 @@ process_message (MbimDevice *self, printable); g_free (printable); } + + /* If we're opening and we get a CLOSE_DONE message without any + * matched transaction, finalize the open request right away to + * trigger a close before open */ + if (self->priv->open_status == OPEN_STATUS_OPENING && + MBIM_MESSAGE_GET_MESSAGE_TYPE (message) == MBIM_MESSAGE_TYPE_CLOSE_DONE) + finalize_pending_open_request (self); + return; } @@ -1209,6 +1247,7 @@ typedef enum { DEVICE_OPEN_CONTEXT_STEP_FIRST = 0, DEVICE_OPEN_CONTEXT_STEP_CREATE_IOCHANNEL, DEVICE_OPEN_CONTEXT_STEP_FLAGS_PROXY, + DEVICE_OPEN_CONTEXT_STEP_CLOSE_MESSAGE, DEVICE_OPEN_CONTEXT_STEP_OPEN_MESSAGE, DEVICE_OPEN_CONTEXT_STEP_LAST } DeviceOpenContextStep; @@ -1218,6 +1257,7 @@ typedef struct { MbimDeviceOpenFlags flags; guint timeout; GTimer *timer; + gboolean close_before_open; } DeviceOpenContext; static void @@ -1278,8 +1318,19 @@ open_message_ready (MbimDevice *self, ctx = g_task_get_task_data (task); + /* Cleanup, as no longer needed */ + self->priv->open_transaction_id = 0; + response = mbim_device_command_finish (self, res, &error); if (!response) { + /* If we get reported that the state is unknown, try to close before open */ + if (g_error_matches (error, MBIM_CORE_ERROR, MBIM_CORE_ERROR_UNKNOWN_STATE)) { + ctx->close_before_open = TRUE; + ctx->step = DEVICE_OPEN_CONTEXT_STEP_CLOSE_MESSAGE; + device_open_context_step (task); + return; + } + /* Check if we should be retrying after a timeout */ if (g_error_matches (error, MBIM_CORE_ERROR, MBIM_CORE_ERROR_TIMEOUT)) { /* Retry same step */ @@ -1319,11 +1370,12 @@ open_message (GTask *task) self = g_task_get_source_object (task); /* Launch 'Open' command */ - request = mbim_message_open_new (mbim_device_get_next_transaction_id (self), + self->priv->open_transaction_id = mbim_device_get_next_transaction_id (self); + request = mbim_message_open_new (self->priv->open_transaction_id, self->priv->max_control_transfer); mbim_device_command (self, request, - RETRY_TIMEOUT_SECS, + OPEN_RETRY_TIMEOUT_SECS, g_task_get_cancellable (task), (GAsyncReadyCallback)open_message_ready, task); @@ -1331,6 +1383,51 @@ open_message (GTask *task) } static void +close_message_before_open_ready (MbimDevice *self, + GAsyncResult *res, + GTask *task) +{ + DeviceOpenContext *ctx; + MbimMessage *response; + GError *error = NULL; + + ctx = g_task_get_task_data (task); + + response = mbim_device_command_finish (self, res, &error); + if (!response) + g_debug ("error reported in close before open: %s (ignored)", error->message); + else if (!mbim_message_response_get_result (response, MBIM_MESSAGE_TYPE_CLOSE_DONE, &error)) + g_debug ("getting close done result failed: %s (ignored)", error->message); + + g_clear_error (&error); + if (response) + mbim_message_unref (response); + + /* go on */ + ctx->step++; + device_open_context_step (task); +} + +static void +close_message_before_open (GTask *task) +{ + MbimDevice *self; + MbimMessage *request; + + self = g_task_get_source_object (task); + + /* Launch 'Close' command */ + request = mbim_message_close_new (mbim_device_get_next_transaction_id (self)); + mbim_device_command (self, + request, + OPEN_CLOSE_TIMEOUT_SECS, + g_task_get_cancellable (task), + (GAsyncReadyCallback)close_message_before_open_ready, + task); + mbim_message_unref (request); +} + +static void proxy_cfg_message_ready (MbimDevice *self, GAsyncResult *res, GTask *task) @@ -1466,6 +1563,16 @@ device_open_context_step (GTask *task) ctx->step++; /* Fall down */ + case DEVICE_OPEN_CONTEXT_STEP_CLOSE_MESSAGE: + /* Only send an explicit close during open if needed */ + if (ctx->close_before_open) { + ctx->close_before_open = FALSE; + close_message_before_open (task); + return; + } + ctx->step++; + /* Fall down */ + case DEVICE_OPEN_CONTEXT_STEP_OPEN_MESSAGE: /* If the device is already in-session, avoid the open message */ if (!self->priv->in_session) { @@ -1525,6 +1632,7 @@ mbim_device_open_full (MbimDevice *self, ctx->flags = flags; ctx->timeout = timeout; ctx->timer = g_timer_new (); + ctx->close_before_open = FALSE; task = g_task_new (self, cancellable, callback, user_data); g_task_set_task_data (task, ctx, (GDestroyNotify)device_open_context_free); diff --git a/src/libmbim-glib/mbim-errors.h b/src/libmbim-glib/mbim-errors.h index 2c7d177..064660b 100644 --- a/src/libmbim-glib/mbim-errors.h +++ b/src/libmbim-glib/mbim-errors.h @@ -49,7 +49,8 @@ * @MBIM_CORE_ERROR_INVALID_ARGS: Invalid arguments given. * @MBIM_CORE_ERROR_INVALID_MESSAGE: MBIM message is invalid. * @MBIM_CORE_ERROR_UNSUPPORTED: Not supported. - * @MBIM_CORE_ERROR_ABORTED: Operation aborted.. + * @MBIM_CORE_ERROR_ABORTED: Operation aborted. + * @MBIM_CORE_ERROR_UNKNOWN_STATE: State is unknown. * * Common errors that may be reported by libmbim-glib. */ @@ -60,7 +61,8 @@ typedef enum { /*< underscore_name=mbim_core_error >*/ MBIM_CORE_ERROR_INVALID_ARGS = 3, /*< nick=InvalidArgs >*/ MBIM_CORE_ERROR_INVALID_MESSAGE = 4, /*< nick=InvalidMessage >*/ MBIM_CORE_ERROR_UNSUPPORTED = 5, /*< nick=Unsupported >*/ - MBIM_CORE_ERROR_ABORTED = 6 /*< nick=Aborted >*/ + MBIM_CORE_ERROR_ABORTED = 6, /*< nick=Aborted >*/ + MBIM_CORE_ERROR_UNKNOWN_STATE = 7 /*< nick=UnknownState >*/ } MbimCoreError; /** -- 2.13.3 </blockquote></div> </div>