Sometimes receiving multiple parts SMS failed
I am using ModemManager 1.20.6. Sometimes receiving multiple parts SMS would failed and the SMS status is always receiving.
/ # mmcli -m 0 --messaging-list-sms
/org/freedesktop/ModemManager1/SMS/3 (receiving)
/org/freedesktop/ModemManager1/SMS/2 (sent)
/org/freedesktop/ModemManager1/SMS/0 (stored)
We debuged and found that some parts of SMS read failed because not obtained the storage lock.
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.511865] Got new message from cmti
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.512196] ========= idx=2, storage=SM ===========
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.512522] [modem0] locking SMS storages to: mem1 (SM), mem2 (none)...
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.601202] [modem0] parsing PDU (2)...
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.601234] [modem0] SMSC address parsed: '+460030934260200'
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.601692] [modem0] deliver type PDU detected
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.601977] [modem0] number parsed: 10001
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.602314] [modem0] PID: 0
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.602543] [modem0] user data encoding is UCS2
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.603011] [modem0] user data length: 136 elements
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.603923] [modem0] user data length: 136 bytes
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.605001] [modem0] decoding SMS text with 130 elements
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.605918] [modem0] converted SMS part text from UTF-16BE to UTF-8: xxxxxxxx
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.607123] [modem0] correctly parsed PDU (2)
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.607894] [modem0/sms-list] SMS part at 'mt/2' is from a multipart SMS (reference: '133', sequence: '1/6')
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.609343] [modem0/sms-list] creating new multipart SMS object: need to receive 6 parts with reference '133'
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.672126] Got new message from cmti
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.672181] ========= idx=3, storage=SM ===========
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.672264] [modem0] locking SMS storages to: mem1 (SM), mem2 (none)...
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.792189] Got new message from cmti
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.792524] ========= idx=4, storage=SM ===========
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.793167] [modem0] parsing PDU (3)...
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.793596] [modem0] SMSC address parsed: '+460030934260200'
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.794350] [modem0] deliver type PDU detected
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.794821] [modem0] number parsed: 10001
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.795472] [modem0] PID: 0
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.796429] [modem0] user data encoding is UCS2
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.797590] [modem0] user data length: 136 elements
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.798764] [modem0] user data length: 136 bytes
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.800051] [modem0] decoding SMS text with 130 elements
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.801155] [modem0] converted SMS part text from UTF-16BE to UTF-8: xxxxxxxxxxx
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.802162] [modem0] correctly parsed PDU (3)
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.802970] [modem0/sms-list] SMS part at 'mt/3' is from a multipart SMS (reference: '133', sequence: '2/6')
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.804019] [modem0/sms-list] found existing multipart SMS object with reference '133': adding new part
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.987866] Got new message from cmti
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.988112] ========= idx=5, storage=SM ===========
[22/03/2024 10:09:37]ModemManager:<debug> [1711102177.988419] [modem0] locking SMS storages to: mem1 (SM), mem2 (none)...
In this case, part 3 (idx=4) read failed because part 2 (idx=3) is under reading holding the storage lock. Will failed in : src/mm-broadband-modem.c +7138 cmti_received => mm_broadband_modem_lock_sms_storages => indication_lock_storages_ready
Do not retry when failed in indication_lock_storages_ready.
if (!mm_broadband_modem_lock_sms_storages_finish (self, res, &error)) {
/* TODO: we should either make this lock() never fail, by automatically
* retrying after some time, or otherwise retry here. */
g_task_return_error (task, error);
g_object_unref (task);
return;
}
Edited by Jacken Zhang