AT command related MC7710 firmware crash in QMI mode

Bjørn Mork bjorn at mork.no
Tue Nov 19 03:31:01 PST 2013


Aleksander Morgado <aleksander at lanedo.com> writes:

> On 18/11/13 14:40, Bjørn Mork wrote:
>> This is obviously the modem crash day....
>> 
>> Attempting to use my MC7710 in QMI mode resulted in:
>> 
>> 
>> ModemManager[2586]: <debug> [1384781593.512071] [mm-serial-port.c:1015] mm_serial_port_close(): (ttyUSB2) device open count is 3 (close)
>> ModemManager[2586]: <debug> [1384781593.512389] [mm-at-serial-port.c:436] debug_log(): (ttyUSB2): --> 'AT+CGREG?<CR>'
>> ModemManager[2586]: <debug> [1384781593.531057] [mm-at-serial-port.c:436] debug_log(): (ttyUSB2): <-- '<CR><LF>+CGREG: 2,2<CR><LF><CR><LF>OK<CR><LF>'
>> ModemManager[2586]: <debug> [1384781593.531537] [mm-serial-port.c:1015] mm_serial_port_close(): (ttyUSB2) device open count is 2 (close)
>> ModemManager[2586]: <debug> [1384781593.531888] [mm-at-serial-port.c:436] debug_log(): (ttyUSB2): --> 'AT+CMGF=0<CR>'
>> ModemManager[2586]: <debug> [1384781593.547581] [mm-at-serial-port.c:436] debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
>> ModemManager[2586]: <debug> [1384781593.548057] [mm-broadband-modem.c:5457] cmgf_set_ready(): Successfully set preferred SMS mode: 'PDU'
>> ModemManager[2586]: <debug> [1384781593.548483] [mm-serial-port.c:969] mm_serial_port_open(): (ttyUSB2) device open count is 3 (open)
>> ModemManager[2586]: <debug> [1384781593.548798] [mm-serial-port.c:1015] mm_serial_port_close(): (ttyUSB2) device open count is 2 (close)
>> ModemManager[2586]: <debug> [1384781593.549357] [mm-at-serial-port.c:436] debug_log(): (ttyUSB2): --> 'AT+CPMS="","MT","MT"<CR>'
>> ModemManager[2586]: <debug> [1384781593.585950] [mm-at-serial-port.c:436] debug_log(): (ttyUSB2): <-- '<CR><LF>+CPMS: 0,20,31,255,31,255<CR><LF><CR><LF>OK<CR><LF>'
>> ModemManager[2586]: <debug> [1384781593.586418] [mm-broadband-modem.c:6155] modem_messaging_load_initial_sms_parts(): Listing SMS parts in storage 'me'
>> ModemManager[2586]: <debug> [1384781593.586772] [mm-broadband-modem.c:5351] mm_broadband_modem_lock_sms_storages(): Locking SMS storages to: mem1 (ME), mem2 (none)...
>> ModemManager[2586]: <debug> [1384781593.587068] [mm-serial-port.c:969] mm_serial_port_open(): (ttyUSB2) device open count is 3 (open)
>> ModemManager[2586]: <debug> [1384781593.587397] [mm-serial-port.c:1015] mm_serial_port_close(): (ttyUSB2) device open count is 2 (close)
>> ModemManager[2586]: <debug> [1384781593.587701] [mm-at-serial-port.c:436] debug_log(): (ttyUSB2): --> 'AT+CPMS="ME"<CR>'
>> ModemManager[2586]: <debug> [1384781593.605809] [mm-at-serial-port.c:436] debug_log(): (ttyUSB2): <-- '<CR><LF>+CPMS: 31,255,31,255,31,255<CR><LF><CR><LF>OK<CR><LF>'
>> ModemManager[2586]: <debug> [1384781593.606307] [mm-serial-port.c:969] mm_serial_port_open(): (ttyUSB2) device open count is 3 (open)
>> ModemManager[2586]: <debug> [1384781593.607037] [mm-serial-port.c:1015] mm_serial_port_close(): (ttyUSB2) device open count is 2 (close)
>> ModemManager[2586]: <debug> [1384781593.607389] [mm-at-serial-port.c:436] debug_log(): (ttyUSB2): --> 'AT+CMGL=4<CR>'
>> ModemManager[2586]: <debug> [1384781593.645543] [mm-at-serial-port.c:436] debug_log(): (ttyUSB2): <-- '<CR><LF>+CMGL: 0,1,,155<CR><LF>06917409001200400481919900F131503021911580A0060804E6CB030149B7F90D32CBC3206A995D76BFE53A90350D3AAB197210B97C06BDE1F07659BE9EBFDB20F80314A683C875103A2C07C1C3F379594E07A5DD6B769D5C96D341E4303DDC2EBBCFE432885C76BBCBA0F6C35D2697DD2E90F12D07C1E5E979DA6D7ECBDBE1B9FAED06CDCB207A995D76BFE52EF7FB252E93E56933FDE5024DEB7273590E22D741<CR><LF>+CMGL: 1,1,,155<CR><LF>06917409001200400481919900F131503021912580A0060804E6CB0302ECF4BA0C6AE7CBA0B09B2C2F83DA0F77995C9683DEE7F983055A87DD2072990E6233DCEE32685E3E831E20741854A683C2E2B7DB5D6E97DD7450BB4C06CDE90CB9BC0C2287E9E176D97D26975D2069DA7D06C17230180C5466B3CB72D0BC0CA297D965F75BEE72BF5FE232599E36D35DA0A2BDECA6D7CB6C3A681D7683C875D05ACD809741<CR><LF>+CMGL: 2,1,,139<CR><LF>06917409001200440481919900F1315030219135808D060804E6CB03036537A8BC9ED3E56110394C0FC3C3EB7519047F8062A0A310444FB341B91C682D7781A0E1F5BAEC06D9C3F2
>  B21C54A78
> 3C865B7BB0C5A87D96537B92C6F3FDC6572D9ED0281A0E1F5BAEC06ADC36E90B83CA7A7D9ECF21C642F93410FD0BCEC269741C2E2949A643241B1A310444FB341B15C2EE702<CR><LF>+CMGL: 3,1,,155<CR><LF>06917409001200400481919900F131503021039080A0060804E8F6030149B7F90D32CBC3206A995D76BFE53A10B10E4287E520F7032496D7D774100E560285ED207A9A7D5697DDE7323B7D0691C3F470BBEC3E93CB2072D9ED2E83DA0F77995C76BB40D634A89D76BBCB72D0BB0D0AD341E8F09C9E3EA3CBF4B21B644FB34162761A242F93EBF3B29C0EA2A7D9A0980C075A8BD3F4D71CE47EC841F434FBAC2EBBCF<CR><LF>+CMGL: 4,1,,155<CR><LF>06917409001200400481919900F131503021030180A0060804E8F603026576FA0C2287E9E176D97D2697416539482CAFAFE9A0371CEE0215ED6537BD5E66D341EBB01B44AE83D66A06BC0C2ABB41E5F59C2E0F83C86'
>> ModemManager[2586]: <debug> [1384781593.663179] [mm-at-serial-port.c:436] debug_log(): (ttyUSB2): <-- '17A181E5EAFCB20F80314031D85207A9A0DCAE5406BB90B040DAFD76537C81E9697E5A03A1D442EBBDD65D03ACC2EBBC96579FBE12E93CB6E1708040DAFD76537681D7683C4E5393DCD6697E7<CR><LF>+CMGL: 5,1,,141<CR><LF>06917409001200440481919900F13150302103118090060804E8F60303207B990C7A80E66537B90C1216A7D42493098A1D85207A9A0D8AE57239174828AFAFCB7210B90EA2CA1F6436630E9ABEDD65903DCD06A5D7EB32885CA6D3CBA0F30314B683E869F6595D769FCBECF419440ED3C3EDB2FB4C2EBB40D332C89E66AF1F7210FC01A297D965F75BEE72BF5FE232599E36D35D<CR><LF>+CMGL: 6,1,,155<CR><LF>06917409001200400481919900F131503021238180A0060804E958030149B7F90D32CBC3206A995D76BFE53A90350D3AAB1972D01B0E6F97E5EBF9BB0D823F40613A885C07B91F2074580E12CBEB6B3AE80D8783E869F6595D769FCBECF419440ED3C3EDB2FB4C2E83C865B7BB0C6A3FDC6572D9ED0225D174903DCD5E3FE4657719242F93EBF3B2BC3C07A1C3737AFA8C2ED3CB6E103DCD06C56438D05A9CA6BFE6<CR><LF>+CMGL: 7,1,,155<CR><LF>0691740900120040048
>  1919900F1
> 31503021239180A0060804E95803022E50D15E76D3EB65361DB40EBB41E43A68AD66C0CBA0B21B545ECFE9F230881CA687E1E1F5BA0C823F4031D05108A2A7D9A05C0EB496BB40D0F07A5D7683EC6179590EAAD341E4B2DB5D06ADC3ECB29B5C96B71FEE32B9EC768140D0F07A5D7683D66137485C9ED3D36C76790EB297C9A007685E7693CB2061714A4D3299A0D85108A2A7D9<CR><LF>+CMGL: 8,1,,106<CR><LF>06917409001200440481919900F13150302123028068060804E9580303A0582E9773819CE539BD0C6A3FDC6532C89E6683C87550B84E7FB7C3F4F47C0D323F40F6B09B9D3E83D0E1393D7D4697E9A0F4595D76BB40D332C89E66AF1F7210FC01A297D965F75BEE72BF5FE232599E36D35D<CR><LF>+CMGL: 9,1,,155<CR><LF>06917409001200400481919900F131507001747180A0060804AE73030149B7F90D32CBC3206A995D76BFE53A90350D3AAB1972D01B0E6F97'
>> ModemManager[2586]: <debug> [1384781594.653047] [mm-serial-port.c:752] data_available(): (ttyUSB0) unexpected port hangup!
>> ModemManager[2586]: <debug> [1384781594.653188] [mm-serial-port.c:1139] mm_serial_port_close_force(): (ttyUSB0) forced to close port
>> ModemManager[2586]: <debug> [1384781594.653241] [mm-serial-port.c:1015] mm_serial_port_close(): (ttyUSB0) device open count is 0 (close)
>> ModemManager[2586]: <debug> [1384781594.653295] [mm-serial-port.c:1031] mm_serial_port_close(): (ttyUSB0) closing serial port...
>> ModemManager[2586]: <debug> [1384781594.653411] [mm-serial-port.c:1064] mm_serial_port_close(): (ttyUSB0) serial port closed
>> ModemManager[2586]: <debug> [1384781594.658968] [mm-serial-port.c:752] data_available(): (ttyUSB2) unexpected port hangup!
>> ModemManager[2586]: <debug> [1384781594.659087] [mm-serial-port.c:1139] mm_serial_port_close_force(): (ttyUSB2) forced to close port
>> ModemManager[2586]: <debug> [1384781594.659183] [mm-serial-port.c:1015] mm_serial_port_close(): (ttyUSB2) device open count is 0 (close)
>> ModemManager[2586]: <debug> [1384781594.659238] [mm-serial-port.c:1031] mm_serial_port_close(): (ttyUSB2) closing serial port...
>> ModemManager[2586]: <debug> [1384781594.659338] [mm-serial-port.c:1064] mm_serial_port_close(): (ttyUSB2) serial port closed
>> ModemManager[2586]: <debug> [1384781594.659418] [mm-iface-modem-messaging.c:762] load_initial_sms_parts_ready(): Couldn't load SMS parts from storage 'me': 'Serial port is now closed'
>> ModemManager[2586]: <debug> [1384781594.659483] [mm-broadband-modem.c:6155] modem_messaging_load_initial_sms_parts(): Listing SMS parts in storage 'sm'
>> ModemManager[2586]: <debug> [1384781594.659536] [mm-broadband-modem.c:5351] mm_broadband_modem_lock_sms_storages(): Locking SMS storages to: mem1 (SM), mem2 (none)...
>> ModemManager[2586]: <debug> [1384781594.659623] [mm-serial-port.c:892] mm_serial_port_open(): (ttyUSB2) opening serial port...
>> ModemManager[2586]: <warn>  [1384781594.659814] [mm-serial-port.c:914] mm_serial_port_open(): (ttyUSB2) could not open serial device (19)
>> ModemManager[2586]: mm_serial_port_close: assertion `priv->open_count > 0' failed
>> ModemManager[2586]: <debug> [1384781594.660002] [mm-iface-modem-messaging.c:762] load_initial_sms_parts_ready(): Couldn't load SMS parts from storage 'sm': 'Cannot run sequence: 'Could not open serial device ttyUSB2: No such device''
>> 
>> 
>> I usually run this device in MBIM mode.  The problem could have existed
>> for a while.
>> 
>
> Your MC7710 in QMI mode doesn't have the WMS service?

It does:

bjorn at nemi:/tmp$ qmicli -d /dev/cdc-wdm0 --get-service-version-info
[/dev/cdc-wdm0] Supported versions:
        ctl (1.5)
        wds (1.12)
        dms (1.7)
        nas (1.21)
        qos (1.3)
        wms (1.4)
        pds (1.10)
        auth (1.1)
        at (1.1)
        voice (2.1)
        cat2 (2.0)
        uim (1.4)
        pbm (1.4)
        sar (1.0)
        wda (1.0)
        cat (2.0)
        rms (1.0)
bjorn at nemi:/tmp$ qmicli -d /dev/cdc-wdm0   --dms-get-revision 
[/dev/cdc-wdm0] Device revision retrieved:
        Revision: 'SWI9200X_03.05.23.02ap r5708 carmd-en-10527 2013/03/14 20:07:35'




But I now see why you ask.  It seems I've managed to screw up the latest
libqmi installation without noticing (probably related to the qmi proxy).

The result is:

ModemManager[12568]: <debug> [1384860187.190582] [mm-serial-port.c:1139] mm_serial_port_close_force(): (ttyUSB1) forced to close port
ModemManager[12568]: <debug> [1384860187.190696] [mm-plugin-manager.c:417] plugin_supports_port_ready(): (Plugin Manager) (Gobi) [ttyUSB1] found best plugin for port
ModemManager[12568]: <debug> [1384860187.190761] [mm-plugin-manager.c:285] port_probe_context_finished(): (Plugin Manager) 'ttyUSB1' port probe finished, last one in device
ModemManager[12568]: <debug> [1384860187.190821] [mm-plugin-manager.c:107] find_device_support_context_complete_and_free(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:1d.7/usb7/7-4] device support check finished in '16.238724' seconds
ModemManager[12568]: <info>  [1384860187.190901] [mm-device.c:486] mm_device_create_modem(): Creating modem with plugin 'Gobi' and '7' ports
ModemManager[12568]: <warn>  [1384860187.193919] [mm-plugin.c:905] mm_plugin_create_modem(): Could not grab port (usbmisc/cdc-wdm0): 'Cannot add port 'usbmisc/cdc-wdm0', unsupported'
ModemManager[12568]: <warn>  [1384860187.194018] [mm-plugin.c:905] mm_plugin_create_modem(): Could not grab port (usbmisc/cdc-wdm1): 'Cannot add port 'usbmisc/cdc-wdm1', unsupported'
ModemManager[12568]: <debug> [1384860187.194112] [mm-base-modem.c:275] mm_base_modem_grab_port(): (wwan0) type 'net' claimed by /sys/devices/pci0000:00/0000:00:1d.7/usb7/7-4
ModemManager[12568]: <debug> [1384860187.194214] [mm-base-modem.c:275] mm_base_modem_grab_port(): (wwan1) type 'net' claimed by /sys/devices/pci0000:00/0000:00:1d.7/usb7/7-4
ModemManager[12568]: <debug> [1384860187.194434] [mm-base-modem.c:275] mm_base_modem_grab_port(): (ttyUSB2) type 'at' claimed by /sys/devices/pci0000:00/0000:00:1d.7/usb7/7-4
ModemManager[12568]: <warn>  [1384860187.194558] [mm-plugin.c:905] mm_plugin_create_modem(): Could not grab port (tty/ttyUSB1): 'Cannot add port 'tty/ttyUSB1', unhandled serial type'
ModemManager[12568]: <debug> [1384860187.194671] [mm-base-modem.c:275] mm_base_modem_grab_port(): (ttyUSB0) type 'qcdm' claimed by /sys/devices/pci0000:00/0000:00:1d.7/usb7/7-4
ModemManager[12568]: <debug> [1384860187.194753] [mm-base-modem.c:1056] log_port(): (/sys/devices/pci0000:00/0000:00:1d.7/usb7/7-4) tty/ttyUSB2 at (primary)
ModemManager[12568]: <debug> [1384860187.194813] [mm-base-modem.c:1056] log_port(): (/sys/devices/pci0000:00/0000:00:1d.7/usb7/7-4) net/wwan0 data (primary)
ModemManager[12568]: <debug> [1384860187.194869] [mm-base-modem.c:1056] log_port(): (/sys/devices/pci0000:00/0000:00:1d.7/usb7/7-4) net/wwan1 data (secondary)
ModemManager[12568]: <debug> [1384860187.194926] [mm-base-modem.c:1056] log_port(): (/sys/devices/pci0000:00/0000:00:1d.7/usb7/7-4) tty/ttyUSB0 qcdm


So the problem is that ModemManager is too forgiving :-) It just
continues with the ports it was able to support, and I didn't notice the
missing QMI ports:


bjorn at nemi:~$ mmcli -m 0

/org/freedesktop/ModemManager1/Modem/0 (device id 'f64b04016c0f5638cc447a58f5462a2975b31d26')
  -------------------------
  Hardware |   manufacturer: 'Sierra Wireless, Incorporated'
           |          model: 'MC7710'
           |       revision: 'SWI9200X_03.05.23.02ap r5708 carmd-en-10527 2013/03/14 20:07:35'
           |      supported: 'gsm-umts, lte'
           |        current: 'gsm-umts, lte'
           |   equipment id: '358178040092316'
  -------------------------
  System   |         device: '/sys/devices/pci0000:00/0000:00:1d.7/usb7/7-4'
           |        drivers: 'qcserial, qmi_wwan'
           |         plugin: 'Gobi'
           |   primary port: 'ttyUSB2'
           |          ports: 'ttyUSB0 (qcdm), ttyUSB2 (at), wwan0 (net), wwan1 (net)'
  -------------------------
  Numbers  |           own : 'unknown'
  -------------------------
  Status   |           lock: 'sim-pin'
           | unlock retries: 'unknown'
           |          state: 'locked'
           |    power state: 'on'
           |    access tech: 'unknown'
           | signal quality: '0' (cached)
  -------------------------
  Modes    |      supported: 'allowed: 2g, 3g, 4g; preferred: none'
           |        current: 'allowed: 2g, 3g, 4g; preferred: none'
  -------------------------
  Bands    |      supported: 'unknown'
           |        current: 'unknown'
  -------------------------
  IP       |      supported: 'ipv4, ipv6, ipv4v6'
  -------------------------
  SIM      |           path: '/org/freedesktop/ModemManager1/SIM/0'



So the AT command fallback does crash the firmware, but this shouldn't
be a problem unless you do like me and fail to install libqmi properly.



Bjørn


More information about the ModemManager-devel mailing list