2021-01-16 05:28:46

by Grant Grundler

[permalink] [raw]
Subject: [PATCH 1/3] net: usb: cdc_ncm: emit dev_err on error paths

Several error paths in bind/probe code will only emit
output using dev_dbg. But if we are going to fail the
bind/probe, emit related output with "err" priority.

Signed-off-by: Grant Grundler <[email protected]>
---
drivers/net/usb/cdc_ncm.c | 10 +++++-----
1 file changed, 5 insertions(+), 5 deletions(-)

diff --git a/drivers/net/usb/cdc_ncm.c b/drivers/net/usb/cdc_ncm.c
index 5a78848db93f..25498c311551 100644
--- a/drivers/net/usb/cdc_ncm.c
+++ b/drivers/net/usb/cdc_ncm.c
@@ -849,17 +849,17 @@ int cdc_ncm_bind_common(struct usbnet *dev, struct usb_interface *intf, u8 data_

/* check if we got everything */
if (!ctx->data) {
- dev_dbg(&intf->dev, "CDC Union missing and no IAD found\n");
+ dev_err(&intf->dev, "CDC Union missing and no IAD found\n");
goto error;
}
if (cdc_ncm_comm_intf_is_mbim(intf->cur_altsetting)) {
if (!ctx->mbim_desc) {
- dev_dbg(&intf->dev, "MBIM functional descriptor missing\n");
+ dev_err(&intf->dev, "MBIM functional descriptor missing\n");
goto error;
}
} else {
if (!ctx->ether_desc || !ctx->func_desc) {
- dev_dbg(&intf->dev, "NCM or ECM functional descriptors missing\n");
+ dev_err(&intf->dev, "NCM or ECM functional descriptors missing\n");
goto error;
}
}
@@ -868,7 +868,7 @@ int cdc_ncm_bind_common(struct usbnet *dev, struct usb_interface *intf, u8 data_
if (ctx->data != ctx->control) {
temp = usb_driver_claim_interface(driver, ctx->data, dev);
if (temp) {
- dev_dbg(&intf->dev, "failed to claim data intf\n");
+ dev_err(&intf->dev, "failed to claim data intf\n");
goto error;
}
}
@@ -924,7 +924,7 @@ int cdc_ncm_bind_common(struct usbnet *dev, struct usb_interface *intf, u8 data_
if (ctx->ether_desc) {
temp = usbnet_get_ethernet_addr(dev, ctx->ether_desc->iMACAddress);
if (temp) {
- dev_dbg(&intf->dev, "failed to get mac address\n");
+ dev_err(&intf->dev, "failed to get mac address\n");
goto error2;
}
dev_info(&intf->dev, "MAC-Address: %pM\n", dev->net->dev_addr);
--
2.29.2


2021-01-16 05:30:23

by Grant Grundler

[permalink] [raw]
Subject: [PATCH 2/3] net: usb: log errors to dmesg/syslog

Errors in protocol should be logged when the driver aborts operations.
If the driver can carry on and "humor" the device, then emitting
the message as debug output level is fine.

Signed-off-by: Grant Grundler <[email protected]>
---
drivers/net/usb/usbnet.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/drivers/net/usb/usbnet.c b/drivers/net/usb/usbnet.c
index 1447da1d5729..bc7b93399bd5 100644
--- a/drivers/net/usb/usbnet.c
+++ b/drivers/net/usb/usbnet.c
@@ -887,7 +887,7 @@ int usbnet_open (struct net_device *net)

// insist peer be connected
if (info->check_connect && (retval = info->check_connect (dev)) < 0) {
- netif_dbg(dev, ifup, dev->net, "can't open; %d\n", retval);
+ netif_err(dev, ifup, dev->net, "can't open; %d\n", retval);
goto done;
}

--
2.29.2

2021-01-16 05:31:56

by Grant Grundler

[permalink] [raw]
Subject: [PATCH 3/3] net: usb: cdc_ncm: don't spew notifications

RTL8156 sends notifications about every 32ms.
Only display/log notifications when something changes.

This issue has been reported by others:
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1832472
https://lkml.org/lkml/2020/8/27/1083

...
[785962.779840] usb 1-1: new high-speed USB device number 5 using xhci_hcd
[785962.929944] usb 1-1: New USB device found, idVendor=0bda, idProduct=8156, bcdDevice=30.00
[785962.929949] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=6
[785962.929952] usb 1-1: Product: USB 10/100/1G/2.5G LAN
[785962.929954] usb 1-1: Manufacturer: Realtek
[785962.929956] usb 1-1: SerialNumber: 000000001
[785962.991755] usbcore: registered new interface driver cdc_ether
[785963.017068] cdc_ncm 1-1:2.0: MAC-Address: 00:24:27:88:08:15
[785963.017072] cdc_ncm 1-1:2.0: setting rx_max = 16384
[785963.017169] cdc_ncm 1-1:2.0: setting tx_max = 16384
[785963.017682] cdc_ncm 1-1:2.0 usb0: register 'cdc_ncm' at usb-0000:00:14.0-1, CDC NCM, 00:24:27:88:08:15
[785963.019211] usbcore: registered new interface driver cdc_ncm
[785963.023856] usbcore: registered new interface driver cdc_wdm
[785963.025461] usbcore: registered new interface driver cdc_mbim
[785963.038824] cdc_ncm 1-1:2.0 enx002427880815: renamed from usb0
[785963.089586] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
[785963.121673] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
[785963.153682] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
...

This is about 2KB per second and will overwrite all contents of a 1MB
dmesg buffer in under 10 minutes rendering them useless for debugging
many kernel problems.

This is also an extra 180 MB/day in /var/logs (or 1GB per week) rendering
the majority of those logs useless too.

When the link is up (expected state), spew amount is >2x higher:
...
[786139.600992] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
[786139.632997] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
[786139.665097] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
[786139.697100] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
[786139.729094] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
[786139.761108] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
...

Chrome OS cannot support RTL8156 until this is fixed.

Signed-off-by: Grant Grundler <[email protected]>
---
drivers/net/usb/cdc_ncm.c | 12 +++++++++++-
include/linux/usb/usbnet.h | 2 ++
2 files changed, 13 insertions(+), 1 deletion(-)

diff --git a/drivers/net/usb/cdc_ncm.c b/drivers/net/usb/cdc_ncm.c
index 25498c311551..5de096545b86 100644
--- a/drivers/net/usb/cdc_ncm.c
+++ b/drivers/net/usb/cdc_ncm.c
@@ -1827,6 +1827,15 @@ cdc_ncm_speed_change(struct usbnet *dev,
uint32_t rx_speed = le32_to_cpu(data->DLBitRRate);
uint32_t tx_speed = le32_to_cpu(data->ULBitRate);

+ /* if the speed hasn't changed, don't report it.
+ * RTL8156 shipped before 2021 sends notification about every 32ms.
+ */
+ if (dev->rx_speed == rx_speed && dev->tx_speed == tx_speed)
+ return;
+
+ dev->rx_speed = rx_speed;
+ dev->tx_speed = tx_speed;
+
/*
* Currently the USB-NET API does not support reporting the actual
* device speed. Do print it instead.
@@ -1867,7 +1876,8 @@ static void cdc_ncm_status(struct usbnet *dev, struct urb *urb)
* USB_CDC_NOTIFY_NETWORK_CONNECTION notification shall be
* sent by device after USB_CDC_NOTIFY_SPEED_CHANGE.
*/
- usbnet_link_change(dev, !!event->wValue, 0);
+ if (netif_carrier_ok(dev->net) != !!event->wValue)
+ usbnet_link_change(dev, !!event->wValue, 0);
break;

case USB_CDC_NOTIFY_SPEED_CHANGE:
diff --git a/include/linux/usb/usbnet.h b/include/linux/usb/usbnet.h
index 88a7673894d5..cfbfd6fe01df 100644
--- a/include/linux/usb/usbnet.h
+++ b/include/linux/usb/usbnet.h
@@ -81,6 +81,8 @@ struct usbnet {
# define EVENT_LINK_CHANGE 11
# define EVENT_SET_RX_MODE 12
# define EVENT_NO_IP_ALIGN 13
+ u32 rx_speed; /* in bps - NOT Mbps */
+ u32 tx_speed; /* in bps - NOT Mbps */
};

static inline struct usb_driver *driver_of(struct usb_interface *intf)
--
2.29.2

2021-01-18 22:04:04

by Grant Grundler

[permalink] [raw]
Subject: Re: [PATCH 1/3] net: usb: cdc_ncm: emit dev_err on error paths

+nic_swsd [adding per Realtek developer team request]

On Sat, Jan 16, 2021 at 5:26 AM Grant Grundler <[email protected]> wrote:
>
> Several error paths in bind/probe code will only emit
> output using dev_dbg. But if we are going to fail the
> bind/probe, emit related output with "err" priority.
>
> Signed-off-by: Grant Grundler <[email protected]>
> ---
> drivers/net/usb/cdc_ncm.c | 10 +++++-----
> 1 file changed, 5 insertions(+), 5 deletions(-)
>
> diff --git a/drivers/net/usb/cdc_ncm.c b/drivers/net/usb/cdc_ncm.c
> index 5a78848db93f..25498c311551 100644
> --- a/drivers/net/usb/cdc_ncm.c
> +++ b/drivers/net/usb/cdc_ncm.c
> @@ -849,17 +849,17 @@ int cdc_ncm_bind_common(struct usbnet *dev, struct usb_interface *intf, u8 data_
>
> /* check if we got everything */
> if (!ctx->data) {
> - dev_dbg(&intf->dev, "CDC Union missing and no IAD found\n");
> + dev_err(&intf->dev, "CDC Union missing and no IAD found\n");
> goto error;
> }
> if (cdc_ncm_comm_intf_is_mbim(intf->cur_altsetting)) {
> if (!ctx->mbim_desc) {
> - dev_dbg(&intf->dev, "MBIM functional descriptor missing\n");
> + dev_err(&intf->dev, "MBIM functional descriptor missing\n");
> goto error;
> }
> } else {
> if (!ctx->ether_desc || !ctx->func_desc) {
> - dev_dbg(&intf->dev, "NCM or ECM functional descriptors missing\n");
> + dev_err(&intf->dev, "NCM or ECM functional descriptors missing\n");
> goto error;
> }
> }
> @@ -868,7 +868,7 @@ int cdc_ncm_bind_common(struct usbnet *dev, struct usb_interface *intf, u8 data_
> if (ctx->data != ctx->control) {
> temp = usb_driver_claim_interface(driver, ctx->data, dev);
> if (temp) {
> - dev_dbg(&intf->dev, "failed to claim data intf\n");
> + dev_err(&intf->dev, "failed to claim data intf\n");
> goto error;
> }
> }
> @@ -924,7 +924,7 @@ int cdc_ncm_bind_common(struct usbnet *dev, struct usb_interface *intf, u8 data_
> if (ctx->ether_desc) {
> temp = usbnet_get_ethernet_addr(dev, ctx->ether_desc->iMACAddress);
> if (temp) {
> - dev_dbg(&intf->dev, "failed to get mac address\n");
> + dev_err(&intf->dev, "failed to get mac address\n");
> goto error2;
> }
> dev_info(&intf->dev, "MAC-Address: %pM\n", dev->net->dev_addr);
> --
> 2.29.2
>

2021-01-18 22:05:45

by Grant Grundler

[permalink] [raw]
Subject: Re: [PATCH 2/3] net: usb: log errors to dmesg/syslog

+nic_swsd [adding per Realtek developer team request]

On Sat, Jan 16, 2021 at 5:27 AM Grant Grundler <[email protected]> wrote:
>
> Errors in protocol should be logged when the driver aborts operations.
> If the driver can carry on and "humor" the device, then emitting
> the message as debug output level is fine.
>
> Signed-off-by: Grant Grundler <[email protected]>
> ---
> drivers/net/usb/usbnet.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/drivers/net/usb/usbnet.c b/drivers/net/usb/usbnet.c
> index 1447da1d5729..bc7b93399bd5 100644
> --- a/drivers/net/usb/usbnet.c
> +++ b/drivers/net/usb/usbnet.c
> @@ -887,7 +887,7 @@ int usbnet_open (struct net_device *net)
>
> // insist peer be connected
> if (info->check_connect && (retval = info->check_connect (dev)) < 0) {
> - netif_dbg(dev, ifup, dev->net, "can't open; %d\n", retval);
> + netif_err(dev, ifup, dev->net, "can't open; %d\n", retval);
> goto done;
> }
>
> --
> 2.29.2
>

2021-01-18 22:07:10

by Grant Grundler

[permalink] [raw]
Subject: Re: [PATCH 3/3] net: usb: cdc_ncm: don't spew notifications

+nic_swsd [adding per Realtek developer team request]

On Sat, Jan 16, 2021 at 5:27 AM Grant Grundler <[email protected]> wrote:
>
> RTL8156 sends notifications about every 32ms.
> Only display/log notifications when something changes.
>
> This issue has been reported by others:
> https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1832472
> https://lkml.org/lkml/2020/8/27/1083
>
> ...
> [785962.779840] usb 1-1: new high-speed USB device number 5 using xhci_hcd
> [785962.929944] usb 1-1: New USB device found, idVendor=0bda, idProduct=8156, bcdDevice=30.00
> [785962.929949] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=6
> [785962.929952] usb 1-1: Product: USB 10/100/1G/2.5G LAN
> [785962.929954] usb 1-1: Manufacturer: Realtek
> [785962.929956] usb 1-1: SerialNumber: 000000001
> [785962.991755] usbcore: registered new interface driver cdc_ether
> [785963.017068] cdc_ncm 1-1:2.0: MAC-Address: 00:24:27:88:08:15
> [785963.017072] cdc_ncm 1-1:2.0: setting rx_max = 16384
> [785963.017169] cdc_ncm 1-1:2.0: setting tx_max = 16384
> [785963.017682] cdc_ncm 1-1:2.0 usb0: register 'cdc_ncm' at usb-0000:00:14.0-1, CDC NCM, 00:24:27:88:08:15
> [785963.019211] usbcore: registered new interface driver cdc_ncm
> [785963.023856] usbcore: registered new interface driver cdc_wdm
> [785963.025461] usbcore: registered new interface driver cdc_mbim
> [785963.038824] cdc_ncm 1-1:2.0 enx002427880815: renamed from usb0
> [785963.089586] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
> [785963.121673] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
> [785963.153682] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
> ...
>
> This is about 2KB per second and will overwrite all contents of a 1MB
> dmesg buffer in under 10 minutes rendering them useless for debugging
> many kernel problems.
>
> This is also an extra 180 MB/day in /var/logs (or 1GB per week) rendering
> the majority of those logs useless too.
>
> When the link is up (expected state), spew amount is >2x higher:
> ...
> [786139.600992] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
> [786139.632997] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
> [786139.665097] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
> [786139.697100] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
> [786139.729094] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
> [786139.761108] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
> ...
>
> Chrome OS cannot support RTL8156 until this is fixed.
>
> Signed-off-by: Grant Grundler <[email protected]>
> ---
> drivers/net/usb/cdc_ncm.c | 12 +++++++++++-
> include/linux/usb/usbnet.h | 2 ++
> 2 files changed, 13 insertions(+), 1 deletion(-)
>
> diff --git a/drivers/net/usb/cdc_ncm.c b/drivers/net/usb/cdc_ncm.c
> index 25498c311551..5de096545b86 100644
> --- a/drivers/net/usb/cdc_ncm.c
> +++ b/drivers/net/usb/cdc_ncm.c
> @@ -1827,6 +1827,15 @@ cdc_ncm_speed_change(struct usbnet *dev,
> uint32_t rx_speed = le32_to_cpu(data->DLBitRRate);
> uint32_t tx_speed = le32_to_cpu(data->ULBitRate);
>
> + /* if the speed hasn't changed, don't report it.
> + * RTL8156 shipped before 2021 sends notification about every 32ms.
> + */
> + if (dev->rx_speed == rx_speed && dev->tx_speed == tx_speed)
> + return;
> +
> + dev->rx_speed = rx_speed;
> + dev->tx_speed = tx_speed;
> +
> /*
> * Currently the USB-NET API does not support reporting the actual
> * device speed. Do print it instead.
> @@ -1867,7 +1876,8 @@ static void cdc_ncm_status(struct usbnet *dev, struct urb *urb)
> * USB_CDC_NOTIFY_NETWORK_CONNECTION notification shall be
> * sent by device after USB_CDC_NOTIFY_SPEED_CHANGE.
> */
> - usbnet_link_change(dev, !!event->wValue, 0);
> + if (netif_carrier_ok(dev->net) != !!event->wValue)
> + usbnet_link_change(dev, !!event->wValue, 0);
> break;
>
> case USB_CDC_NOTIFY_SPEED_CHANGE:
> diff --git a/include/linux/usb/usbnet.h b/include/linux/usb/usbnet.h
> index 88a7673894d5..cfbfd6fe01df 100644
> --- a/include/linux/usb/usbnet.h
> +++ b/include/linux/usb/usbnet.h
> @@ -81,6 +81,8 @@ struct usbnet {
> # define EVENT_LINK_CHANGE 11
> # define EVENT_SET_RX_MODE 12
> # define EVENT_NO_IP_ALIGN 13
> + u32 rx_speed; /* in bps - NOT Mbps */
> + u32 tx_speed; /* in bps - NOT Mbps */
> };
>
> static inline struct usb_driver *driver_of(struct usb_interface *intf)
> --
> 2.29.2
>

2021-01-19 05:39:40

by Hayes Wang

[permalink] [raw]
Subject: RE: [PATCH 3/3] net: usb: cdc_ncm: don't spew notifications

Grant Grundler <[email protected]>
> Sent: Tuesday, January 19, 2021 6:03 AM
> Subject: Re: [PATCH 3/3] net: usb: cdc_ncm: don't spew notifications
[...]
> > RTL8156 sends notifications about every 32ms.
> > Only display/log notifications when something changes.
> >
> > This issue has been reported by others:
> > https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1832472
> > https://lkml.org/lkml/2020/8/27/1083
> >
> > ...
> > [785962.779840] usb 1-1: new high-speed USB device number 5 using
> xhci_hcd
> > [785962.929944] usb 1-1: New USB device found, idVendor=0bda,
> idProduct=8156, bcdDevice=30.00
> > [785962.929949] usb 1-1: New USB device strings: Mfr=1, Product=2,
> SerialNumber=6
> > [785962.929952] usb 1-1: Product: USB 10/100/1G/2.5G LAN
> > [785962.929954] usb 1-1: Manufacturer: Realtek
> > [785962.929956] usb 1-1: SerialNumber: 000000001
> > [785962.991755] usbcore: registered new interface driver cdc_ether
> > [785963.017068] cdc_ncm 1-1:2.0: MAC-Address: 00:24:27:88:08:15
> > [785963.017072] cdc_ncm 1-1:2.0: setting rx_max = 16384
> > [785963.017169] cdc_ncm 1-1:2.0: setting tx_max = 16384
> > [785963.017682] cdc_ncm 1-1:2.0 usb0: register 'cdc_ncm' at
> usb-0000:00:14.0-1, CDC NCM, 00:24:27:88:08:15
> > [785963.019211] usbcore: registered new interface driver cdc_ncm
> > [785963.023856] usbcore: registered new interface driver cdc_wdm
> > [785963.025461] usbcore: registered new interface driver cdc_mbim
> > [785963.038824] cdc_ncm 1-1:2.0 enx002427880815: renamed from usb0
> > [785963.089586] cdc_ncm 1-1:2.0 enx002427880815: network connection:
> disconnected
> > [785963.121673] cdc_ncm 1-1:2.0 enx002427880815: network connection:
> disconnected
> > [785963.153682] cdc_ncm 1-1:2.0 enx002427880815: network connection:
> disconnected
> > ...
> >
> > This is about 2KB per second and will overwrite all contents of a 1MB
> > dmesg buffer in under 10 minutes rendering them useless for debugging
> > many kernel problems.
> >
> > This is also an extra 180 MB/day in /var/logs (or 1GB per week) rendering
> > the majority of those logs useless too.
> >
> > When the link is up (expected state), spew amount is >2x higher:
> > ...
> > [786139.600992] cdc_ncm 2-1:2.0 enx002427880815: network connection:
> connected
> > [786139.632997] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink
> 2500 mbit/s uplink
> > [786139.665097] cdc_ncm 2-1:2.0 enx002427880815: network connection:
> connected
> > [786139.697100] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink
> 2500 mbit/s uplink
> > [786139.729094] cdc_ncm 2-1:2.0 enx002427880815: network connection:
> connected
> > [786139.761108] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink
> 2500 mbit/s uplink
> > ...
> >
> > Chrome OS cannot support RTL8156 until this is fixed.
> >
> > Signed-off-by: Grant Grundler <[email protected]>

Reviewed-by: Hayes Wang <[email protected]>

Best Regards,
Hayes

2021-01-19 21:51:10

by Jakub Kicinski

[permalink] [raw]
Subject: Re: [PATCH 3/3] net: usb: cdc_ncm: don't spew notifications

On Fri, 15 Jan 2021 21:26:23 -0800 Grant Grundler wrote:
> RTL8156 sends notifications about every 32ms.
> Only display/log notifications when something changes.
>
> This issue has been reported by others:
> https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1832472
> https://lkml.org/lkml/2020/8/27/1083
>
> ...
> [785962.779840] usb 1-1: new high-speed USB device number 5 using xhci_hcd
> [785962.929944] usb 1-1: New USB device found, idVendor=0bda, idProduct=8156, bcdDevice=30.00
> [785962.929949] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=6
> [785962.929952] usb 1-1: Product: USB 10/100/1G/2.5G LAN
> [785962.929954] usb 1-1: Manufacturer: Realtek
> [785962.929956] usb 1-1: SerialNumber: 000000001
> [785962.991755] usbcore: registered new interface driver cdc_ether
> [785963.017068] cdc_ncm 1-1:2.0: MAC-Address: 00:24:27:88:08:15
> [785963.017072] cdc_ncm 1-1:2.0: setting rx_max = 16384
> [785963.017169] cdc_ncm 1-1:2.0: setting tx_max = 16384
> [785963.017682] cdc_ncm 1-1:2.0 usb0: register 'cdc_ncm' at usb-0000:00:14.0-1, CDC NCM, 00:24:27:88:08:15
> [785963.019211] usbcore: registered new interface driver cdc_ncm
> [785963.023856] usbcore: registered new interface driver cdc_wdm
> [785963.025461] usbcore: registered new interface driver cdc_mbim
> [785963.038824] cdc_ncm 1-1:2.0 enx002427880815: renamed from usb0
> [785963.089586] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
> [785963.121673] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
> [785963.153682] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
> ...
>
> This is about 2KB per second and will overwrite all contents of a 1MB
> dmesg buffer in under 10 minutes rendering them useless for debugging
> many kernel problems.
>
> This is also an extra 180 MB/day in /var/logs (or 1GB per week) rendering
> the majority of those logs useless too.
>
> When the link is up (expected state), spew amount is >2x higher:
> ...
> [786139.600992] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
> [786139.632997] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
> [786139.665097] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
> [786139.697100] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
> [786139.729094] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
> [786139.761108] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
> ...
>
> Chrome OS cannot support RTL8156 until this is fixed.

> @@ -1867,7 +1876,8 @@ static void cdc_ncm_status(struct usbnet *dev, struct urb *urb)
> * USB_CDC_NOTIFY_NETWORK_CONNECTION notification shall be
> * sent by device after USB_CDC_NOTIFY_SPEED_CHANGE.
> */
> - usbnet_link_change(dev, !!event->wValue, 0);
> + if (netif_carrier_ok(dev->net) != !!event->wValue)
> + usbnet_link_change(dev, !!event->wValue, 0);
> break;
>
> case USB_CDC_NOTIFY_SPEED_CHANGE:

Thanks for the patch, this looks like an improvement over:

59b4a8fa27f5 ("CDC-NCM: remove "connected" log message")

right? Should we bring the "network connection: connected" message back?


Do you want all of these patches to be applied to 5.11 and backported?
Feels to me like the last one is a fix and the rest can go into -next,
WDYT?

2021-01-20 00:57:28

by Grant Grundler

[permalink] [raw]
Subject: Re: [PATCH 3/3] net: usb: cdc_ncm: don't spew notifications

On Tue, Jan 19, 2021 at 9:46 PM Jakub Kicinski <[email protected]> wrote:
>
> On Fri, 15 Jan 2021 21:26:23 -0800 Grant Grundler wrote:
> > RTL8156 sends notifications about every 32ms.
> > Only display/log notifications when something changes.
> >
> > This issue has been reported by others:
> > https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1832472
> > https://lkml.org/lkml/2020/8/27/1083
> >
> > ...
> > [785962.779840] usb 1-1: new high-speed USB device number 5 using xhci_hcd
> > [785962.929944] usb 1-1: New USB device found, idVendor=0bda, idProduct=8156, bcdDevice=30.00
> > [785962.929949] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=6
> > [785962.929952] usb 1-1: Product: USB 10/100/1G/2.5G LAN
> > [785962.929954] usb 1-1: Manufacturer: Realtek
> > [785962.929956] usb 1-1: SerialNumber: 000000001
> > [785962.991755] usbcore: registered new interface driver cdc_ether
> > [785963.017068] cdc_ncm 1-1:2.0: MAC-Address: 00:24:27:88:08:15
> > [785963.017072] cdc_ncm 1-1:2.0: setting rx_max = 16384
> > [785963.017169] cdc_ncm 1-1:2.0: setting tx_max = 16384
> > [785963.017682] cdc_ncm 1-1:2.0 usb0: register 'cdc_ncm' at usb-0000:00:14.0-1, CDC NCM, 00:24:27:88:08:15
> > [785963.019211] usbcore: registered new interface driver cdc_ncm
> > [785963.023856] usbcore: registered new interface driver cdc_wdm
> > [785963.025461] usbcore: registered new interface driver cdc_mbim
> > [785963.038824] cdc_ncm 1-1:2.0 enx002427880815: renamed from usb0
> > [785963.089586] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
> > [785963.121673] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
> > [785963.153682] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
> > ...
> >
> > This is about 2KB per second and will overwrite all contents of a 1MB
> > dmesg buffer in under 10 minutes rendering them useless for debugging
> > many kernel problems.
> >
> > This is also an extra 180 MB/day in /var/logs (or 1GB per week) rendering
> > the majority of those logs useless too.
> >
> > When the link is up (expected state), spew amount is >2x higher:
> > ...
> > [786139.600992] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
> > [786139.632997] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
> > [786139.665097] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
> > [786139.697100] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
> > [786139.729094] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
> > [786139.761108] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
> > ...
> >
> > Chrome OS cannot support RTL8156 until this is fixed.
>
> > @@ -1867,7 +1876,8 @@ static void cdc_ncm_status(struct usbnet *dev, struct urb *urb)
> > * USB_CDC_NOTIFY_NETWORK_CONNECTION notification shall be
> > * sent by device after USB_CDC_NOTIFY_SPEED_CHANGE.
> > */
> > - usbnet_link_change(dev, !!event->wValue, 0);
> > + if (netif_carrier_ok(dev->net) != !!event->wValue)
> > + usbnet_link_change(dev, !!event->wValue, 0);
> > break;
> >
> > case USB_CDC_NOTIFY_SPEED_CHANGE:
>
> Thanks for the patch, this looks like an improvement over:
>
> 59b4a8fa27f5 ("CDC-NCM: remove "connected" log message")
>
> right? Should we bring the "network connection: connected" message back?

Yes, we can revert Roland's patch. I didn't see that one.

> Do you want all of these patches to be applied to 5.11 and backported?

Yes to 5.11. Only the 3rd one really needs to be applied to stable kernels.

> Feels to me like the last one is a fix and the rest can go into -next,
> WDYT?

Exactly.

Thanks!
grant

2021-01-20 01:03:47

by Grant Grundler

[permalink] [raw]
Subject: Re: [PATCH 3/3] net: usb: cdc_ncm: don't spew notifications

On Wed, Jan 20, 2021 at 12:55 AM Grant Grundler <[email protected]> wrote:
>
> On Tue, Jan 19, 2021 at 9:46 PM Jakub Kicinski <[email protected]> wrote:
> >
> > On Fri, 15 Jan 2021 21:26:23 -0800 Grant Grundler wrote:
> > > RTL8156 sends notifications about every 32ms.
> > > Only display/log notifications when something changes.
> > >
> > > This issue has been reported by others:
> > > https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1832472
> > > https://lkml.org/lkml/2020/8/27/1083
> > >
> > > ...
> > > [785962.779840] usb 1-1: new high-speed USB device number 5 using xhci_hcd
> > > [785962.929944] usb 1-1: New USB device found, idVendor=0bda, idProduct=8156, bcdDevice=30.00
> > > [785962.929949] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=6
> > > [785962.929952] usb 1-1: Product: USB 10/100/1G/2.5G LAN
> > > [785962.929954] usb 1-1: Manufacturer: Realtek
> > > [785962.929956] usb 1-1: SerialNumber: 000000001
> > > [785962.991755] usbcore: registered new interface driver cdc_ether
> > > [785963.017068] cdc_ncm 1-1:2.0: MAC-Address: 00:24:27:88:08:15
> > > [785963.017072] cdc_ncm 1-1:2.0: setting rx_max = 16384
> > > [785963.017169] cdc_ncm 1-1:2.0: setting tx_max = 16384
> > > [785963.017682] cdc_ncm 1-1:2.0 usb0: register 'cdc_ncm' at usb-0000:00:14.0-1, CDC NCM, 00:24:27:88:08:15
> > > [785963.019211] usbcore: registered new interface driver cdc_ncm
> > > [785963.023856] usbcore: registered new interface driver cdc_wdm
> > > [785963.025461] usbcore: registered new interface driver cdc_mbim
> > > [785963.038824] cdc_ncm 1-1:2.0 enx002427880815: renamed from usb0
> > > [785963.089586] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
> > > [785963.121673] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
> > > [785963.153682] cdc_ncm 1-1:2.0 enx002427880815: network connection: disconnected
> > > ...
> > >
> > > This is about 2KB per second and will overwrite all contents of a 1MB
> > > dmesg buffer in under 10 minutes rendering them useless for debugging
> > > many kernel problems.
> > >
> > > This is also an extra 180 MB/day in /var/logs (or 1GB per week) rendering
> > > the majority of those logs useless too.
> > >
> > > When the link is up (expected state), spew amount is >2x higher:
> > > ...
> > > [786139.600992] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
> > > [786139.632997] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
> > > [786139.665097] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
> > > [786139.697100] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
> > > [786139.729094] cdc_ncm 2-1:2.0 enx002427880815: network connection: connected
> > > [786139.761108] cdc_ncm 2-1:2.0 enx002427880815: 2500 mbit/s downlink 2500 mbit/s uplink
> > > ...
> > >
> > > Chrome OS cannot support RTL8156 until this is fixed.
> >
> > > @@ -1867,7 +1876,8 @@ static void cdc_ncm_status(struct usbnet *dev, struct urb *urb)
> > > * USB_CDC_NOTIFY_NETWORK_CONNECTION notification shall be
> > > * sent by device after USB_CDC_NOTIFY_SPEED_CHANGE.
> > > */
> > > - usbnet_link_change(dev, !!event->wValue, 0);
> > > + if (netif_carrier_ok(dev->net) != !!event->wValue)
> > > + usbnet_link_change(dev, !!event->wValue, 0);
> > > break;
> > >
> > > case USB_CDC_NOTIFY_SPEED_CHANGE:
> >
> > Thanks for the patch, this looks like an improvement over:
> >
> > 59b4a8fa27f5 ("CDC-NCM: remove "connected" log message")
> >
> > right? Should we bring the "network connection: connected" message back?
>
> Yes, we can revert Roland's patch. I didn't see that one.
>
> > Do you want all of these patches to be applied to 5.11 and backported?
>
> Yes to 5.11. Only the 3rd one really needs to be applied to stable kernels.

Sorry - I was thinking 5.11 was -next (and that's incorrect).

As you suggested below, only the 3rd one really needs to be applied to
5.11 and other stable kernels.

cheers,
grant

>
> > Feels to me like the last one is a fix and the rest can go into -next,
> > WDYT?
>
> Exactly.
>
> Thanks!
> grant

2021-01-20 01:08:31

by Jakub Kicinski

[permalink] [raw]
Subject: Re: [PATCH 3/3] net: usb: cdc_ncm: don't spew notifications

On Wed, 20 Jan 2021 00:59:17 +0000 Grant Grundler wrote:
> > > Thanks for the patch, this looks like an improvement over:
> > >
> > > 59b4a8fa27f5 ("CDC-NCM: remove "connected" log message")
> > >
> > > right? Should we bring the "network connection: connected" message back?
> >
> > Yes, we can revert Roland's patch. I didn't see that one.
> >
> > > Do you want all of these patches to be applied to 5.11 and backported?
> >
> > Yes to 5.11. Only the 3rd one really needs to be applied to stable kernels.
>
> Sorry - I was thinking 5.11 was -next (and that's incorrect).
>
> As you suggested below, only the 3rd one really needs to be applied to
> 5.11 and other stable kernels.

Cool, would you mind reposting just the 3rd patch separately, and
tagged as [PATCH net] so that CI can give it a shaking? We'll go
from there with the rest.

> >
> > > Feels to me like the last one is a fix and the rest can go into -next,
> > > WDYT?
> >
> > Exactly.

2021-01-20 01:18:46

by Grant Grundler

[permalink] [raw]
Subject: Re: [PATCH 3/3] net: usb: cdc_ncm: don't spew notifications

On Wed, Jan 20, 2021 at 1:05 AM Jakub Kicinski <[email protected]> wrote:
>
> On Wed, 20 Jan 2021 00:59:17 +0000 Grant Grundler wrote:
> > > > Thanks for the patch, this looks like an improvement over:
> > > >
> > > > 59b4a8fa27f5 ("CDC-NCM: remove "connected" log message")
> > > >
> > > > right? Should we bring the "network connection: connected" message back?
> > >
> > > Yes, we can revert Roland's patch. I didn't see that one.
> > >
> > > > Do you want all of these patches to be applied to 5.11 and backported?
> > >
> > > Yes to 5.11. Only the 3rd one really needs to be applied to stable kernels.
> >
> > Sorry - I was thinking 5.11 was -next (and that's incorrect).
> >
> > As you suggested below, only the 3rd one really needs to be applied to
> > 5.11 and other stable kernels.
>
> Cool, would you mind reposting just the 3rd patch separately, and
> tagged as [PATCH net] so that CI can give it a shaking?

Done :)

> We'll go from there with the rest.

Awesome - thank you!

cheers,
grant

>
> > >
> > > > Feels to me like the last one is a fix and the rest can go into -next,
> > > > WDYT?
> > >
> > > Exactly.