sms sending times out too early?

[Aleksander Morgado]

Hey,

>> I just noticed that SMS sending failures with the MC7710 result in
>>
>>
>> ModemManager[6067]: <debug> [1387788544.392227] [mm-sms.c:178] generate_3gpp_submit_pdus():   Processing chunk '0' of text with '3' bytes
>> ModemManager[6067]: <debug> [1387788544.392344] [mm-sms.c:208] generate_3gpp_submit_pdus(): Created SMS part for singlepart SMS
>> ModemManager[6067]: <debug> [1387788544.392408] [mm-sms-part-3gpp.c:805] mm_sms_part_3gpp_get_submit_pdu(): Creating PDU for part...
>> ModemManager[6067]: <debug> [1387788544.392458] [mm-sms-part-3gpp.c:892] mm_sms_part_3gpp_get_submit_pdu():   using GSM7 encoding...
>> ModemManager[6067]: <debug> [1387788544.392519] [mm-sms-part-3gpp.c:957] mm_sms_part_3gpp_get_submit_pdu():   user data length is '3' septets (without UDH)
>> ModemManager[6067]: [/dev/cdc-wdm0] Sent message...
>> <<<<<< RAW:
>> <<<<<<   length = 76
>> <<<<<<   data   = 03:00:00:00:4C:00:00:00:25:00:00:00:01:00:00:00:00:00:00:00:53:3F:BE:EB:14:FE:44:67:9F:90:33:A2:23:E5:6C:3F:03:00:00:00:01:00:00:00:1C:00:00:00:00:00:00:00:08:00:00:00:10:00:00:00:00:01:00:0A:91:74:74:09:00:68:00:00:03:E6:F7:1B
>> ModemManager[6067]: [/dev/cdc-wdm0] Sent message (translated)...
>> <<<<<< Header:
>> <<<<<<   length      = 76
>> <<<<<<   type        = command (0x00000003)
>> <<<<<<   transaction = 37
>> <<<<<< Fragment header:
>> <<<<<<   total   = 1
>> <<<<<<   current = 0
>> <<<<<< Contents:
>> <<<<<<   service = 'sms' (533fbeeb-14fe-4467-9f90-33a223e56c3f)
>> <<<<<<   cid     = 'send' (0x00000003)
>> <<<<<<   type    = 'set' (0x00000001)
>>
>> ModemManager[6067]: [/dev/cdc-wdm0] Received message...
>> >>>>>> RAW:
>> >>>>>>   length = 48
>> >>>>>>   data   = 03:00:00:80:30:00:00:00:25:00:00:00:01:00:00:00:00:00:00:00:53:3F:BE:EB:14:FE:44:67:9F:90:33:A2:23:E5:6C:3F:03:00:00:00:02:00:00:00:00:00:00:00
>> ModemManager[6067]: [/dev/cdc-wdm0] No transaction matched in received message
>>
>>
>> And with times to show why the received message isn't matched with the
>> request:
>>
>>
>> Dec 23 09:49:04 nemi ModemManager[6067]: [/dev/cdc-wdm0] Sent message (translated)...#012<<<<<< Header:#012<<<<<<   length      = 76#012<<<<<<   type        = command (0x00000003)#012<<<<<<   transaction = 37#012<<<<<< Fragment header:#012<<<<<<   total   = 1#012<<<<<<   current = 0#012<<<<<< Contents:#012<<<<<<   service = 'sms' (533fbeeb-14fe-4467-9f90-33a223e56c3f)#012<<<<<<   cid     = 'send' (0x00000003)#012<<<<<<   type    = 'set' (0x00000001)
>> Dec 23 09:50:35 nemi ModemManager[6067]: [/dev/cdc-wdm0] Received message...#012>>>>>> RAW:#012>>>>>>   length = 48#012>>>>>>   data   = 03:00:00:80:30:00:00:00:25:00:00:00:01:00:00:00:00:00:00:00:53:3F:BE:EB:14:FE:44:67:9F:90:33:A2:23:E5:6C:3F:03:00:00:00:02:00:00:00:00:00:00:00
>>
>>
>> So the modem tries for 90 seconds before it decides to time out the
>> transaction.  I suspect that may apply to other transactions which may
>> time out as well..
>>
>> Maybe libmbim needs to wait that long as well?
>>
>>
>
> Yeah, probably something to change in ModemManager itself; as each
> libmbim command request has the timeout specified as an input
> parameter. Will add it to my TODO list.

I'm guessing that the timeout to decide that an SMS cannot be sent is
device specific... and 90s really seems too much to me. Should we
really increase the default timeout to >90s? With which device did you
get this timeout? I'm tempted to just increase the default timeout in
MBIM's SMS send from 10s (which is likely too low) to e.g. 30s (which
is what we have in the QMI implementation). But that wouldn't solve
your issue, you would still get the unmatched response if the modem
times out at 90s.

What do others think?

-- 
Aleksander