qmi_wwan fails with error -22

[Muri Nicanor]

hi,

On 10/30/2015 05:46 PM, Bjørn Mork wrote:

>>> The latter might seem redundant since we have an entry in the driver
>>> already.  But the problem is that the driver entry refers to interface
>>> #4, while your modem is set up with QMI at interface #3.
>> well, only after the latter a /dev/cdcwdm0 device is created
> 
> 
> This looks pretty much as expected. The qcserial driver is handling the
> correct interfaces, mostly by chance but still. Did you test that the
> /dev/cdc-wdm0 device worked as a QMI device?
no, sorry, i don't know how to do that :/

[...]
> Ouch.  Didn't think of the qcserial conflict here.  It should definitely
> not mess with interfaces #0 and #1, which are CDC class interfaces.
> 
> You will ether have to blacklist qcserial, or manually unbinding it from
> these interfaces and then bind cdc_mbim to them instead.  This should
> work: 
> 
>  echo 1-6:3.0 >/sys/bus/usb/devices/1-6:3.0/driver/unbind
>  echo 1-6:3.1 >/sys/bus/usb/devices/1-6:3.1/driver/unbind
>  echo 1-6:3.0 >/sys/bus/usb/drivers/cdc_mbim/bind
> 
> 
> But that's of course not the kind of mess you'll want to have to sort
> out manually just to use a modem.  We'll definitely have to remove this
> device from qcserial..
oke, i've blacklisted qcserial

[...]
> 
> I wonder if you and/or Martin is able to test the attached qmi-wwan
> patch?  Ideally both should verify that it works, as your lt4112 modems
> obviosly are configured slightly different.
yes.

i now have a /dev/cdc-wdm0 device and
[...]
Oct 30 18:28:02 tekla kernel: [   18.617856] cdc_mbim 1-6:3.0: cdc-wdm0:
USB WDM device
Oct 30 18:28:02 tekla kernel: [   18.617973] cdc_mbim 1-6:3.0 wwan0:
register 'cdc_mbim' at usb-0000:00:14.0-6, CDC MBIM, ab:cd:ef:gh:ij:kl
Oct 30 18:28:02 tekla kernel: [   18.617991] usbcore: registered new
interface driver cdc_mbim
[...]
Oct 30 18:28:04 tekla ModemManager[878]: <info>  Creating modem with
plugin 'Generic' and '2' ports
Oct 30 18:28:04 tekla ModemManager[878]: <info>  Modem for device at
'/sys/devices/pci0000:00/0000:00:14.0/usb1/1-6' successfully created
Oct 30 18:28:04 tekla ModemManager[878]: <info>  Couldn't find support
for device at '/sys/devices/pci0000:00/0000:00:19.0': not supported by
any plugin
Oct 30 18:28:04 tekla ModemManager[878]: <info>  Couldn't find support
for device at '/sys/devices/pci0000:00/0000:00:1c.3/0000:03:00.0': not
supported by any plugin
Oct 30 18:28:04 tekla ModemManager[878]: opening device...
Oct 30 18:28:04 tekla ModemManager[878]: [/dev/cdc-wdm0] Read max
control message size from descriptors file: 4096
Oct 30 18:28:05 tekla ModemManager[878]: <info>  Modem: state changed
(unknown -> disabled)
Oct 30 18:28:05 tekla NetworkManager[1015]: <info>  (cdc-wdm0): modem
state changed, 'disabled' --> 'enabling' (reason: user preference)
Oct 30 18:28:05 tekla NetworkManager[1015]: <info>  (cdc-wdm0): new
Broadband device (carrier: UNKNOWN, driver: 'cdc_mbim', ifindex: 0)
Oct 30 18:28:05 tekla NetworkManager[1015]: <info>  (cdc-wdm0): device
state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Oct 30 18:28:05 tekla NetworkManager[1015]: <info>  (cdc-wdm0): modem
state 'enabling'
Oct 30 18:28:05 tekla NetworkManager[1015]: <info>  (cdc-wdm0): device
state change: unavailable -> disconnected (reason 'none') [20 30 0]
[...]
Oct 30 18:28:34 tekla ModemManager[878]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (registered ->
disabling)
Oct 30 18:28:34 tekla ModemManager[878]: [/dev/cdc-wdm0] unexpected port
hangup!
Oct 30 18:28:54 tekla ModemManager[878]: <warn>  Disabling modems took
too long, shutting down with '1' modems around
Oct 30 18:28:54 tekla NetworkManager[1015]: <info>  ModemManager
disappeared from bus

[...]
then i restarted modemmanager:

Oct 30 18:28:54 tekla NetworkManager[1015]: <info>  ModemManager
available in the bus
Oct 30 18:28:54 tekla ModemManager[2337]: opening device...
Oct 30 18:28:54 tekla ModemManager[2337]: cannot connect to proxy: Could
not connect: Connection refused
Oct 30 18:28:54 tekla ModemManager[2337]: spawning new mbim-proxy (try 1)...
Oct 30 18:28:54 tekla ModemManager[2337]: [/dev/cdc-wdm0] Read max
control message size from descriptors file: 4096
Oct 30 18:28:56 tekla ModemManager[2337]: <info>  Creating modem with
plugin 'Generic' and '2' ports
Oct 30 18:28:56 tekla ModemManager[2337]: <info>  Modem for device at
'/sys/devices/pci0000:00/0000:00:14.0/usb1/1-6' successfully created
Oct 30 18:28:56 tekla ModemManager[2337]: opening device...
Oct 30 18:28:56 tekla ModemManager[2337]: [/dev/cdc-wdm0] Read max
control message size from descriptors file: 4096
Oct 30 18:28:56 tekla ModemManager[2337]: <info>  Couldn't find support
for device at '/sys/devices/pci0000:00/0000:00:19.0': not supported by
any plugin
Oct 30 18:28:56 tekla ModemManager[2337]: <info>  Couldn't find support
for device at '/sys/devices/pci0000:00/0000:00:1c.3/0000:03:00.0': not
supported by any plugin
Oct 30 18:28:57 tekla ModemManager[2337]: <info>  Modem: state changed
(unknown -> disabled)
Oct 30 18:28:57 tekla NetworkManager[1015]: <info>  (cdc-wdm0): modem
state changed, 'disabled' --> 'enabling' (reason: user preference)
Oct 30 18:28:57 tekla NetworkManager[1015]: <info>  (cdc-wdm0): new
Broadband device (carrier: UNKNOWN, driver: 'cdc_mbim', ifindex: 0)
Oct 30 18:28:57 tekla NetworkManager[1015]: <info>  (cdc-wdm0): device
state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Oct 30 18:28:57 tekla NetworkManager[1015]: <info>  (cdc-wdm0): modem
state 'enabling'
Oct 30 18:28:57 tekla NetworkManager[1015]: <info>  (cdc-wdm0): device
state change: unavailable -> disconnected (reason 'none') [20 30 0]
Oct 30 18:28:57 tekla ModemManager[2337]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> enabling)
Oct 30 18:28:57 tekla ModemManager[2337]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed
(unknown -> registering)
Oct 30 18:28:57 tekla ModemManager[2337]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed
(registering -> home)
Oct 30 18:28:57 tekla ModemManager[2337]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (enabling ->
registered)
Oct 30 18:28:57 tekla NetworkManager[1015]: <info>  (cdc-wdm0): modem
state changed, 'enabling' --> 'registered' (reason: user-requested)
Oct 30 18:29:46 tekla NetworkManager[1015]: <info>  (cdc-wdm0):
Activation: starting connection 'Drei (3) Default 1'
(171599cd-7930-4d27-9297-c91262fd1fd9)
Oct 30 18:29:46 tekla NetworkManager[1015]: <info>  (cdc-wdm0): device
state change: disconnected -> prepare (reason 'none') [30 40 0]
Oct 30 18:29:46 tekla NetworkManager[1015]: <info>  NetworkManager state
is now CONNECTING
Oct 30 18:29:46 tekla ModemManager[2337]: <info>  Simple connect started...
Oct 30 18:29:46 tekla ModemManager[2337]: <info>  Simple connect state
(4/8): Wait to get fully enabled
Oct 30 18:29:46 tekla ModemManager[2337]: <info>  Simple connect state
(5/8): Register
Oct 30 18:29:46 tekla ModemManager[2337]: <info>  Simple connect state
(6/8): Bearer
Oct 30 18:29:46 tekla ModemManager[2337]: <info>  Simple connect state
(7/8): Connect
Oct 30 18:29:46 tekla ModemManager[2337]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (registered ->
connecting)
Oct 30 18:29:46 tekla NetworkManager[1015]: <info>  (cdc-wdm0): modem
state changed, 'registered' --> 'connecting' (reason: user-requested)
Oct 30 18:29:50 tekla ModemManager[2337]: <info>  Modem
/org/freedesktop/ModemManager1/Modem/0: state changed (connecting ->
connected)
Oct 30 18:29:50 tekla ModemManager[2337]: <info>  Simple connect state
(8/8): All done
Oct 30 18:29:50 tekla NetworkManager[1015]: <info>  (cdc-wdm0): modem
state changed, 'connecting' --> 'connected' (reason: user-requested)
Oct 30 18:29:50 tekla NetworkManager[1015]: <info>  (cdc-wdm0): device
state change: prepare -> config (reason 'none') [40 50 0]
Oct 30 18:29:50 tekla NetworkManager[1015]: <info>  (cdc-wdm0): device
state change: config -> ip-config (reason 'none') [50 70 0]
Oct 30 18:29:50 tekla NetworkManager[1015]: <info>  (cdc-wdm0): IPv6
configuration disabled
Oct 30 18:29:50 tekla NetworkManager[1015]: <info>  (cdc-wdm0): IPv4
static configuration:
Oct 30 18:29:50 tekla NetworkManager[1015]: <info>    address
10.76.XY.XXX/28
Oct 30 18:29:50 tekla NetworkManager[1015]: <info>    gateway 10.76.XY.XXZ

and i have a wwan0 device, and in network-manager the broadband device
is now called cdc-wdm0 and not lt4112 any more. but i cannot ping anything.
did i forget anything? if you need more detailed debugging info, i can
do more tests...

cheers,
muri