Unable to connect using a Quectel EC25-E modem and libqmi 1.18.0

Wed Jun 7 08:55:08 UTC 2017

Hello all,

I have a Quectel EC25-E modem that I'm trying to get working on a Raspberry
Pi 3 Model B V1.2. The rootfs has been built using Buildroot and includes
libqmi 1.18.0 and is running kernel 4.9.17 which has been pulled from the
Raspberry Foundation github repo (https://github.com/raspberrypi/linux). As
far as I can tell, there does appear to be support for the EC25 in the 4.9
kernel (it is referenced in qmi_wwan.c).

After plugging in the device, I get the following messages in dmesg:

[    6.357871] usb 1-1.4: new high-speed USB device number 5 using dwc_otg
[    6.497868] usb 1-1.4: New USB device found, idVendor=2c7c,
idProduct=0125
[    6.498110] usb 1-1.4: New USB device strings: Mfr=1, Product=2,
SerialNumber=0
[    6.498329] usb 1-1.4: Product: Android
[    6.498444] usb 1-1.4: Manufacturer: Android
[    6.523414] usbcore: registered new interface driver usbserial
[    6.523740] usbcore: registered new interface driver usbserial_generic
[    6.524027] usbserial: USB Serial support registered for generic
[    6.543366] usbcore: registered new interface driver option
[    6.543647] usbserial: USB Serial support registered for GSM modem
(1-port)
[    6.544646] option 1-1.4:1.0: GSM modem (1-port) converter detected
[    6.545372] usb 1-1.4: GSM modem (1-port) converter now attached to
ttyUSB0
[    6.545849] option 1-1.4:1.1: GSM modem (1-port) converter detected
[    6.546566] usb 1-1.4: GSM modem (1-port) converter now attached to
ttyUSB1
[    6.547038] option 1-1.4:1.2: GSM modem (1-port) converter detected
[    6.547628] usb 1-1.4: GSM modem (1-port) converter now attached to
ttyUSB2
[    6.550785] usbcore: registered new interface driver cdc_wdm
[    6.555116] option 1-1.4:1.3: GSM modem (1-port) converter detected
[    6.556428] usb 1-1.4: GSM modem (1-port) converter now attached to
ttyUSB3
[    6.565055] qmi_wwan 1-1.4:1.4: cdc-wdm0: USB WDM device
[    6.569221] qmi_wwan 1-1.4:1.4 wwan0: register 'qmi_wwan' at
usb-3f980000.usb-1.4, WWAN/QMI device, 3a:e6:60:3a:76:ef
[    6.570799] usbcore: registered new interface driver qmi_wwan

In order to get debug information, I've manually started qmi-proxy by
running the following:

# /usr/libexec/qmi-proxy --verbose --no-exit
[07 Jun 2017, 09:48:31] [Debug] creating UNIX socket service...
[07 Jun 2017, 09:48:31] [Debug] starting UNIX socket service at
'qmi-proxy'...

I've created the file /etc/qmi-network.conf with the following contents:

# cat /etc/qmi-network.conf
APN=internet
PROXY=yes

After that, I've attempted to use qmi-network to start the network by
running the following:

# qmi-network /dev/cdc-wdm0 start
Loading profile at /etc/qmi-network.conf...
    APN: internet
    APN user: unset
    APN password: unset
    qmi-proxy: yes
Checking data format with 'qmicli -d /dev/cdc-wdm0 --wda-get-data-format
--device-open-proxy'...
error: couldn't create client for the 'wda' service: CID allocation failed
in the CTL client: Transaction timed out
Device link layer protocol not retrieved: WDA unsupported
Starting network with 'qmicli -d /dev/cdc-wdm0
--wds-start-network=apn='internet'
 --client-no-release-cid --device-open-proxy'...
error: couldn't open the QmiDevice: Transaction timed out
error: network start failed, client not allocated

While this has been running, the following output can be seen on qmi-proxy:

[07 Jun 2017, 09:48:42] [Debug] Client (6) connection open...
[07 Jun 2017, 09:48:42] [Debug] valid request to open connection to QMI
device file: /dev/cdc-wdm0
[07 Jun 2017, 09:48:42] [Debug] [/dev/cdc-wdm0] Opening device with flags
'none'...
[07 Jun 2017, 09:48:42] [Debug] [/dev/cdc-wdm0] loaded driver of cdc-wdm
port: qmi_wwan
[07 Jun 2017, 09:48:42] [Debug] connection to QMI device '/dev/cdc-wdm0'
established
[07 Jun 2017, 09:48:42] [Debug] Client (6) TX: 19 bytes
[07 Jun 2017, 09:48:42] [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:1A

[07 Jun 2017, 09:48:42] [Debug] [/dev/cdc-wdm0] sent generic request
(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      = 1A
<<<<<<   translated = wda

[07 Jun 2017, 09:48:52] [Debug] Client (6) connection closed...
[07 Jun 2017, 09:48:52] [Debug] closing device '/dev/cdc-wdm0': no longer
used

Obviously, the connection doesn't work.

When I try and run qmi-network again, there is no new output on qmi-proxy,
and it appears to have frozen (this may be related to
https://bugs.freedesktop.org/show_bug.cgi?id=101271).

dmesg also shows the following:

[  243.678016] INFO: task qmi-proxy:325 blocked for more than 120 seconds.
[  243.678219]       Not tainted 4.9.17-v7 #1
[  243.678338] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
this message.
[  243.682908] qmi-proxy       D    0   325    322 0x00000000
[  243.687530] [<80718ea4>] (__schedule) from [<807193d0>]
(schedule+0x50/0xa8)
[  243.692023] [<807193d0>] (schedule) from [<7f3a93a0>]
(wdm_flush+0x74/0xe4 [cdc_wdm])
[  243.696465] [<7f3a93a0>] (wdm_flush [cdc_wdm]) from [<8026ee98>]
(filp_close+0x40/0x8c)
[  243.700773] [<8026ee98>] (filp_close) from [<80291768>]
(__close_fd+0xc8/0xec)
[  243.705090] [<80291768>] (__close_fd) from [<8026ef14>]
(SyS_close+0x30/0x58)
[  243.709404] [<8026ef14>] (SyS_close) from [<80107fc0>]
(ret_fast_syscall+0x0/0x1c)
[  366.566270] INFO: task qmi-proxy:325 blocked for more than 120 seconds.
[  366.570693]       Not tainted 4.9.17-v7 #1
[  366.575122] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
this message.
[  366.579679] qmi-proxy       D    0   325    322 0x00000000
[  366.584384] [<80718ea4>] (__schedule) from [<807193d0>]
(schedule+0x50/0xa8)
[  366.589105] [<807193d0>] (schedule) from [<7f3a93a0>]
(wdm_flush+0x74/0xe4 [cdc_wdm])
[  366.593802] [<7f3a93a0>] (wdm_flush [cdc_wdm]) from [<8026ee98>]
(filp_close+0x40/0x8c)
[  366.598465] [<8026ee98>] (filp_close) from [<80291768>]
(__close_fd+0xc8/0xec)
[  366.603191] [<80291768>] (__close_fd) from [<8026ef14>]
(SyS_close+0x30/0x58)
[  366.607938] [<8026ef14>] (SyS_close) from [<80107fc0>]
(ret_fast_syscall+0x0/0x1c)

(there are more of these repeated).

How can I get this unit working?
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/libqmi-devel/attachments/20170607/fc0515d2/attachment.html>