Created attachment 131660 [details]
dmesg

> 
> I am currently trying to get the Sierra EM7455 LTE modem that came with my
> ThinkPad T470p to work.
> 
> Unfortunately, the mbim-proxy process spawned by ModemManager starts
> consuming 100% CPU and the attempt of ModemManager to access the modem fails.
> 
> The attached log shows that there seems to be only a single sensible message
> exchange until the loop starts.
> 
> ModemManager states:
> 
> -- 8< --
> Jun 01 19:20:18 vega ModemManager[585]: <info>  ModemManager (version 1.6.6)
> starting in system bus...
> Jun 01 19:20:20 vega ModemManager[585]: opening device...
> Jun 01 19:20:20 vega ModemManager[585]: cannot connect to proxy: Could not
> connect: Connection refused
> Jun 01 19:20:20 vega ModemManager[585]: spawning new mbim-proxy (try 1)...
> Jun 01 19:20:20 vega ModemManager[585]: [/dev/cdc-wdm1] Read max control
> message size from descriptors file: 4096
> Jun 01 19:20:20 vega ModemManager[585]: <info>  Couldn't check support for
> device at '/sys/devices/pci0000:00/0000:00:1c.0/0000:03:00.0': not supported
> by any plugin
> Jun 01 19:20:20 vega ModemManager[585]: <info>  Couldn't check support for
> device at '/sys/devices/pci0000:00/0000:00:1f.6': not supported by any plugin
> Jun 01 19:20:50 vega ModemManager[585]: proxy configuration failed: closed
> Jun 01 19:20:50 vega ModemManager[585]: <info>  Creating modem with plugin
> 'Sierra' and '2' ports
> Jun 01 19:20:50 vega ModemManager[585]: <warn>  Could not grab port
> (usbmisc/cdc-wdm1): 'Cannot add port 'usbmisc/cdc-wdm1', unsupported'
> Jun 01 19:20:50 vega ModemManager[585]: <warn>  Couldn't create modem for
> device at '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-5': Failed to find
> primary AT port
> -- 8< --
> 
> Any ideas?
> 

Similar to #100938, but didn't have much time to get to look at it. In your case, with a EM7455, I think it's the first time we've seen it; and I do have a EM7455 around if I'm not mistaken.

> 
> 
> P.S.: I am aware of #100938, but what seems to happen in mbim-proxy seems to
> be different for me

We cannot rule out it being the same issue, they look quite similar to me.

Interesting: Switched to Kernel 4.9.30 (linux-lts in Arch Linux) and everything started working. So, at least for me, this looks like it could be a Kernel bug.

This is very interesting. There are almost no differences between those versions.  Could this be the problem?:


bjorn@miraculix:/usr/local/src/git/linux$ git diff v4.9.30:drivers/usb/class/cdc-wdm.c v4.11.3:drivers/usb/class/cdc-wdm.c
diff --git a/v4.9.30:drivers/usb/class/cdc-wdm.c b/v4.11.3:drivers/usb/class/cdc-wdm.c
index 0b845e550fbd..08669fee6d7f 100644
--- a/v4.9.30:drivers/usb/class/cdc-wdm.c
+++ b/v4.11.3:drivers/usb/class/cdc-wdm.c
@@ -510,7 +510,7 @@ static ssize_t wdm_read
                i++;
                if (file->f_flags & O_NONBLOCK) {
                        if (!test_bit(WDM_READ, &desc->flags)) {
-                               rv = cntr ? cntr : -EAGAIN;
+                               rv = -EAGAIN;
                                goto err;
                        }
                        rv = 0;

Having rebooted again under 4.11.3 I am no longer able to reproduce the issue. I'll keep an eye on the situation and will report back if the issue reoccurs.

This is also happening for me: mbim-proxy is using 100% after boot and does not stop, and the modem can't connect.

Laptop: Lenovo Thinkpad T450s
Modem: Sierra EM7345
OS: the problem occurs on fresh installs of the following:
- Ubuntu 16.04.3
- Ubuntu 17.04
- Fedora 26

Firmware: not sure, how can I check?

I tried this, but it fails:

$ sudo mbimcli -d /dev/cdc-wdm0 --ms-query-firmware-id
[31 Aug 2017, 11:23:43] -Warning ** [/dev/cdc-wdm0] error reading from the IOChannel: 'No buffer space available'
error: operation failed: Transaction timed out
error: couldn't close device: Transaction timed out

I noticed this in the kernel log:

$ dmesg | grep mbim
[   21.163723] cdc_mbim 2-4:1.0: setting rx_max = 16384
[   21.164421] cdc_mbim 2-4:1.0: cdc-wdm0: USB WDM device
[   21.164681] cdc_mbim 2-4:1.0 wwan0: register 'cdc_mbim' at usb-0000:00:14.0-4, CDC MBIM, 2a:14:f1:47:c8:34
[   21.164967] usbcore: registered new interface driver cdc_mbim
[   21.364493] cdc_mbim 2-4:1.0 wwp0s20u4: renamed from wwan0
[   25.096326] cdc_mbim 2-4:1.0: nonzero urb status received: -EPIPE
[   25.096534] cdc_mbim 2-4:1.0: nonzero urb status received: -EPIPE
[   25.096703] cdc_mbim 2-4:1.0: nonzero urb status received: -EPIPE
[   25.096889] cdc_mbim 2-4:1.0: nonzero urb status received: -EPIPE
[   25.097071] cdc_mbim 2-4:1.0: nonzero urb status received: -EPIPE
and many more of these EPIPE warnings

(is it correct to comment on this bug, or should I raise another one? Sorry, I'm new here)

Some more info, not sure if it's important:

I've used Ubuntu on this exact hardware for 2 years and never had this problem. I then installed Windows 10 and the drivers for the EM7345, this may have updated the firmware on the modem?

Then I reinstalled Ubuntu and the problem occurred, and occurs with any recent version of Linux I try.

Could installing Windows 10 (and the modem drivers) have changed something?

I would really like to find a fix or workaround to this issue. As it stands, there seems to be no way to run Linux on this laptop and have the LTE modem working, which is really impacting its usability for me.

And frustrating because it used to work before I put Windows on it!

I've had to remove ModemManager for now to prevent the 100% cpu use.

Cheers.

> Laptop: Lenovo Thinkpad T450s
> Modem: Sierra EM7345
> OS: the problem occurs on fresh installs of the following:
> - Ubuntu 16.04.3
> - Ubuntu 17.04
> - Fedora 26

Wow, those are very different kernel versions there, and the problem is seen in all of them?

Installing the modem drivers may have updated the firmware, yes. Are you getting any TTY exposed when running in Linux? If so, can you run these commands through "minicom"?

$ minicom -D /dev/ttyUSB0

AT+CGMR
AT+GMR
AT!ENTERCND="A710"
AT!USBCOMP?
AT!USBCOMP=?

Maybe we can switch this modem to QMI mode as a fallback procedure while this issue isn't solved.

>> Laptop: Lenovo Thinkpad T450s
>> Modem: Sierra EM7345
>> OS: the problem occurs on fresh installs of the following:
>> - Ubuntu 16.04.3
>> - Ubuntu 17.04
>> - Fedora 26
>
> Wow, those are very different kernel versions there, and the problem is seen in
> all of them?

Which kernel versions exactly are we talking about.  Yes, I could
probably go look up those distros, but it's easier to ask.

We have been playing ping-pong with the attempt to solve the
'"out-of-sync" due to missing notifications"'  issue, which used to be
easy to trigger with the EM7345.  So the workaround and the later revert
of that workaround is likely to cause changes for EM7345 users.

It would be interesting to know if this problem is correlated with one
of these kernel version steps:

 v4.8 => v4.9
   833415a3e781 ("cdc-wdm: fix "out-of-sync" due to missing notifications")

 v4.11 => v4.12
   19445816996d ("USB: Revert "cdc-wdm: fix "out-of-sync" due to missing notifications"")

The revert was backported to stable, so we also have to consider

 v4.9.28 => v4.9.29
   6312a84dc8b5 ("USB: Revert "cdc-wdm: fix "out-of-sync" due to missing notifications"")

 v4.10.16 => v4.10.17
   5b92090a53eb ("USB: Revert "cdc-wdm: fix "out-of-sync" due to missing notifications"")

 v4.11.1 => v4.11.2
   f49d36b7b300 ("USB: Revert "cdc-wdm: fix "out-of-sync" due to missing notifications"")



The other suspect kernel change I can think of happened at the same time
that workaround was introduced:

 v4.8 => v4.9
    c1da59dad0eb ("cdc-wdm: Clear read pipeline in case of error")


This did change the driver behaviour in case of errors, so it's
definitely suspicious.  And it is still present in the current driver,
so it will be my primary suspect if the problem is there after v4.9.29,
v4.10.17, v4.11.2 or v4.12.

> Installing the modem drivers may have updated the firmware, yes. Are you
> getting any TTY exposed when running in Linux? If so, can you run these
> commands through "minicom"?
>
> $ minicom -D /dev/ttyUSB0
>
> AT+CGMR
> AT+GMR
> AT!ENTERCND="A710"
> AT!USBCOMP?
> AT!USBCOMP=?
>
> Maybe we can switch this modem to QMI mode as a fallback procedure while this
> issue isn't solved.

The EM7345 is an Intel XMM7160 modem, so that's not an option unfortunately...


Bjørn

(In reply to Aleksander Morgado from comment #9)
> Wow, those are very different kernel versions there, and the problem is seen
> in all of them?

Yes the problem is seen immediately on boot with all three. Kernel versions are:

- Ubuntu 16.04.3 kernel 4.10.0-33-generic #37~16.04.1-Ubuntu 
- Ubuntu 17.04 (not updated) kernel 4.10.0.19-generic #21-Ubuntu
- Fedora 26 - kernel 4.12.x (according to the docs, I didn't actually check)

> Installing the modem drivers may have updated the firmware, yes. Are you
> getting any TTY exposed when running in Linux?

I think so yes:

$ dmesg | grep cdc | grep tty
[   17.901721] cdc_acm 2-4:1.2: ttyACM0: USB ACM device

> If so, can you run these commands through "minicom"?
> 
> $ minicom -D /dev/ttyUSB0
> 
> AT+CGMR
> AT+GMR
> AT!ENTERCND="A710"
> AT!USBCOMP?
> AT!USBCOMP=?

Result:

AT+CGMR
V1.1,11

OK
AT+GMR
V1.1,11

OK
AT!ENTERCND="A710"
ERROR
AT!USBCOMP?
ERROR
AT!USBCOMP=?
ERROR

Thanks for your help. Please let me know what other info I can provide.

Cheers

*** This bug has been marked as a duplicate of bug 100938 ***

FYI I can confirm that this problem is fixed in kernel 4.13.10.

I suspect it's this fix:

https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable.git/commit/drivers/usb/class/cdc-wdm.c?id=8fec9355a968ad240f3a2e9ad55b823cf1cc52ff

Thanks for the help!