4.16 issue with mbim modem and ping with size > 14552 bytes

4.16 issue with mbim modem and ping with size > 14552 bytes

[Daniele Palmas]

Hello,

I have an issue with an USB mbim modem when trying to send with ping
more than 14552 bytes: it looks like to me a kernel issue, but not at
the cdc_mbim or cdc_ncm level, anyway not sure, so I'm reporting the
issue.

My kernel is 4.16. The device is the following:

root@L2122:~# ifconfig
wwp0s20u7i2 Link encap:Ethernet  HWaddr be:3d:f2:f4:0d:e9
          inet addr:2.193.7.73  Bcast:0.0.0.0  Mask:255.255.255.252
          inet6 addr: fe80::bc3d:f2ff:fef4:de9/64 Scope:Link
          UP BROADCAST RUNNING NOARP MULTICAST  MTU:1500  Metric:1
          RX packets:5 errors:0 dropped:0 overruns:0 frame:0
          TX packets:55 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:759 (759.0 B)  TX bytes:6275 (6.2 KB)

Sending ping sized 14552 no issue:

root@L2122:~# ping -s 14552 8.8.8.8
PING 8.8.8.8 (8.8.8.8) 14552(14580) bytes of data.
1448 bytes from 8.8.8.8: icmp_seq=1 ttl=52 (truncated)
1448 bytes from 8.8.8.8: icmp_seq=2 ttl=52 (truncated)
1448 bytes from 8.8.8.8: icmp_seq=3 ttl=52 (truncated)
1448 bytes from 8.8.8.8: icmp_seq=4 ttl=52 (truncated)
1448 bytes from 8.8.8.8: icmp_seq=5 ttl=52 (truncated)
1448 bytes from 8.8.8.8: icmp_seq=6 ttl=52 (truncated)
1448 bytes from 8.8.8.8: icmp_seq=7 ttl=52 (truncated)
1448 bytes from 8.8.8.8: icmp_seq=8 ttl=52 (truncated)
^C
--- 8.8.8.8 ping statistics ---
8 packets transmitted, 8 received, 0% packet loss, time 7008ms
rtt min/avg/max/mdev = 54.887/83.154/102.563/18.502 ms

root@L2122:~# ifconfig
wwp0s20u7i2 Link encap:Ethernet  HWaddr be:3d:f2:f4:0d:e9
          inet addr:2.193.7.73  Bcast:0.0.0.0  Mask:255.255.255.252
          inet6 addr: fe80::bc3d:f2ff:fef4:de9/64 Scope:Link
          UP BROADCAST RUNNING NOARP MULTICAST  MTU:1500  Metric:1
          RX packets:15 errors:0 dropped:0 overruns:0 frame:0
          TX packets:161 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:12583 (12.5 KB)  TX bytes:125999 (125.9 KB)

If I try ping sized 14554, it does not work

root@L2122:~# ping -s 14554 8.8.8.8
PING 8.8.8.8 (8.8.8.8) 14554(14582) bytes of data.
^C
--- 8.8.8.8 ping statistics ---
7 packets transmitted, 0 received, 100% packet loss, time 6122ms

and I see tx errors in the network interface

root@L2122:~# ifconfig
wwp0s20u7i2 Link encap:Ethernet  HWaddr be:3d:f2:f4:0d:e9
          inet addr:2.193.7.73  Bcast:0.0.0.0  Mask:255.255.255.252
          inet6 addr: fe80::bc3d:f2ff:fef4:de9/64 Scope:Link
          UP BROADCAST RUNNING NOARP MULTICAST  MTU:1500  Metric:1
          RX packets:20 errors:0 dropped:0 overruns:0 frame:0
          TX packets:190 errors:5 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:12943 (12.9 KB)  TX bytes:142476 (142.4 KB)

but the real problem is that the network interface seems not to be
working anymore:

root@L2122:~# ping 8.8.8.8
PING 8.8.8.8 (8.8.8.8) 56(84) bytes of data.
^C
--- 8.8.8.8 ping statistics ---
10 packets transmitted, 0 received, 100% packet loss, time 9193ms

root@L2122:~#
root@L2122:~# ifconfig
wwp0s20u7i2 Link encap:Ethernet  HWaddr be:3d:f2:f4:0d:e9
          inet addr:2.193.7.73  Bcast:0.0.0.0  Mask:255.255.255.252
          inet6 addr: fe80::bc3d:f2ff:fef4:de9/64 Scope:Link
          UP BROADCAST RUNNING NOARP MULTICAST  MTU:1500  Metric:1
          RX packets:20 errors:0 dropped:0 overruns:0 frame:0
          TX packets:190 errors:20 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:12943 (12.9 KB)  TX bytes:142476 (142.4 KB)

Nothing relevant in the kernel log.

Anyone can suggest me how to debug this further?

Thanks in advance,
Daniele

Re: 4.16 issue with mbim modem and ping with size > 14552 bytes

[Greg KH]

On Thu, May 24, 2018 at 05:04:49PM +0200, Daniele Palmas wrote:
> Hello,
> 
> I have an issue with an USB mbim modem when trying to send with ping
> more than 14552 bytes: it looks like to me a kernel issue, but not at
> the cdc_mbim or cdc_ncm level, anyway not sure, so I'm reporting the
> issue.
> 
> My kernel is 4.16. The device is the following:

Does older kernels work, or is this something that has always been
there?

I ask, as my mobile provider does horrible things to large packet sizes.
So much so that I have to set the mtu to 1280 just to get things to work
properly when tethering my phone through to my laptop.  So this might be
a network provider issue :)

thanks,

greg k-h

Re: 4.16 issue with mbim modem and ping with size > 14552 bytes

[Daniele Palmas]

Hi Greg,

2018-05-24 17:53 GMT+02:00 Greg KH <gregkh@linuxfoundation.org>:
> On Thu, May 24, 2018 at 05:04:49PM +0200, Daniele Palmas wrote:
>> Hello,
>>
>> I have an issue with an USB mbim modem when trying to send with ping
>> more than 14552 bytes: it looks like to me a kernel issue, but not at
>> the cdc_mbim or cdc_ncm level, anyway not sure, so I'm reporting the
>> issue.
>>
>> My kernel is 4.16. The device is the following:
>
> Does older kernels work, or is this something that has always been
> there?
>

Not tested yet, I'm going to do.

> I ask, as my mobile provider does horrible things to large packet sizes.
> So much so that I have to set the mtu to 1280 just to get things to work
> properly when tethering my phone through to my laptop.  So this might be
> a network provider issue :)
>

Yeah, I thought the same, so I tried the same scenario with Windows 10
but it is working fine.

Thanks,
Daniele

> thanks,
>
> greg k-h

Re: 4.16 issue with mbim modem and ping with size > 14552 bytes

[Daniele Palmas]

2018-05-25 0:54 GMT+02:00 Daniele Palmas <dnlplm@gmail.com>:
> Hi Greg,
>
> 2018-05-24 17:53 GMT+02:00 Greg KH <gregkh@linuxfoundation.org>:
>> On Thu, May 24, 2018 at 05:04:49PM +0200, Daniele Palmas wrote:
>>> Hello,
>>>
>>> I have an issue with an USB mbim modem when trying to send with ping
>>> more than 14552 bytes: it looks like to me a kernel issue, but not at
>>> the cdc_mbim or cdc_ncm level, anyway not sure, so I'm reporting the
>>> issue.
>>>
>>> My kernel is 4.16. The device is the following:
>>
>> Does older kernels work, or is this something that has always been
>> there?
>>
>
> Not tested yet, I'm going to do.
>

So, ping with more than 14552 was working properly until v4.5-rc7:
starting from v4.5 I'm not even able to make a data connection with
mbim since things fail badly with the following:

[  259.551836] ------------[ cut here ]------------
[  259.551848] WARNING: CPU: 2 PID: 0 at
/home/kernel/COD/linux/net/sched/sch_generic.c:303
dev_watchdog+0x237/0x240()
[  259.551860] NETDEV WATCHDOG: wwp0s20u7i2 (cdc_mbim): transmit queue
0 timed out
[  259.551861] Modules linked in: cdc_mbim cdc_wdm cdc_ncm usbnet mii
intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm
snd_hda_codec_realtek snd_hda_codec_hdmi snd_hda_codec_generic
irqbypass crct10dif_pclmul snd_hda_intel snd_hda_codec snd_hda_core
crc32_pclmul snd_hwdep ghash_clmulni_intel aesni_intel aes_x86_64
snd_pcm snd_seq_midi lrw snd_seq_midi_event gf128mul input_leds
snd_rawmidi snd_seq glue_helper snd_seq_device ablk_helper snd_timer
cryptd snd soundcore shpchp serio_raw mac_hid lpc_ich 8250_fintek
mei_me mei parport_pc ppdev lp parport autofs4 hid_generic usbhid hid
i915 i2c_algo_bit drm_kms_helper syscopyarea sysfillrect psmouse
sysimgblt ahci fb_sys_fops e1000e libahci drm ptp pps_core wmi fjes
video
[  259.551889] CPU: 2 PID: 0 Comm: swapper/2 Not tainted
4.5.0-040500-generic #201603140130
[  259.551890] Hardware name: LENOVO 10A6A0J5IX/SHARKBAY, BIOS
FBKT79AUS 04/17/2014
[  259.551891]  0000000000000286 108c91d75cf5b65f ffff88021eb03d98
ffffffff813e0233
[  259.551893]  ffff88021eb03de0 ffffffff81d816a0 ffff88021eb03dd0
ffffffff81080e72
[  259.551894]  0000000000000000 ffff8800cee81880 0000000000000002
ffff8800a19f8000
[  259.551895] Call Trace:
[  259.551896]  <IRQ>  [<ffffffff813e0233>] dump_stack+0x63/0x90
[  259.551903]  [<ffffffff81080e72>] warn_slowpath_common+0x82/0xc0
[  259.551904]  [<ffffffff81080f0c>] warn_slowpath_fmt+0x5c/0x80
[  259.551907]  [<ffffffff8173f557>] dev_watchdog+0x237/0x240
[  259.551909]  [<ffffffff8173f320>] ? qdisc_rcu_free+0x40/0x40
[  259.551910]  [<ffffffff810ecc75>] call_timer_fn+0x35/0x120
[  259.551911]  [<ffffffff8173f320>] ? qdisc_rcu_free+0x40/0x40
[  259.551912]  [<ffffffff810ed626>] run_timer_softirq+0x246/0x2f0
[  259.551914]  [<ffffffff81085836>] __do_softirq+0xf6/0x280
[  259.551916]  [<ffffffff81085b33>] irq_exit+0xa3/0xb0
[  259.551919]  [<ffffffff81826092>] smp_apic_timer_interrupt+0x42/0x50
[  259.551920]  [<ffffffff81824362>] apic_timer_interrupt+0x82/0x90
[  259.551922]  <EOI>  [<ffffffff816b669d>] ? cpuidle_enter_state+0x11d/0x2c0
[  259.551925]  [<ffffffff816b6877>] cpuidle_enter+0x17/0x20
[  259.551928]  [<ffffffff810c413a>] call_cpuidle+0x2a/0x40
[  259.551929]  [<ffffffff810c4505>] cpu_startup_entry+0x295/0x350
[  259.551931]  [<ffffffff81050d9e>] start_secondary+0x15e/0x190
[  259.551933] ---[ end trace 6f8d3c1a1b02644d ]---

but this is probably something different, cause with v4.16 data
connection works fine.

If this is not helpful I guess I need to bisect.

Thanks,
Daniele

>> I ask, as my mobile provider does horrible things to large packet sizes.
>> So much so that I have to set the mtu to 1280 just to get things to work
>> properly when tethering my phone through to my laptop.  So this might be
>> a network provider issue :)
>>
>
> Yeah, I thought the same, so I tried the same scenario with Windows 10
> but it is working fine.
>
> Thanks,
> Daniele
>
>> thanks,
>>
>> greg k-h

Re: 4.16 issue with mbim modem and ping with size > 14552 bytes

[Greg KH]

On Mon, May 28, 2018 at 09:58:01AM +0200, Daniele Palmas wrote:
> 2018-05-25 0:54 GMT+02:00 Daniele Palmas <dnlplm@gmail.com>:
> > Hi Greg,
> >
> > 2018-05-24 17:53 GMT+02:00 Greg KH <gregkh@linuxfoundation.org>:
> >> On Thu, May 24, 2018 at 05:04:49PM +0200, Daniele Palmas wrote:
> >>> Hello,
> >>>
> >>> I have an issue with an USB mbim modem when trying to send with ping
> >>> more than 14552 bytes: it looks like to me a kernel issue, but not at
> >>> the cdc_mbim or cdc_ncm level, anyway not sure, so I'm reporting the
> >>> issue.
> >>>
> >>> My kernel is 4.16. The device is the following:
> >>
> >> Does older kernels work, or is this something that has always been
> >> there?
> >>
> >
> > Not tested yet, I'm going to do.
> >
> 
> So, ping with more than 14552 was working properly until v4.5-rc7:
> starting from v4.5 I'm not even able to make a data connection with
> mbim since things fail badly with the following:
> 
> [  259.551836] ------------[ cut here ]------------
> [  259.551848] WARNING: CPU: 2 PID: 0 at
> /home/kernel/COD/linux/net/sched/sch_generic.c:303
> dev_watchdog+0x237/0x240()
> [  259.551860] NETDEV WATCHDOG: wwp0s20u7i2 (cdc_mbim): transmit queue
> 0 timed out
> [  259.551861] Modules linked in: cdc_mbim cdc_wdm cdc_ncm usbnet mii
> intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm
> snd_hda_codec_realtek snd_hda_codec_hdmi snd_hda_codec_generic
> irqbypass crct10dif_pclmul snd_hda_intel snd_hda_codec snd_hda_core
> crc32_pclmul snd_hwdep ghash_clmulni_intel aesni_intel aes_x86_64
> snd_pcm snd_seq_midi lrw snd_seq_midi_event gf128mul input_leds
> snd_rawmidi snd_seq glue_helper snd_seq_device ablk_helper snd_timer
> cryptd snd soundcore shpchp serio_raw mac_hid lpc_ich 8250_fintek
> mei_me mei parport_pc ppdev lp parport autofs4 hid_generic usbhid hid
> i915 i2c_algo_bit drm_kms_helper syscopyarea sysfillrect psmouse
> sysimgblt ahci fb_sys_fops e1000e libahci drm ptp pps_core wmi fjes
> video
> [  259.551889] CPU: 2 PID: 0 Comm: swapper/2 Not tainted
> 4.5.0-040500-generic #201603140130
> [  259.551890] Hardware name: LENOVO 10A6A0J5IX/SHARKBAY, BIOS
> FBKT79AUS 04/17/2014
> [  259.551891]  0000000000000286 108c91d75cf5b65f ffff88021eb03d98
> ffffffff813e0233
> [  259.551893]  ffff88021eb03de0 ffffffff81d816a0 ffff88021eb03dd0
> ffffffff81080e72
> [  259.551894]  0000000000000000 ffff8800cee81880 0000000000000002
> ffff8800a19f8000
> [  259.551895] Call Trace:
> [  259.551896]  <IRQ>  [<ffffffff813e0233>] dump_stack+0x63/0x90
> [  259.551903]  [<ffffffff81080e72>] warn_slowpath_common+0x82/0xc0
> [  259.551904]  [<ffffffff81080f0c>] warn_slowpath_fmt+0x5c/0x80
> [  259.551907]  [<ffffffff8173f557>] dev_watchdog+0x237/0x240
> [  259.551909]  [<ffffffff8173f320>] ? qdisc_rcu_free+0x40/0x40
> [  259.551910]  [<ffffffff810ecc75>] call_timer_fn+0x35/0x120
> [  259.551911]  [<ffffffff8173f320>] ? qdisc_rcu_free+0x40/0x40
> [  259.551912]  [<ffffffff810ed626>] run_timer_softirq+0x246/0x2f0
> [  259.551914]  [<ffffffff81085836>] __do_softirq+0xf6/0x280
> [  259.551916]  [<ffffffff81085b33>] irq_exit+0xa3/0xb0
> [  259.551919]  [<ffffffff81826092>] smp_apic_timer_interrupt+0x42/0x50
> [  259.551920]  [<ffffffff81824362>] apic_timer_interrupt+0x82/0x90
> [  259.551922]  <EOI>  [<ffffffff816b669d>] ? cpuidle_enter_state+0x11d/0x2c0
> [  259.551925]  [<ffffffff816b6877>] cpuidle_enter+0x17/0x20
> [  259.551928]  [<ffffffff810c413a>] call_cpuidle+0x2a/0x40
> [  259.551929]  [<ffffffff810c4505>] cpu_startup_entry+0x295/0x350
> [  259.551931]  [<ffffffff81050d9e>] start_secondary+0x15e/0x190
> [  259.551933] ---[ end trace 6f8d3c1a1b02644d ]---
> 
> but this is probably something different, cause with v4.16 data
> connection works fine.
> 
> If this is not helpful I guess I need to bisect.

Bisection would be best.  It looks like you narrowed things down really
well already, bisection should go very quickly.

thanks,

greg k-h