Created attachment 1204863 [details] Debug log from: /usr/sbin/ModemManager --log-file=/var/log/mm.log --log-level=DEBUG Description of problem: I can't use the builtin Sierra EM7455 modem. It seems like the device is recognised, but I get very generic error messages when trying to use it. When I try to connect via NetworkManager nothing happens at all, no error message or nothing. Via CLI I get this: # mmcli -m 0 --simple-connect="apn=services.telenor.se" error: couldn't connect the modem: 'GDBus.Error:org.freedesktop.libmbim.Error.Status.Failure: Failure' Version-Release number of selected component (if applicable): mmcli 1.6.0 How reproducible: Try to connect, nothing happens Steps to Reproduce: 1. Insert SIM 2. Specify APN 3. Try to connect Actual results: Nothing happens Expected results: I expect to at least see an error message telling me what's wrong Additional info: # uname -a Linux joma03-fedora 4.7.3-200.fc24.x86_64 #1 SMP Wed Sep 7 17:31:21 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux # mmcli -m 0 /org/freedesktop/ModemManager1/Modem/0 (device id 'e4df1bb2550f2c89951b100d1481a0418feb2c59') ------------------------- Hardware | manufacturer: 'Sierra' | model: 'MBIM [1199:9079]' | revision: 'SWI9X30C_02.08.02.00' | supported: 'gsm-umts, lte' | current: 'gsm-umts, lte' | equipment id: '014582001016543' ------------------------- System | device: '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-2' | drivers: 'cdc_mbim' | plugin: 'Sierra' | primary port: 'cdc-wdm0' | ports: 'cdc-wdm0 (mbim), wwp0s20f0u2i12 (net)' ------------------------- Numbers | own : 'unknown' ------------------------- Status | lock: 'none' | unlock retries: 'sim-pin2 (3)' | state: 'disabled' | power state: 'low' | access tech: 'unknown' | signal quality: '0' (cached) ------------------------- Modes | supported: 'allowed: 3g, 4g; preferred: none' | current: 'allowed: 3g, 4g; preferred: none' ------------------------- Bands | supported: 'unknown' | current: 'unknown' ------------------------- IP | supported: 'ipv4, ipv6, ipv4v6' ------------------------- 3GPP | imei: '014582001016543' | enabled locks: 'fixed-dialing' | operator id: 'unknown' | operator name: 'unknown' | subscription: 'unknown' | registration: 'unknown' ------------------------- SIM | path: '/org/freedesktop/ModemManager1/SIM/0' ------------------------- Bearers | paths: 'none' [root@joma03-fedora ~]# mbimcli -d /dev/cdc-wdm0 --query-device-caps --verbose [26 Sep 2016, 17:19:25] [Debug] opening device... [26 Sep 2016, 17:19:25] [Debug] [/dev/cdc-wdm0] Queried max control message size: 4096 [26 Sep 2016, 17:19:25] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 16 <<<<<< data = 01:00:00:00:10:00:00:00:01:00:00:00:00:10:00:00 [26 Sep 2016, 17:19:25] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< Header: <<<<<< length = 16 <<<<<< type = open (0x00000001) <<<<<< transaction = 1 <<<<<< Contents: <<<<<< max_control_transfer = 4096 [26 Sep 2016, 17:19:30] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 16 <<<<<< data = 01:00:00:00:10:00:00:00:02:00:00:00:00:10:00:00 [26 Sep 2016, 17:19:30] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< Header: <<<<<< length = 16 <<<<<< type = open (0x00000001) <<<<<< transaction = 2 <<<<<< Contents: <<<<<< max_control_transfer = 4096 [26 Sep 2016, 17:19:34] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 16 >>>>>> data = 01:00:00:80:10:00:00:00:02:00:00:00:00:00:00:00 [26 Sep 2016, 17:19:34] [Debug] MBIM Device at '/dev/cdc-wdm0' ready [26 Sep 2016, 17:19:34] [Debug] Asynchronously querying device capabilities... [26 Sep 2016, 17:19:34] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 48 <<<<<< data = 03:00:00:00:30:00:00:00:03:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:01:00:00:00:00:00:00:00:00:00:00:00 [26 Sep 2016, 17:19:34] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< Header: <<<<<< length = 48 <<<<<< type = command (0x00000003) <<<<<< transaction = 3 <<<<<< Fragment header: <<<<<< total = 1 <<<<<< current = 0 <<<<<< Contents: <<<<<< service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df) <<<<<< cid = 'device-caps' (0x00000001) <<<<<< type = 'query' (0x00000000) [26 Sep 2016, 17:19:34] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 196 >>>>>> data = 03:00:00:80:C4:00:00:00:03:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:01:00:00:00:00:00:00:00:94:00:00:00:03:00:00:00:01:00:00:00:01:00:00:00:02:00:00:00:3C:00:00:00:03:00:00:00:01:00:00:00:08:00:00:00:00:00:00:00:00:00:00:00:40:00:00:00:1E:00:00:00:60:00:00:00:28:00:00:00:88:00:00:00:0C:00:00:00:30:00:31:00:34:00:35:00:38:00:32:00:30:00:30:00:31:00:30:00:31:00:36:00:35:00:34:00:33:00:00:00:53:00:57:00:49:00:39:00:58:00:33:00:30:00:43:00:5F:00:30:00:32:00:2E:00:30:00:38:00:2E:00:30:00:32:00:2E:00:30:00:30:00:45:00:4D:00:37:00:34:00:35:00:35:00 [26 Sep 2016, 17:19:34] [Debug] [/dev/cdc-wdm0] Received message (translated)... >>>>>> Header: >>>>>> length = 196 >>>>>> type = command-done (0x80000003) >>>>>> transaction = 3 >>>>>> Fragment header: >>>>>> total = 1 >>>>>> current = 0 >>>>>> Contents: >>>>>> status error = 'None' (0x00000000) >>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df) >>>>>> cid = 'device-caps' (0x00000001) [/dev/cdc-wdm0] Device capabilities retrieved: Device type: 'remote' Cellular class: 'gsm' Voice class: 'no-voice' Sim class: 'removable' Data class: 'umts, hsdpa, hsupa, lte' SMS caps: 'pdu-receive, pdu-send' Ctrl caps: 'reg-manual' Max sessions: '8' Custom data class: 'unknown' Device ID: '014582001016543' Firmware info: 'SWI9X30C_02.08.02.00' Hardware info: 'EM7455' [26 Sep 2016, 17:19:34] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 12 <<<<<< data = 02:00:00:00:0C:00:00:00:04:00:00:00 [26 Sep 2016, 17:19:34] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< Header: <<<<<< length = 12 <<<<<< type = close (0x00000002) <<<<<< transaction = 4 [26 Sep 2016, 17:19:34] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 16 >>>>>> data = 02:00:00:80:10:00:00:00:04:00:00:00:00:00:00:00 [26 Sep 2016, 17:19:34] [Debug] Device closed
Looks like issues related to FCCAuth that newer Sierra modems require. ModemManager is attempting to enable the modem (bring it to full power mode for connection) but it cannot do that because the modem reports failure. When this happens, can you run and get the output of: sudo mbimcli -v -p -d /dev/cdc-wdm0 --query-radio-state sudo mbimcli -v -p -d /dev/cdc-wdm0 --set-radio-state=on
Thanks for the quick reply :) I tried connecting again and then ran the commands right after: [root@joma03-fedora ~]# mbimcli -v -p -d /dev/cdc-wdm0 --query-radio-state [26 Sep 2016, 17:59:01] [Debug] opening device... [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Read max control message size from descriptors file: 4096 [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 88 <<<<<< data = 03:00:00:00:58:00:00:00:01:00:00:00:01:00:00:00:00:00:00:00:83:8C:F7:FB:8D:0D:4D:7F:87:1E:D7:1D:BE:FB:B3:9B:01:00:00:00:01:00:00:00:28:00:00:00:0C:00:00:00:1A:00:00:00:1E:00:00:00:2F:00:64:00:65:00:76:00:2F:00:63:00:64:00:63:00:2D:00:77:00:64:00:6D:00:30:00:00:00 [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< Header: <<<<<< length = 88 <<<<<< type = command (0x00000003) <<<<<< transaction = 1 <<<<<< Fragment header: <<<<<< total = 1 <<<<<< current = 0 <<<<<< Contents: <<<<<< service = 'proxy-control' (838cf7fb-8d0d-4d7f-871e-d71dbefbb39b) <<<<<< cid = 'configuration' (0x00000001) <<<<<< type = 'set' (0x00000001) [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 48 >>>>>> data = 03:00:00:80:30:00:00:00:01:00:00:00:01:00:00:00:00:00:00:00:83:8C:F7:FB:8D:0D:4D:7F:87:1E:D7:1D:BE:FB:B3:9B:01:00:00:00:00:00:00:00:00:00:00:00 [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Received message (translated)... >>>>>> Header: >>>>>> length = 48 >>>>>> type = command-done (0x80000003) >>>>>> transaction = 1 >>>>>> Fragment header: >>>>>> total = 1 >>>>>> current = 0 >>>>>> Contents: >>>>>> status error = 'None' (0x00000000) >>>>>> service = 'proxy-control' (838cf7fb-8d0d-4d7f-871e-d71dbefbb39b) >>>>>> cid = 'configuration' (0x00000001) [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 16 <<<<<< data = 01:00:00:00:10:00:00:00:02:00:00:00:00:10:00:00 [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< Header: <<<<<< length = 16 <<<<<< type = open (0x00000001) <<<<<< transaction = 2 <<<<<< Contents: <<<<<< max_control_transfer = 4096 [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 16 >>>>>> data = 01:00:00:80:10:00:00:00:02:00:00:00:00:00:00:00 [26 Sep 2016, 17:59:01] [Debug] MBIM Device at '/dev/cdc-wdm0' ready [26 Sep 2016, 17:59:01] [Debug] Asynchronously querying radio state... [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 48 <<<<<< data = 03:00:00:00:30:00:00:00:03:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:03:00:00:00:00:00:00:00:00:00:00:00 [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< Header: <<<<<< length = 48 <<<<<< type = command (0x00000003) <<<<<< transaction = 3 <<<<<< Fragment header: <<<<<< total = 1 <<<<<< current = 0 <<<<<< Contents: <<<<<< service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df) <<<<<< cid = 'radio-state' (0x00000003) <<<<<< type = 'query' (0x00000000) [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 56 >>>>>> data = 03:00:00:80:38:00:00:00:03:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:03:00:00:00:00:00:00:00:08:00:00:00:01:00:00:00:00:00:00:00 [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Received message (translated)... >>>>>> Header: >>>>>> length = 56 >>>>>> type = command-done (0x80000003) >>>>>> transaction = 3 >>>>>> Fragment header: >>>>>> total = 1 >>>>>> current = 0 >>>>>> Contents: >>>>>> status error = 'None' (0x00000000) >>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df) >>>>>> cid = 'radio-state' (0x00000003) [/dev/cdc-wdm0] Radio state retrieved: Hardware Radio State: 'on' Software Radio State: 'off' [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 12 <<<<<< data = 02:00:00:00:0C:00:00:00:04:00:00:00 [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< Header: <<<<<< length = 12 <<<<<< type = close (0x00000002) <<<<<< transaction = 4 [26 Sep 2016, 17:59:01] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 16 >>>>>> data = 02:00:00:80:10:00:00:00:04:00:00:00:00:00:00:00 [26 Sep 2016, 17:59:01] [Debug] Device closed [root@joma03-fedora ~]# mbimcli -v -p -d /dev/cdc-wdm0 --set-radio-state=on [26 Sep 2016, 17:59:09] [Debug] opening device... [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Read max control message size from descriptors file: 4096 [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 88 <<<<<< data = 03:00:00:00:58:00:00:00:01:00:00:00:01:00:00:00:00:00:00:00:83:8C:F7:FB:8D:0D:4D:7F:87:1E:D7:1D:BE:FB:B3:9B:01:00:00:00:01:00:00:00:28:00:00:00:0C:00:00:00:1A:00:00:00:1E:00:00:00:2F:00:64:00:65:00:76:00:2F:00:63:00:64:00:63:00:2D:00:77:00:64:00:6D:00:30:00:00:00 [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< Header: <<<<<< length = 88 <<<<<< type = command (0x00000003) <<<<<< transaction = 1 <<<<<< Fragment header: <<<<<< total = 1 <<<<<< current = 0 <<<<<< Contents: <<<<<< service = 'proxy-control' (838cf7fb-8d0d-4d7f-871e-d71dbefbb39b) <<<<<< cid = 'configuration' (0x00000001) <<<<<< type = 'set' (0x00000001) [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 48 >>>>>> data = 03:00:00:80:30:00:00:00:01:00:00:00:01:00:00:00:00:00:00:00:83:8C:F7:FB:8D:0D:4D:7F:87:1E:D7:1D:BE:FB:B3:9B:01:00:00:00:00:00:00:00:00:00:00:00 [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Received message (translated)... >>>>>> Header: >>>>>> length = 48 >>>>>> type = command-done (0x80000003) >>>>>> transaction = 1 >>>>>> Fragment header: >>>>>> total = 1 >>>>>> current = 0 >>>>>> Contents: >>>>>> status error = 'None' (0x00000000) >>>>>> service = 'proxy-control' (838cf7fb-8d0d-4d7f-871e-d71dbefbb39b) >>>>>> cid = 'configuration' (0x00000001) [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 16 <<<<<< data = 01:00:00:00:10:00:00:00:02:00:00:00:00:10:00:00 [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< Header: <<<<<< length = 16 <<<<<< type = open (0x00000001) <<<<<< transaction = 2 <<<<<< Contents: <<<<<< max_control_transfer = 4096 [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 16 >>>>>> data = 01:00:00:80:10:00:00:00:02:00:00:00:00:00:00:00 [26 Sep 2016, 17:59:09] [Debug] MBIM Device at '/dev/cdc-wdm0' ready [26 Sep 2016, 17:59:09] [Debug] Asynchronously setting radio state to on... [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 52 <<<<<< data = 03:00:00:00:34:00:00:00:03:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:03:00:00:00:01:00:00:00:04:00:00:00:01:00:00:00 [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< Header: <<<<<< length = 52 <<<<<< type = command (0x00000003) <<<<<< transaction = 3 <<<<<< Fragment header: <<<<<< total = 1 <<<<<< current = 0 <<<<<< Contents: <<<<<< service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df) <<<<<< cid = 'radio-state' (0x00000003) <<<<<< type = 'set' (0x00000001) [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 56 >>>>>> data = 03:00:00:80:38:00:00:00:03:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:03:00:00:00:02:00:00:00:08:00:00:00:01:00:00:00:00:00:00:00 [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Received message (translated)... >>>>>> Header: >>>>>> length = 56 >>>>>> type = command-done (0x80000003) >>>>>> transaction = 3 >>>>>> Fragment header: >>>>>> total = 1 >>>>>> current = 0 >>>>>> Contents: >>>>>> status error = 'Failure' (0x00000002) >>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df) >>>>>> cid = 'radio-state' (0x00000003) error: operation failed: Failure [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 12 <<<<<< data = 02:00:00:00:0C:00:00:00:04:00:00:00 [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< Header: <<<<<< length = 12 <<<<<< type = close (0x00000002) <<<<<< transaction = 4 [26 Sep 2016, 17:59:09] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 16 >>>>>> data = 02:00:00:80:10:00:00:00:04:00:00:00:00:00:00:00 [26 Sep 2016, 17:59:09] [Debug] Device closed
How about: sudo qmicli -p -v -d /dev/cdc-wdm0 --device-open-mbim --dms-set-fcc-authentication
And then after that, again with: sudo mbimcli -p -d /dev/cdc-wdm0 --query-radio-state
Couldn't set FCC authentication something: [root@joma03-fedora ~]# qmicli -p -v -d /dev/cdc-wdm0 --device-open-mbim --dms-set-fcc-authentication [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Opening device with flags 'proxy, mbim'... [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] creating MBIM device... [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] MBIM device created [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] opening MBIM device... [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] MBIM device open [26 Sep 2016, 18:30:04] [Debug] QMI Device at '/dev/cdc-wdm0' ready [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Assuming service 'dms' is supported... [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Allocating new client ID... [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 16 <<<<<< data = 01:0F:00:00:00:00:00:01:22:00:04:00:01:01:00:02 [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< QMUX: <<<<<< length = 15 <<<<<< flags = 0x00 <<<<<< service = "ctl" <<<<<< client = 0 <<<<<< QMI: <<<<<< flags = "none" <<<<<< transaction = 1 <<<<<< tlv_length = 4 <<<<<< message = "Allocate CID" (0x0022) <<<<<< TLV: <<<<<< type = "Service" (0x01) <<<<<< length = 1 <<<<<< value = 02 <<<<<< translated = dms [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] sending message as MBIM... [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Received MBIM message [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 24 >>>>>> data = 01:17:00:80:00:00:01:01:22:00:0C:00:02:04:00:00:00:00:00:01:02:00:02:03 [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Received message (translated)... >>>>>> QMUX: >>>>>> length = 23 >>>>>> flags = 0x80 >>>>>> service = "ctl" >>>>>> client = 0 >>>>>> QMI: >>>>>> flags = "response" >>>>>> transaction = 1 >>>>>> tlv_length = 12 >>>>>> message = "Allocate CID" (0x0022) >>>>>> TLV: >>>>>> type = "Result" (0x02) >>>>>> length = 4 >>>>>> value = 00:00:00:00 >>>>>> translated = SUCCESS >>>>>> TLV: >>>>>> type = "Allocation Info" (0x01) >>>>>> length = 2 >>>>>> value = 02:03 >>>>>> translated = [ service = 'dms' cid = '3' ] [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Registered 'dms' (version unknown) client with ID '3' [26 Sep 2016, 18:30:04] [Debug] Asynchronously setting FCC auth... [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 13 <<<<<< data = 01:0C:00:00:02:03:00:01:00:5F:55:00:00 [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< QMUX: <<<<<< length = 12 <<<<<< flags = 0x00 <<<<<< service = "dms" <<<<<< client = 3 <<<<<< QMI: <<<<<< flags = "none" <<<<<< transaction = 1 <<<<<< tlv_length = 0 <<<<<< message = "Set FCC Authentication" (0x555F) [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] sending message as MBIM... [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Received MBIM message [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 20 >>>>>> data = 01:13:00:80:02:03:02:01:00:5F:55:07:00:02:04:00:01:00:1A:00 [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Received message (translated)... >>>>>> QMUX: >>>>>> length = 19 >>>>>> flags = 0x80 >>>>>> service = "dms" >>>>>> client = 3 >>>>>> QMI: >>>>>> flags = "response" >>>>>> transaction = 1 >>>>>> tlv_length = 7 >>>>>> message = "Set FCC Authentication" (0x555F) >>>>>> TLV: >>>>>> type = "Result" (0x02) >>>>>> length = 4 >>>>>> value = 01:00:1A:00 >>>>>> translated = FAILURE: NoEffect error: couldn't set FCC authentication: QMI protocol error (26): 'NoEffect' [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Releasing 'dms' client with flags 'release-cid'... [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Unregistered 'dms' client with ID '3' [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 17 <<<<<< data = 01:10:00:00:00:00:00:02:23:00:05:00:01:02:00:02:03 [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< QMUX: <<<<<< length = 16 <<<<<< flags = 0x00 <<<<<< service = "ctl" <<<<<< client = 0 <<<<<< QMI: <<<<<< flags = "none" <<<<<< transaction = 2 <<<<<< tlv_length = 5 <<<<<< message = "Release CID" (0x0023) <<<<<< TLV: <<<<<< type = "Release Info" (0x01) <<<<<< length = 2 <<<<<< value = 02:03 <<<<<< translated = [ service = 'dms' cid = '3' ] [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] sending message as MBIM... [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Received MBIM message [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 24 >>>>>> data = 01:17:00:80:00:00:01:02:23:00:0C:00:02:04:00:00:00:00:00:01:02:00:02:03 [26 Sep 2016, 18:30:04] [Debug] [/dev/cdc-wdm0] Received message (translated)... >>>>>> QMUX: >>>>>> length = 23 >>>>>> flags = 0x80 >>>>>> service = "ctl" >>>>>> client = 0 >>>>>> QMI: >>>>>> flags = "response" >>>>>> transaction = 2 >>>>>> tlv_length = 12 >>>>>> message = "Release CID" (0x0023) >>>>>> TLV: >>>>>> type = "Result" (0x02) >>>>>> length = 4 >>>>>> value = 00:00:00:00 >>>>>> translated = SUCCESS >>>>>> TLV: >>>>>> type = "Release Info" (0x01) >>>>>> length = 2 >>>>>> value = 02:03 >>>>>> translated = [ service = 'dms' cid = '3' ] [26 Sep 2016, 18:30:04] [Debug] Client released [root@joma03-fedora ~]# mbimcli -p -d /dev/cdc-wdm0 --query-radio-state [/dev/cdc-wdm0] Radio state retrieved: Hardware Radio State: 'on' Software Radio State: 'off' I couldn't connect after that either
Ok, now: sudo qmicli -p -d /dev/cdc-wdm0 --device-open-mbim --dms-get-capabilities sudo qmicli -p -d /dev/cdc-wdm0 --device-open-mbim --dms-get-operating-mode
[root@joma03-fedora ~]# qmicli -p -d /dev/cdc-wdm0 --device-open-mbim --dms-get-capabilities [/dev/cdc-wdm0] Device capabilities retrieved: Max TX channel rate: '50000000' Max RX channel rate: '300000000' Data Service: 'non-simultaneous-cs-ps' SIM: 'supported' Networks: 'umts, lte' [root@joma03-fedora ~]# qmicli -p -d /dev/cdc-wdm0 --device-open-mbim --dms-get-operating-mode [/dev/cdc-wdm0] Operating mode retrieved: Mode: 'low-power' HW restricted: 'no'
One last one, this time with '-v' because only that shows the reason for the operating mode state: qmicli -v -p -d /dev/cdc-wdm0 --device-open-mbim --dms-get-operating-mode
# qmicli -v -p -d /dev/cdc-wdm0 --device-open-mbim --dms-get-operating-mode [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Opening device with flags 'proxy, mbim'... [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] creating MBIM device... [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] MBIM device created [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] opening MBIM device... [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] MBIM device open [26 Sep 2016, 22:31:32] [Debug] QMI Device at '/dev/cdc-wdm0' ready [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Assuming service 'dms' is supported... [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Allocating new client ID... [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 16 <<<<<< data = 01:0F:00:00:00:00:00:01:22:00:04:00:01:01:00:02 [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< QMUX: <<<<<< length = 15 <<<<<< flags = 0x00 <<<<<< service = "ctl" <<<<<< client = 0 <<<<<< QMI: <<<<<< flags = "none" <<<<<< transaction = 1 <<<<<< tlv_length = 4 <<<<<< message = "Allocate CID" (0x0022) <<<<<< TLV: <<<<<< type = "Service" (0x01) <<<<<< length = 1 <<<<<< value = 02 <<<<<< translated = dms [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] sending message as MBIM... [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Received MBIM message [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 24 >>>>>> data = 01:17:00:80:00:00:01:01:22:00:0C:00:02:04:00:00:00:00:00:01:02:00:02:03 [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Received message (translated)... >>>>>> QMUX: >>>>>> length = 23 >>>>>> flags = 0x80 >>>>>> service = "ctl" >>>>>> client = 0 >>>>>> QMI: >>>>>> flags = "response" >>>>>> transaction = 1 >>>>>> tlv_length = 12 >>>>>> message = "Allocate CID" (0x0022) >>>>>> TLV: >>>>>> type = "Result" (0x02) >>>>>> length = 4 >>>>>> value = 00:00:00:00 >>>>>> translated = SUCCESS >>>>>> TLV: >>>>>> type = "Allocation Info" (0x01) >>>>>> length = 2 >>>>>> value = 02:03 >>>>>> translated = [ service = 'dms' cid = '3' ] [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Registered 'dms' (version unknown) client with ID '3' [26 Sep 2016, 22:31:32] [Debug] Asynchronously getting operating mode... [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 13 <<<<<< data = 01:0C:00:00:02:03:00:01:00:2D:00:00:00 [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< QMUX: <<<<<< length = 12 <<<<<< flags = 0x00 <<<<<< service = "dms" <<<<<< client = 3 <<<<<< QMI: <<<<<< flags = "none" <<<<<< transaction = 1 <<<<<< tlv_length = 0 <<<<<< message = "Get Operating Mode" (0x002D) [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] sending message as MBIM... [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Received MBIM message [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 24 >>>>>> data = 01:17:00:80:02:03:02:01:00:2D:00:0B:00:02:04:00:00:00:00:00:01:01:00:01 [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Received message (translated)... >>>>>> QMUX: >>>>>> length = 23 >>>>>> flags = 0x80 >>>>>> service = "dms" >>>>>> client = 3 >>>>>> QMI: >>>>>> flags = "response" >>>>>> transaction = 1 >>>>>> tlv_length = 11 >>>>>> message = "Get Operating Mode" (0x002D) >>>>>> TLV: >>>>>> type = "Result" (0x02) >>>>>> length = 4 >>>>>> value = 00:00:00:00 >>>>>> translated = SUCCESS >>>>>> TLV: >>>>>> type = "Mode" (0x01) >>>>>> length = 1 >>>>>> value = 01 >>>>>> translated = low-power [/dev/cdc-wdm0] Operating mode retrieved: Mode: 'low-power' HW restricted: 'no' [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Releasing 'dms' client with flags 'release-cid'... [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Unregistered 'dms' client with ID '3' [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 17 <<<<<< data = 01:10:00:00:00:00:00:02:23:00:05:00:01:02:00:02:03 [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Sent message (translated)... <<<<<< QMUX: <<<<<< length = 16 <<<<<< flags = 0x00 <<<<<< service = "ctl" <<<<<< client = 0 <<<<<< QMI: <<<<<< flags = "none" <<<<<< transaction = 2 <<<<<< tlv_length = 5 <<<<<< message = "Release CID" (0x0023) <<<<<< TLV: <<<<<< type = "Release Info" (0x01) <<<<<< length = 2 <<<<<< value = 02:03 <<<<<< translated = [ service = 'dms' cid = '3' ] [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] sending message as MBIM... [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Received MBIM message [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Received message... >>>>>> RAW: >>>>>> length = 24 >>>>>> data = 01:17:00:80:00:00:01:02:23:00:0C:00:02:04:00:00:00:00:00:01:02:00:02:03 [26 Sep 2016, 22:31:32] [Debug] [/dev/cdc-wdm0] Received message (translated)... >>>>>> QMUX: >>>>>> length = 23 >>>>>> flags = 0x80 >>>>>> service = "ctl" >>>>>> client = 0 >>>>>> QMI: >>>>>> flags = "response" >>>>>> transaction = 2 >>>>>> tlv_length = 12 >>>>>> message = "Release CID" (0x0023) >>>>>> TLV: >>>>>> type = "Result" (0x02) >>>>>> length = 4 >>>>>> value = 00:00:00:00 >>>>>> translated = SUCCESS >>>>>> TLV: >>>>>> type = "Release Info" (0x01) >>>>>> length = 2 >>>>>> value = 02:03 >>>>>> translated = [ service = 'dms' cid = '3' ] [26 Sep 2016, 22:31:32] [Debug] Client released
We should dig a bit further to figure out if there's a firmware mismatch in the module. To do that, we need to switch the device to QMI mode: cd -P /sys/class/usbmisc/cdc-wdm0/device/../ echo "1" > bConfigurationValue then wait about 10 seconds for the module to appear. You should now get a new cdc-wdm0 plus three ttyUSBx devices. Run minicom on the third one: minicom -D /dev/ttyUSB2 and then enter these commands and report the result: AT!ENTERCND="A710" AT!PRIID? AT!GOBIIMPREF? to get out of minicom, hit <CTRL>+A, then Z, then hit return to exit without reset.
Hm, sorry I can't seem to get it to work. The bConfigurationValue was already set to 1, and nothing much happens when I echo 1 to it again. I don't get any /dev/ttyUSB* devices dmesg after I run the echo command: [Tue Sep 27 17:22:11 2016] cdc_mbim 1-2:1.12 wwp0s20f0u2i12: unregister 'cdc_mbim' usb-0000:00:14.0-2, CDC MBIM [Tue Sep 27 17:22:11 2016] cdc_mbim 1-2:1.12: cdc-wdm0: USB WDM device [Tue Sep 27 17:22:11 2016] cdc_mbim 1-2:1.12 wwan0: register 'cdc_mbim' at usb-0000:00:14.0-2, CDC MBIM, 12:ed:d4:37:8d:21 [Tue Sep 27 17:22:11 2016] cdc_mbim 1-2:1.12 wwp0s20f0u2i12: renamed from wwan0 I waited about 2 mins but nothing, tried again but still nothing. The cdc-wdm0 device is there though: # ls -l /dev/cdc-wdm0 crw-------. 1 root root 180, 176 Sep 27 17:28 /dev/cdc-wdm0
(In reply to independence from comment #11) > Hm, sorry I can't seem to get it to work. The bConfigurationValue was > already set to 1, and nothing much happens when I echo 1 to it again. I > don't get any /dev/ttyUSB* devices > > dmesg after I run the echo command: > [Tue Sep 27 17:22:11 2016] cdc_mbim 1-2:1.12 wwp0s20f0u2i12: unregister > 'cdc_mbim' usb-0000:00:14.0-2, CDC MBIM > [Tue Sep 27 17:22:11 2016] cdc_mbim 1-2:1.12: cdc-wdm0: USB WDM device > [Tue Sep 27 17:22:11 2016] cdc_mbim 1-2:1.12 wwan0: register 'cdc_mbim' at > usb-0000:00:14.0-2, CDC MBIM, 12:ed:d4:37:8d:21 > [Tue Sep 27 17:22:11 2016] cdc_mbim 1-2:1.12 wwp0s20f0u2i12: renamed from > wwan0 > > I waited about 2 mins but nothing, tried again but still nothing. > The cdc-wdm0 device is there though: > # ls -l /dev/cdc-wdm0 > crw-------. 1 root root 180, 176 Sep 27 17:28 /dev/cdc-wdm0 Ok, interesting. Can you grab "lsusb -v -d <vid>:<pid>" (where you replace vid/pid with the numbers from your module) output and attach it? It may be that the EM7455 doesn't expose multiple USB configurations and thus we can't get an AT port like we can with the EM7355.
Ok # lsusb -v -d 1199:9079 Bus 001 Device 002: ID 1199:9079 Sierra Wireless, Inc. Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 2.10 bDeviceClass 0 bDeviceSubClass 0 bDeviceProtocol 0 bMaxPacketSize0 64 idVendor 0x1199 Sierra Wireless, Inc. idProduct 0x9079 bcdDevice 0.06 iManufacturer 1 Sierra Wireless, Incorporated iProduct 2 Sierra Wireless EM7455 Qualcomm Snapdragon X7 LTE-A iSerial 3 LF61727105041013 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 95 bNumInterfaces 2 bConfigurationValue 1 iConfiguration 0 bmAttributes 0xa0 (Bus Powered) Remote Wakeup MaxPower 500mA Interface Association: bLength 8 bDescriptorType 11 bFirstInterface 12 bInterfaceCount 2 bFunctionClass 2 Communications bFunctionSubClass 14 bFunctionProtocol 0 iFunction 0 Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 12 bAlternateSetting 0 bNumEndpoints 1 bInterfaceClass 2 Communications bInterfaceSubClass 14 bInterfaceProtocol 0 iInterface 0 CDC Header: bcdCDC 1.10 CDC Union: bMasterInterface 12 bSlaveInterface 13 CDC MBIM: bcdMBIMVersion 1.00 wMaxControlMessage 4096 bNumberFilters 32 bMaxFilterSize 128 wMaxSegmentSize 2048 bmNetworkCapabilities 0x20 8-byte ntb input size CDC MBIM Extended: bcdMBIMExtendedVersion 1.00 bMaxOutstandingCommandMessages 64 wMTU 1500 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x82 EP 2 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0040 1x 64 bytes bInterval 9 Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 13 bAlternateSetting 0 bNumEndpoints 0 bInterfaceClass 10 CDC Data bInterfaceSubClass 0 bInterfaceProtocol 2 iInterface 0 Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 13 bAlternateSetting 1 bNumEndpoints 2 bInterfaceClass 10 CDC Data bInterfaceSubClass 0 bInterfaceProtocol 2 iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 2 Transfer Type Bulk Synch Type None Usage Type Data wMaxPacketSize 0x0200 1x 512 bytes bInterval 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x01 EP 1 OUT bmAttributes 2 Transfer Type Bulk Synch Type None Usage Type Data wMaxPacketSize 0x0200 1x 512 bytes bInterval 0 Binary Object Store Descriptor: bLength 5 bDescriptorType 15 wTotalLength 12 bNumDeviceCaps 1 USB 2.0 Extension Device Capability: bLength 7 bDescriptorType 16 bDevCapabilityType 2 bmAttributes 0x00000000 (Missing must-be-set LPM bit!) can't get debug descriptor: Resource temporarily unavailable Device Status: 0x0000 (Bus Powered)
One last thing to try before I ask Bjorn what to do next: sudo qmicli -p -d /dev/cdc-wdm0 --device-open-mbim --dms-list-stored-images
Sure: # qmicli -p -d /dev/cdc-wdm0 --device-open-mbim --dms-list-stored-images [/dev/cdc-wdm0] Device list of stored images retrieved: [0] Type: 'modem' Maximum: '4' [modem0] Unique ID: '3F:5F:3F:00:00:00:00:00:00:00:00:00:00:00:00:00' Build ID: '02.05.07.00_?' Storage index: '1' Failure count: '0' >>>>>>>>>> [CURRENT] <<<<<<<<<< [modem1] Unique ID: '3F:5F:3F:00:00:00:00:00:00:00:00:00:00:00:00:00' Build ID: '02.08.02.00_?' Storage index: '2' Failure count: '0' [1] Type: 'pri' Maximum: '50' [pri0] Unique ID: '30:30:32:2E:30:30:34:5F:30:30:30:00:00:00:00:00' Build ID: '02.05.07.00_GENERIC'
It looks like you don't have a PRI selected, which can cause the firmware to refuse to power up. Had you plugged this modem into a Windows machine or played around with firmware updates at all? The PRI unique ID is translates to "002.004_000", so we'd need to select that with: qmicli -p -d /dev/cdc-wdm0 --device-open-mbim --dms-set-firmware-preference=02.08.02.00,002.004_000,GENERIC qmicli -p -d /dev/cdc-wdm0 --device-open-mbim --dms-set-operating-mode=offline qmicli -p -d /dev/cdc-wdm0 --device-open-mbim --dms-set-operating-mode=reset and then wait until the modem comes back and try: qmicli -p -d /dev/cdc-wdm0 --device-open-mbim --dms-get-operating-mode The only problem is that F24's version of libqmi doesn't support --dms-set-firmware-preference, because that command isn't in a libqmi release yet :( We might be able to do a custom build of libqmi which you can test, but I can't do that today or tomorrow.
Oh, ok. No, I never booted Windows fully on this machine and the firmware is stock. I'm guessing I'll need Windows to update the firmware too, which is a hassle. Yeah, as you said I don't seem to have that option in my qmicli. Is that version available in rawhide, and if so could I get the rawhide version of just that particular package on my machine? Thanks so much for your help so far, seems like are making some progress at least :)
Yeah, it may be that on first boot Windows and the Sierra drivers will fix up the firmware image mismatch for you automatically. There is some work going on for libqmi to allow firmware updating, but it's not quite finished yet. But I'm hopeful your device can become operational by selecting the right PRI. Try installing these libqmi packages: wget http://people.redhat.com/dcbw/libqmi-1.17.0-0.1.fc26.x86_64.rpm wget http://people.redhat.com/dcbw/libqmi-utils-1.17.0-0.1.fc26.x86_64.rpm rpm -Uhv libqmi*.rpm and then do the --dms-set-firmware-preference dance I listed above. If for some reason that doesn't get things working, grab the output of --dms-list-stored-images so we can see what happened.
Yes, it's working now! # qmicli -p -d /dev/cdc-wdm0 --device-open-mbim --dms-get-operating-mode [/dev/cdc-wdm0] Operating mode retrieved: Mode: 'online' HW restricted: 'no' # mmcli -L Found 1 modems: /org/freedesktop/ModemManager1/Modem/4 [Sierra] MBIM [1199:9079] # mmcli -m 4 --simple-connect="apn=services.telenor.se" successfully connected the modem I can connect to my provider through NetworkManager now, so everything seems good! Thanks for your help again
Glad to hear its working now! Thanks for sticking with this and the quick turnaround time, I'm sure others will experience this same issue and now we know what to do.
I had the same issue on the same hardware. However, I never booted into Windows and it worked fine from the start. That is, until I did boot into Windows after which I did run into this. My PRI unique ID was different: Unique ID: '30:30:32:2E:30:30:37:5F:30:30:30:00:00:00:00:00' I changed the set-firmware-preference parameter accordingly (note that the output above is simply a hex-encoded version of the ASCII string you need to supply) and ran it with a git master build of libqmi. Everything works fine again! Thanks for the detailed debugging procedure.
Not working on F25 on my new T570 either. Will try the procedures described here when I get home.
Seems to be a faulty SIM for me, going to order a new one :-)