GNOME Bugzilla – Bug 696724
[MM 0.8] umw190: SM message storage hangs device's AT interpreter
Last modified: 2013-04-02 07:54:50 UTC
Sigh. It seems that grabbing the messages out of SIM storage hangs the AT interpreter, but the QCDM port still works just fine, oddly: ModemManager[30613]: <debug> [1364406386.366501] [mm-at-serial-port.c:397] debug_log(): (ttyACM0): --> 'AT+CNMI=?<CR>' ModemManager[30613]: <debug> [1364406386.383924] [mm-at-serial-port.c:397] debug_log(): (ttyACM0): <-- '<CR><LF>+CNMI: (0,1,2),(0,1,2,3),(0,2),(0),(0,1)<CR><LF><CR><LF>OK<CR><LF>' ModemManager[30613]: <debug> [1364406386.384238] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM0) device open count is 3 (open) ModemManager[30613]: <debug> [1364406386.384327] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 2 (close) ModemManager[30613]: <debug> [1364406386.384407] [mm-at-serial-port.c:397] debug_log(): (ttyACM0): --> 'AT+CPMS=?<CR>' ModemManager[30613]: <debug> [1364406386.402646] [mm-at-serial-port.c:397] debug_log(): (ttyACM0): <-- '<CR><LF>+CPMS: ("ME","MT","SM","SR"),("ME","MT"),("ME","MT")<CR><LF><CR><LF>OK<CR><LF>' ModemManager[30613]: <debug> [1364406386.402995] [mm-iface-modem-messaging.c:1113] load_supported_storages_ready(): Supported storages loaded: ModemManager[30613]: <debug> [1364406386.403047] [mm-iface-modem-messaging.c:1114] load_supported_storages_ready(): mem1 (list/read/delete) storages: 'me, mt, sm, sr' ModemManager[30613]: <debug> [1364406386.403083] [mm-iface-modem-messaging.c:1115] load_supported_storages_ready(): mem2 (write/send) storages: 'me, mt' ModemManager[30613]: <debug> [1364406386.403115] [mm-iface-modem-messaging.c:1116] load_supported_storages_ready(): mem3 (reception) storages: 'me, mt' <snip> ModemManager[30613]: <debug> [1364406401.778227] [mm-at-serial-port.c:397] debug_log(): (ttyACM0): --> 'AT+CPMS="","MT","MT"<CR>' ModemManager[30613]: <debug> [1364406401.855441] [mm-at-serial-port.c:397] debug_log(): (ttyACM0): <-- '<CR><LF>+CPMS: 9,240,9,240,9,240<CR><LF><CR><LF>OK<CR><LF>' ModemManager[30613]: <debug> [1364406401.855562] [mm-broadband-modem.c:5843] modem_messaging_load_initial_sms_parts(): Listing SMS parts in storage 'me' ModemManager[30613]: <debug> [1364406401.855585] [mm-broadband-modem.c:5026] mm_broadband_modem_lock_sms_storages(): Locking SMS storages to: mem1 (ME), mem2 (none)... ModemManager[30613]: <debug> [1364406401.855614] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM0) device open count is 3 (open) ModemManager[30613]: <debug> [1364406401.855648] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 2 (close) ModemManager[30613]: <debug> [1364406401.855699] [mm-at-serial-port.c:397] debug_log(): (ttyACM0): --> 'AT+CPMS="ME"<CR>' ModemManager[30613]: <debug> [1364406401.897791] [mm-at-serial-port.c:397] debug_log(): (ttyACM0): <-- '<CR><LF>+CPMS: 9,240,9,240,9,240<CR><LF><CR><LF>OK<CR><LF>' ModemManager[30613]: <debug> [1364406401.898007] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM0) device open count is 3 (open) ModemManager[30613]: <debug> [1364406401.898093] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 2 (close) ModemManager[30613]: <debug> [1364406401.898168] [mm-at-serial-port.c:397] debug_log(): (ttyACM0): --> 'AT+CMGL=4<CR>' ModemManager[30613]: <debug> [1364406402.020859] [mm-at-serial-port.c:397] debug_log(): (ttyACM0): <-- '<CR><LF>+CMGL: 17,3,35<CR><LF>079100F40D1101000F001000B917118336058F300001954747A0E4ACF41F27298CDCE83C6EF371B0402814020<CR><LF>+CMGL: 15,3,35<CR><LF>079100F40D1101000F001000B917118336058F300001954747A0E4ACF41F27298CDCE83C6EF371B0402814020<CR><LF>+CMGL: 13,3,35<CR><LF>079100F40D1101000F001000B917118336058F300001954747A0E4ACF41F27298CDCE83C6EF371B0402814020<CR><LF>+CMGL: 11,3,35<CR><LF>079100F40D1101000F001000B917118336058F300 ModemManager[30613]: <debug> [1364406402.021226] [mm-iface-modem-messaging.c:762] load_initial_sms_parts_ready(): Couldn't load SMS parts from storage 'me': 'Couldn't parse SMS list response: only 2 fields parsed' ModemManager[30613]: <debug> [1364406402.021285] [mm-broadband-modem.c:5843] modem_messaging_load_initial_sms_parts(): Listing SMS parts in storage 'sm' ModemManager[30613]: <debug> [1364406402.021329] [mm-broadband-modem.c:5026] mm_broadband_modem_lock_sms_storages(): Locking SMS storages to: mem1 (SM), mem2 (none)... ModemManager[30613]: <debug> [1364406402.021396] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM0) device open count is 3 (open) ModemManager[30613]: <debug> [1364406402.021470] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 2 (close) ModemManager[30613]: <debug> [1364406402.021563] [mm-at-serial-port.c:397] debug_log(): (ttyACM0): --> 'AT+CPMS="SM"<CR>' ModemManager[30613]: <debug> [1364406402.063213] [mm-at-serial-port.c:397] debug_log(): (ttyACM0): <-- '<CR><LF>+CPMS: 0,30,9,240,9,240<CR><LF><CR><LF>OK<CR><LF>' ModemManager[30613]: <debug> [1364406402.063343] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM0) device open count is 3 (open) ModemManager[30613]: <debug> [1364406402.063384] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 2 (close) ModemManager[30613]: <debug> [1364406402.063418] [mm-at-serial-port.c:397] debug_log(): (ttyACM0): --> 'AT+CMGL=4<CR>' ModemManager[30613]: <debug> [1364406422.035998] [mm-iface-modem-messaging.c:762] load_initial_sms_parts_ready(): Couldn't load SMS parts from storage 'sm': 'Serial command timed out' ModemManager[30613]: <debug> [1364406422.036146] [mm-broadband-modem.c:5843] modem_messaging_load_initial_sms_parts(): Listing SMS parts in storage 'sr' ModemManager[30613]: <debug> [1364406422.036219] [mm-broadband-modem.c:5026] mm_broadband_modem_lock_sms_storages(): Locking SMS storages to: mem1 (SR), mem2 (none)... ModemManager[30613]: <debug> [1364406422.036315] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM0) device open count is 3 (open) ModemManager[30613]: <debug> [1364406422.036441] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 2 (close) ModemManager[30613]: <debug> [1364406422.036639] [mm-at-serial-port.c:397] debug_log(): (ttyACM0): --> 'AT+CPMS="SR"<CR>' ModemManager[30613]: <debug> [1364406425.019191] [mm-iface-modem-messaging.c:762] load_initial_sms_parts_ready(): Couldn't load SMS parts from storage 'sr': 'Serial command timed out' Not really sure what we should do here...
The 'aleksander/pantech-sms-fixes' branch in MM git tries to handle this issue by fully ignoring SM storage. It is not a patch specific to the UMW190, but applicable to the whole pantech plugin, but I don't think it would be very difficult to make it UMW190-specific, if needed.
It seems we need to kill both SM and SR storage. Pushed a fixup commit for that. One question though: for load_supported_storages_finish() will mem1/mem2/mem3 *always* be !NULL? If we can't guarantee that, then we need additional protection for the skip_sm_sr_storage() calls. Other than that, the storage fix appears to work on the 190 so this bug is fixed. SMS parsing fails for other reasons, see bug 696723.
Given that bug 696723 needs more investigation and I can't immediately decode the PDUs the thing is sending, lets merge your pantech branch along with the fixup I pushed and close this bug.
Merged to git master.