| Message ID | 20220304113057.1477958-1-martin.kepplinger@puri.sm (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | usb: xhci: make XHCI_STOP_EP_CMD_TIMEOUT a module parameter | expand |
Am Freitag, dem 04.03.2022 um 12:30 +0100 schrieb Martin Kepplinger: > On the Librem 5 imx8mq system we've seen the stop endpoint command > time out regularly which results in the hub dying. sorry this is pretty useless information. We see this on an internal USB2642 USB 2.0 Hub by Microchip. > > While on the one hand we see "Port resume timed out, port 1-1: 0xfe3" > before this and on the other hand driver-comments suggest that the > driver > might be able to recover instead of dying here, Sarah seemed to have > a > workaround for this particulator problem in mind already: > > Make it a module parameter. So while it might not be the root cause > for > the problem, do this to give users a workaround. > > Signed-off-by: Martin Kepplinger <martin.kepplinger@puri.sm> > --- > drivers/usb/host/xhci-ring.c | 2 +- > drivers/usb/host/xhci.c | 8 +++++++- > drivers/usb/host/xhci.h | 3 +-- > 3 files changed, 9 insertions(+), 4 deletions(-) > > diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci- > ring.c > index d0b6806275e0..e631d408e6b2 100644 > --- a/drivers/usb/host/xhci-ring.c > +++ b/drivers/usb/host/xhci-ring.c > @@ -1133,7 +1133,7 @@ static void xhci_handle_cmd_stop_ep(struct > xhci_hcd *xhci, int slot_id, > xhci_stop_watchdog_timer_in_irq(xhci, > ep); > > mod_timer(&ep->stop_cmd_timer, > - jiffies + XHCI_STOP_EP_CMD_TIMEOUT > * HZ); > + jiffies + xhci->stop_ep_cmd_timeout > * HZ); > xhci_queue_stop_endpoint(xhci, command, > slot_id, ep_index, 0); > xhci_ring_cmd_db(xhci); > > diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c > index a1c781f70d02..37fd05e75dcf 100644 > --- a/drivers/usb/host/xhci.c > +++ b/drivers/usb/host/xhci.c > @@ -37,6 +37,11 @@ static unsigned long long quirks; > module_param(quirks, ullong, S_IRUGO); > MODULE_PARM_DESC(quirks, "Bit flags for quirks to be enabled as > default"); > > +static unsigned int stop_ep_cmd_timeout = 5; > +module_param(stop_ep_cmd_timeout, uint, S_IRUGO | S_IWUSR); > +MODULE_PARM_DESC(stop_ep_cmd_timeout, > + "Stop endpoint command timeout (secs) for URB cancel > watchdog. default=5"); > + > static bool td_on_ring(struct xhci_td *td, struct xhci_ring *ring) > { > struct xhci_segment *seg = ring->first_seg; > @@ -1849,7 +1854,7 @@ static int xhci_urb_dequeue(struct usb_hcd > *hcd, struct urb *urb, int status) > } > ep->ep_state |= EP_STOP_CMD_PENDING; > ep->stop_cmd_timer.expires = jiffies + > - XHCI_STOP_EP_CMD_TIMEOUT * HZ; > + xhci->stop_ep_cmd_timeout * HZ; > add_timer(&ep->stop_cmd_timer); > xhci_queue_stop_endpoint(xhci, command, urb->dev- > >slot_id, > ep_index, 0); > @@ -5288,6 +5293,7 @@ int xhci_gen_setup(struct usb_hcd *hcd, > xhci_get_quirks_t get_quirks) > xhci->hcc_params2 = readl(&xhci->cap_regs- > >hcc_params2); > > xhci->quirks |= quirks; > + xhci->stop_ep_cmd_timeout = stop_ep_cmd_timeout; > > get_quirks(dev, xhci); > > diff --git a/drivers/usb/host/xhci.h b/drivers/usb/host/xhci.h > index 8a0026ee9524..80c9ced4a276 100644 > --- a/drivers/usb/host/xhci.h > +++ b/drivers/usb/host/xhci.h > @@ -1674,8 +1674,6 @@ struct urb_priv { > #define ERST_NUM_SEGS 1 > /* Poll every 60 seconds */ > #define POLL_TIMEOUT 60 > -/* Stop endpoint command timeout (secs) for URB cancellation > watchdog timer */ > -#define XHCI_STOP_EP_CMD_TIMEOUT 5 > /* XXX: Make these module parameters */ > > struct s3_save { > @@ -1899,6 +1897,7 @@ struct xhci_hcd { > #define XHCI_BROKEN_D3COLD BIT_ULL(41) > #define XHCI_EP_CTX_BROKEN_DCS BIT_ULL(42) > > + unsigned int stop_ep_cmd_timeout; > unsigned int num_active_eps; > unsigned int limit_active_eps; > struct xhci_port *hw_ports;
On Fri, Mar 04, 2022 at 12:30:57PM +0100, Martin Kepplinger wrote: > On the Librem 5 imx8mq system we've seen the stop endpoint command > time out regularly which results in the hub dying. > > While on the one hand we see "Port resume timed out, port 1-1: 0xfe3" > before this and on the other hand driver-comments suggest that the driver > might be able to recover instead of dying here, Sarah seemed to have a > workaround for this particulator problem in mind already: > > Make it a module parameter. So while it might not be the root cause for > the problem, do this to give users a workaround. This is not the 1990's, sorry, please do not add new module parameters. They modify code, when you want to modify an individual device. thanks, greg k-h
On 4.3.2022 16.17, Greg KH wrote: > On Fri, Mar 04, 2022 at 12:30:57PM +0100, Martin Kepplinger wrote: >> On the Librem 5 imx8mq system we've seen the stop endpoint command >> time out regularly which results in the hub dying. >> >> While on the one hand we see "Port resume timed out, port 1-1: 0xfe3" >> before this and on the other hand driver-comments suggest that the driver >> might be able to recover instead of dying here, Sarah seemed to have a >> workaround for this particulator problem in mind already: >> >> Make it a module parameter. So while it might not be the root cause for >> the problem, do this to give users a workaround. > > This is not the 1990's, sorry, please do not add new module parameters. > They modify code, when you want to modify an individual device. > Agree, I think we really need to find the rootcause here. There's a known problem with this stop endpoint timeout timer. For all other commands we start the timer when the controller starts processing the command, but the stop endpoint timer is started immediately when command is queued. So it might timeout if some other commend before it failed. I have a patchseries for this. It's still work in progress but should be testable. Pushed to a branch named stop_endpoint_fixes git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git stop_endpoint_fixes https://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git/log/?h=stop_endpoint_fixes Can you try it out and see if it helps? Thanks -Mathias
Am Montag, dem 07.03.2022 um 10:49 +0200 schrieb Mathias Nyman: > On 4.3.2022 16.17, Greg KH wrote: > > On Fri, Mar 04, 2022 at 12:30:57PM +0100, Martin Kepplinger wrote: > > > On the Librem 5 imx8mq system we've seen the stop endpoint > > > command > > > time out regularly which results in the hub dying. > > > > > > While on the one hand we see "Port resume timed out, port 1-1: > > > 0xfe3" > > > before this and on the other hand driver-comments suggest that > > > the driver > > > might be able to recover instead of dying here, Sarah seemed to > > > have a > > > workaround for this particulator problem in mind already: > > > > > > Make it a module parameter. So while it might not be the root > > > cause for > > > the problem, do this to give users a workaround. > > > > This is not the 1990's, sorry, please do not add new module > > parameters. > > They modify code, when you want to modify an individual device. > > > > Agree, I think we really need to find the rootcause here. > > There's a known problem with this stop endpoint timeout timer. > > For all other commands we start the timer when the controller starts > processing the > command, but the stop endpoint timer is started immediately when > command is queued. > So it might timeout if some other commend before it failed. > > I have a patchseries for this. It's still work in progress but should > be testable. > Pushed to a branch named stop_endpoint_fixes > > git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git > stop_endpoint_fixes > https://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git/log/?h=stop_endpoint_fixes > > Can you try it out and see if it helps? > thanks a lot Mathias, I'm running these now. The timeout has not been easy to reproduce (or I'm just lazy) but in a few days I should be able to tell whether that helps. So this thread has been about [14145.960512] xhci-hcd xhci-hcd.4.auto: Port resume timed out, port 1- 1: 0xfe3 [14156.308511] xhci-hcd xhci-hcd.4.auto: xHCI host not responding to stop endpoint command. that I previously tried to work around by increasing XHCI_MAX_REXIT_TIMEOUT_MS and XHCI_STOP_EP_CMD_TIMEOUT. These patches can't help with the following, right? readl_poll_timeout_atomic() with a fixed timeout is called in this case: xhci-hcd xhci-hcd.4.auto: Abort failed to stop command ring: -110 I see that too from time to time. It results in the HC dying as well. thanks, martin
Am Dienstag, dem 08.03.2022 um 17:17 +0100 schrieb Martin Kepplinger: > Am Montag, dem 07.03.2022 um 10:49 +0200 schrieb Mathias Nyman: > > On 4.3.2022 16.17, Greg KH wrote: > > > On Fri, Mar 04, 2022 at 12:30:57PM +0100, Martin Kepplinger > > > wrote: > > > > On the Librem 5 imx8mq system we've seen the stop endpoint > > > > command > > > > time out regularly which results in the hub dying. > > > > > > > > While on the one hand we see "Port resume timed out, port 1-1: > > > > 0xfe3" > > > > before this and on the other hand driver-comments suggest that > > > > the driver > > > > might be able to recover instead of dying here, Sarah seemed to > > > > have a > > > > workaround for this particulator problem in mind already: > > > > > > > > Make it a module parameter. So while it might not be the root > > > > cause for > > > > the problem, do this to give users a workaround. > > > > > > This is not the 1990's, sorry, please do not add new module > > > parameters. > > > They modify code, when you want to modify an individual device. > > > > > > > Agree, I think we really need to find the rootcause here. > > > > There's a known problem with this stop endpoint timeout timer. > > > > For all other commands we start the timer when the controller > > starts > > processing the > > command, but the stop endpoint timer is started immediately when > > command is queued. > > So it might timeout if some other commend before it failed. > > > > I have a patchseries for this. It's still work in progress but > > should > > be testable. > > Pushed to a branch named stop_endpoint_fixes > > > > git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git > > stop_endpoint_fixes > > https://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git/log/?h=stop_endpoint_fixes > > > > Can you try it out and see if it helps? > > > > thanks a lot Mathias, I'm running these now. The timeout has not been > easy to reproduce (or I'm just lazy) but in a few days I should be > able > to tell whether that helps. > > So this thread has been about > > [14145.960512] xhci-hcd xhci-hcd.4.auto: Port resume timed out, port > 1- > 1: 0xfe3 > [14156.308511] xhci-hcd xhci-hcd.4.auto: xHCI host not responding to > stop endpoint command. > > that I previously tried to work around by increasing > XHCI_MAX_REXIT_TIMEOUT_MS and XHCI_STOP_EP_CMD_TIMEOUT. > > > These patches can't help with the following, right? > readl_poll_timeout_atomic() with a fixed timeout is called in this > case: > > xhci-hcd xhci-hcd.4.auto: Abort failed to stop command ring: -110 > > I see that too from time to time. It results in the HC dying as well. > > thanks, > martin > hi Mathias, I already saw "Port resume timed out" and the HC dying running your patches. I append the logs. So for now I saw more success with increasing XHCI_MAX_REXIT_TIMEOUT_MS. thank you, martin Mär 08 18:06:22 pureos kernel: usb 1-1.2: reset high-speed USB device number 10 using xhci-hcd Mär 08 18:06:34 pureos kernel: xhci-hcd xhci-hcd.4.auto: Port resume timed out, port 1-1: 0xfe3 Mär 08 18:06:45 pureos kernel: xhci-hcd xhci-hcd.4.auto: xHCI host not responding to stop endpoint command Mär 08 18:06:45 pureos kernel: xhci-hcd xhci-hcd.4.auto: xHCI host controller not responding, assume dead Mär 08 18:06:45 pureos kernel: xhci-hcd xhci-hcd.4.auto: HC died; cleaning up Mär 08 18:06:45 pureos kernel: usb 1-1: USB disconnect, device number 2 Mär 08 18:06:45 pureos kernel: usb 1-1.1: USB disconnect, device number 3 Mär 08 18:06:50 pureos kernel: ------------[ cut here ]------------ Mär 08 18:06:50 pureos kernel: NETDEV WATCHDOG: wwan0 (qmi_wwan): transmit queue 0 timed out Mär 08 18:06:50 pureos kernel: WARNING: CPU: 1 PID: 0 at net/sched/sch_generic.c:529 dev_watchdog+0x27c/0x284 Mär 08 18:06:50 pureos kernel: Modules linked in: cdc_ether r8152 aes_ce_ccm bnep option usb_wwan usbserial qmi_wwan cdc_wdm usbnet mii usb_f_acm u_serial usb_f_ecm u_ether caam_jr caamhash_desc caamalg_desc ofpart crypto_engine spi_nor mtd hantro_vpu(C) redpine_sdio imx7_media_csi(C) v4l2_vp9 imx_media_common(C) redpine_91x v4l2_h264 bluetooth mac80211 v4l2_mem2mem videobuf2_vmalloc videobuf2_dma_contig cfg80211 videobuf2_memops videobuf2_v4l2 snd_soc_gtm601 snd_soc_simple_card snd_soc_simple_card_utils st_lsm6dsx_spi videobuf2_common imx8mq_mipi_csi2(C) leds_lm3560 gnss_mtk gnss_serial mousedev gnss hi846 s5k3l6xx v4l2_fwnode dw9714 v4l2_async snd_soc_wm8962 vcnl4000 st_lsm6dsx_i2c st_lsm6dsx industrialio_triggered_buffer kfifo_buf videodev mc caam snd_soc_fsl_sai error imx_pcm_dma snd_soc_core snd_pcm_dmaengine snvs_pwrkey snd_pcm snd_timer snd imx2_wdt imx_sdma rfkill_hks virt_dma soundcore watchdog rfkill libcomposite ledtrig_timer ledtrig_pattern fuse ip_tables x_tables ipv6 uas usb_storage Mär 08 18:06:50 pureos kernel: xhci_plat_hcd xhci_hcd usbcore aes_ce_blk crct10dif_ce dwc3 ghash_ce tps6598x sha2_ce typec ulpi clk_bd718x7 cdns_mhdp_imx udc_core roles cdns_mhdp_drmcore sha1_ce imx_dcss pwm_vibra phy_fsl_imx8mq_usb usb_common bq25890_charger edt_ft5x06 Mär 08 18:06:50 pureos kernel: CPU: 1 PID: 0 Comm: swapper/1 Tainted: G C 5.17.0-rc7-librem5-00006-g80df5edbe9cc #50 Mär 08 18:06:50 pureos kernel: Hardware name: Purism Librem 5r4 (DT) Mär 08 18:06:50 pureos kernel: pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--) Mär 08 18:06:50 pureos kernel: pc : dev_watchdog+0x27c/0x284 Mär 08 18:06:50 pureos kernel: lr : dev_watchdog+0x27c/0x284 Mär 08 18:06:50 pureos kernel: sp : ffff800009a1b9f0 Mär 08 18:06:50 pureos kernel: x29: ffff800009a1b9f0 x28: ffff800008abb490 x27: ffff800009a1bae0 Mär 08 18:06:50 pureos kernel: x26: ffff8000091ad000 x25: 0000000000000000 x24: ffff800009518998 Mär 08 18:06:50 pureos kernel: x23: ffff800009516000 x22: 0000000000000000 x21: ffff0000bef893dc Mär 08 18:06:50 pureos kernel: x20: ffff0000bef89000 x19: ffff0000bef89488 x18: 00000000fffffffe Mär 08 18:06:50 pureos kernel: x17: ffff8000b679f000 x16: ffff80000800c000 x15: 0000000000000020 Mär 08 18:06:50 pureos kernel: x14: ffffffffffffffff x13: 74756f2064656d69 x12: 7420302065756575 Mär 08 18:06:50 pureos kernel: x11: ffff8000095ea820 x10: 00000000ffffe000 x9 : ffff8000086ae2c4 Mär 08 18:06:50 pureos kernel: x8 : ffff80000953a820 x7 : 0000000000000000 x6 : 0000000000000000 Mär 08 18:06:50 pureos kernel: x5 : 0000000000000000 x4 : 0000000000000000 x3 : 0000000000000000 Mär 08 18:06:50 pureos kernel: x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffff0000001ee3c0 Mär 08 18:06:50 pureos kernel: Call trace: Mär 08 18:06:50 pureos kernel: dev_watchdog+0x27c/0x284 Mär 08 18:06:50 pureos kernel: call_timer_fn+0x3c/0x1c4 Mär 08 18:06:50 pureos kernel: __run_timers.part.0+0x224/0x2dc Mär 08 18:06:50 pureos kernel: run_timer_softirq+0x48/0x80 Mär 08 18:06:50 pureos kernel: __do_softirq+0x120/0x3b8 Mär 08 18:06:50 pureos kernel: __irq_exit_rcu+0xac/0xf0 Mär 08 18:06:50 pureos kernel: irq_exit_rcu+0x1c/0x30 Mär 08 18:06:50 pureos kernel: el1_interrupt+0x38/0x84 Mär 08 18:06:50 pureos kernel: el1h_64_irq_handler+0x18/0x24 Mär 08 18:06:50 pureos kernel: el1h_64_irq+0x78/0x7c Mär 08 18:06:50 pureos kernel: cpuidle_enter_state+0xc4/0x3d0 Mär 08 18:06:50 pureos kernel: cpuidle_enter+0x44/0x5c Mär 08 18:06:50 pureos kernel: do_idle+0x218/0x2a0 Mär 08 18:06:50 pureos kernel: cpu_startup_entry+0x30/0x80 Mär 08 18:06:50 pureos kernel: secondary_start_kernel+0x138/0x160 Mär 08 18:06:50 pureos kernel: __secondary_switched+0x94/0x98 Mär 08 18:06:50 pureos kernel: ---[ end trace 0000000000000000 ]--- Mär 08 18:09:42 pureos kernel: INFO: task kworker/0:2:5044 blocked for more than 120 seconds. Mär 08 18:09:42 pureos kernel: Tainted: G WC 5.17.0-rc7-librem5-00006-g80df5edbe9cc #50 Mär 08 18:09:42 pureos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mär 08 18:09:42 pureos kernel: task:kworker/0:2 state:D stack: 0 pid: 5044 ppid: 2 flags:0x00000008 Mär 08 18:09:42 pureos kernel: Workqueue: usb_hub_wq hub_event [usbcore] Mär 08 18:09:42 pureos kernel: Call trace: Mär 08 18:09:42 pureos kernel: __switch_to+0xf8/0x150 Mär 08 18:09:42 pureos kernel: __schedule+0x28c/0x72c Mär 08 18:09:42 pureos kernel: schedule+0x60/0x100 Mär 08 18:09:42 pureos kernel: __bio_queue_enter+0xbc/0x18c Mär 08 18:09:42 pureos kernel: blk_mq_submit_bio+0x364/0x65c Mär 08 18:09:42 pureos kernel: __submit_bio+0xac/0xc0 Mär 08 18:09:42 pureos kernel: submit_bio_noacct+0x1ec/0x240 Mär 08 18:09:42 pureos kernel: submit_bio+0x64/0x180 Mär 08 18:09:42 pureos kernel: submit_bh_wbc+0x158/0x1d0 Mär 08 18:09:42 pureos kernel: __block_write_full_page+0x238/0x550 Mär 08 18:09:42 pureos kernel: block_write_full_page+0x118/0x134 Mär 08 18:09:42 pureos kernel: blkdev_writepage+0x28/0x3c Mär 08 18:09:42 pureos kernel: __writepage+0x2c/0xc0 Mär 08 18:09:42 pureos kernel: write_cache_pages+0x188/0x3e0 Mär 08 18:09:42 pureos kernel: generic_writepages+0x68/0xb0 Mär 08 18:09:42 pureos kernel: blkdev_writepages+0x1c/0x2c Mär 08 18:09:42 pureos kernel: do_writepages+0x94/0x1c0 Mär 08 18:09:42 pureos kernel: filemap_fdatawrite_wbc+0x8c/0xc0 Mär 08 18:09:42 pureos kernel: filemap_flush+0x54/0x80 Mär 08 18:09:42 pureos kernel: sync_blockdev_nowait+0x28/0x40 Mär 08 18:09:42 pureos kernel: sync_filesystem+0x74/0xc0 Mär 08 18:09:42 pureos kernel: fsync_bdev+0x6c/0x90 Mär 08 18:09:42 pureos kernel: delete_partition+0x20/0x84 Mär 08 18:09:42 pureos kernel: blk_drop_partitions+0x54/0xa0 Mär 08 18:09:42 pureos kernel: del_gendisk+0x78/0x240 Mär 08 18:09:42 pureos kernel: sd_remove+0x50/0x90 Mär 08 18:09:42 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:09:42 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:09:42 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:09:42 pureos kernel: device_del+0x180/0x39c Mär 08 18:09:42 pureos kernel: __scsi_remove_device+0x100/0x130 Mär 08 18:09:42 pureos kernel: scsi_forget_host+0x80/0xc0 Mär 08 18:09:42 pureos kernel: scsi_remove_host+0x7c/0x130 Mär 08 18:09:42 pureos kernel: usb_stor_disconnect+0x54/0x100 [usb_storage] Mär 08 18:09:42 pureos kernel: usb_unbind_interface+0x84/0x29c [usbcore] Mär 08 18:09:42 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:09:42 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:09:42 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:09:42 pureos kernel: device_del+0x180/0x39c Mär 08 18:09:42 pureos kernel: usb_disable_device+0x104/0x250 [usbcore] Mär 08 18:09:42 pureos kernel: usb_disconnect+0x114/0x300 [usbcore] Mär 08 18:09:42 pureos kernel: usb_disconnect+0xbc/0x300 [usbcore] Mär 08 18:09:42 pureos kernel: hub_event+0xb90/0x18f0 [usbcore] Mär 08 18:09:42 pureos kernel: process_one_work+0x208/0x4bc Mär 08 18:09:42 pureos kernel: worker_thread+0x148/0x46c Mär 08 18:09:42 pureos kernel: kthread+0x118/0x120 Mär 08 18:09:42 pureos kernel: ret_from_fork+0x10/0x20 Mär 08 18:11:43 pureos kernel: INFO: task kworker/0:2:5044 blocked for more than 241 seconds. Mär 08 18:11:43 pureos kernel: Tainted: G WC 5.17.0-rc7-librem5-00006-g80df5edbe9cc #50 Mär 08 18:11:43 pureos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mär 08 18:11:43 pureos kernel: task:kworker/0:2 state:D stack: 0 pid: 5044 ppid: 2 flags:0x00000008 Mär 08 18:11:43 pureos kernel: Workqueue: usb_hub_wq hub_event [usbcore] Mär 08 18:11:43 pureos kernel: Call trace: Mär 08 18:11:43 pureos kernel: __switch_to+0xf8/0x150 Mär 08 18:11:43 pureos kernel: __schedule+0x28c/0x72c Mär 08 18:11:43 pureos kernel: schedule+0x60/0x100 Mär 08 18:11:43 pureos kernel: __bio_queue_enter+0xbc/0x18c Mär 08 18:11:43 pureos kernel: blk_mq_submit_bio+0x364/0x65c Mär 08 18:11:43 pureos kernel: __submit_bio+0xac/0xc0 Mär 08 18:11:43 pureos kernel: submit_bio_noacct+0x1ec/0x240 Mär 08 18:11:43 pureos kernel: submit_bio+0x64/0x180 Mär 08 18:11:43 pureos kernel: submit_bh_wbc+0x158/0x1d0 Mär 08 18:11:43 pureos kernel: __block_write_full_page+0x238/0x550 Mär 08 18:11:43 pureos kernel: block_write_full_page+0x118/0x134 Mär 08 18:11:43 pureos kernel: blkdev_writepage+0x28/0x3c Mär 08 18:11:43 pureos kernel: __writepage+0x2c/0xc0 Mär 08 18:11:43 pureos kernel: write_cache_pages+0x188/0x3e0 Mär 08 18:11:43 pureos kernel: generic_writepages+0x68/0xb0 Mär 08 18:11:43 pureos kernel: blkdev_writepages+0x1c/0x2c Mär 08 18:11:43 pureos kernel: do_writepages+0x94/0x1c0 Mär 08 18:11:43 pureos kernel: filemap_fdatawrite_wbc+0x8c/0xc0 Mär 08 18:11:43 pureos kernel: filemap_flush+0x54/0x80 Mär 08 18:11:43 pureos kernel: sync_blockdev_nowait+0x28/0x40 Mär 08 18:11:43 pureos kernel: sync_filesystem+0x74/0xc0 Mär 08 18:11:43 pureos kernel: fsync_bdev+0x6c/0x90 Mär 08 18:11:43 pureos kernel: delete_partition+0x20/0x84 Mär 08 18:11:43 pureos kernel: blk_drop_partitions+0x54/0xa0 Mär 08 18:11:43 pureos kernel: del_gendisk+0x78/0x240 Mär 08 18:11:43 pureos kernel: sd_remove+0x50/0x90 Mär 08 18:11:43 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:11:43 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:11:43 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:11:43 pureos kernel: device_del+0x180/0x39c Mär 08 18:11:43 pureos kernel: __scsi_remove_device+0x100/0x130 Mär 08 18:11:43 pureos kernel: scsi_forget_host+0x80/0xc0 Mär 08 18:11:43 pureos kernel: scsi_remove_host+0x7c/0x130 Mär 08 18:11:43 pureos kernel: usb_stor_disconnect+0x54/0x100 [usb_storage] Mär 08 18:11:43 pureos kernel: usb_unbind_interface+0x84/0x29c [usbcore] Mär 08 18:11:43 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:11:43 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:11:43 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:11:43 pureos kernel: device_del+0x180/0x39c Mär 08 18:11:43 pureos kernel: usb_disable_device+0x104/0x250 [usbcore] Mär 08 18:11:43 pureos kernel: usb_disconnect+0x114/0x300 [usbcore] Mär 08 18:11:43 pureos kernel: usb_disconnect+0xbc/0x300 [usbcore] Mär 08 18:11:43 pureos kernel: hub_event+0xb90/0x18f0 [usbcore] Mär 08 18:11:43 pureos kernel: process_one_work+0x208/0x4bc Mär 08 18:11:43 pureos kernel: worker_thread+0x148/0x46c Mär 08 18:11:43 pureos kernel: kthread+0x118/0x120 Mär 08 18:11:43 pureos kernel: ret_from_fork+0x10/0x20 Mär 08 18:13:44 pureos kernel: INFO: task kworker/0:2:5044 blocked for more than 362 seconds. Mär 08 18:13:44 pureos kernel: Tainted: G WC 5.17.0-rc7-librem5-00006-g80df5edbe9cc #50 Mär 08 18:13:44 pureos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mär 08 18:13:44 pureos kernel: task:kworker/0:2 state:D stack: 0 pid: 5044 ppid: 2 flags:0x00000008 Mär 08 18:13:44 pureos kernel: Workqueue: usb_hub_wq hub_event [usbcore] Mär 08 18:13:44 pureos kernel: Call trace: Mär 08 18:13:44 pureos kernel: __switch_to+0xf8/0x150 Mär 08 18:13:44 pureos kernel: __schedule+0x28c/0x72c Mär 08 18:13:44 pureos kernel: schedule+0x60/0x100 Mär 08 18:13:44 pureos kernel: __bio_queue_enter+0xbc/0x18c Mär 08 18:13:44 pureos kernel: blk_mq_submit_bio+0x364/0x65c Mär 08 18:13:44 pureos kernel: __submit_bio+0xac/0xc0 Mär 08 18:13:44 pureos kernel: submit_bio_noacct+0x1ec/0x240 Mär 08 18:13:44 pureos kernel: submit_bio+0x64/0x180 Mär 08 18:13:44 pureos kernel: submit_bh_wbc+0x158/0x1d0 Mär 08 18:13:44 pureos kernel: __block_write_full_page+0x238/0x550 Mär 08 18:13:44 pureos kernel: block_write_full_page+0x118/0x134 Mär 08 18:13:44 pureos kernel: blkdev_writepage+0x28/0x3c Mär 08 18:13:44 pureos kernel: __writepage+0x2c/0xc0 Mär 08 18:13:44 pureos kernel: write_cache_pages+0x188/0x3e0 Mär 08 18:13:44 pureos kernel: generic_writepages+0x68/0xb0 Mär 08 18:13:44 pureos kernel: blkdev_writepages+0x1c/0x2c Mär 08 18:13:44 pureos kernel: do_writepages+0x94/0x1c0 Mär 08 18:13:44 pureos kernel: filemap_fdatawrite_wbc+0x8c/0xc0 Mär 08 18:13:44 pureos kernel: filemap_flush+0x54/0x80 Mär 08 18:13:44 pureos kernel: sync_blockdev_nowait+0x28/0x40 Mär 08 18:13:44 pureos kernel: sync_filesystem+0x74/0xc0 Mär 08 18:13:44 pureos kernel: fsync_bdev+0x6c/0x90 Mär 08 18:13:44 pureos kernel: delete_partition+0x20/0x84 Mär 08 18:13:44 pureos kernel: blk_drop_partitions+0x54/0xa0 Mär 08 18:13:44 pureos kernel: del_gendisk+0x78/0x240 Mär 08 18:13:44 pureos kernel: sd_remove+0x50/0x90 Mär 08 18:13:44 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:13:44 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:13:44 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:13:44 pureos kernel: device_del+0x180/0x39c Mär 08 18:13:44 pureos kernel: __scsi_remove_device+0x100/0x130 Mär 08 18:13:44 pureos kernel: scsi_forget_host+0x80/0xc0 Mär 08 18:13:44 pureos kernel: scsi_remove_host+0x7c/0x130 Mär 08 18:13:44 pureos kernel: usb_stor_disconnect+0x54/0x100 [usb_storage] Mär 08 18:13:44 pureos kernel: usb_unbind_interface+0x84/0x29c [usbcore] Mär 08 18:13:44 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:13:44 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:13:44 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:13:44 pureos kernel: device_del+0x180/0x39c Mär 08 18:13:44 pureos kernel: usb_disable_device+0x104/0x250 [usbcore] Mär 08 18:13:44 pureos kernel: usb_disconnect+0x114/0x300 [usbcore] Mär 08 18:13:44 pureos kernel: usb_disconnect+0xbc/0x300 [usbcore] Mär 08 18:13:44 pureos kernel: hub_event+0xb90/0x18f0 [usbcore] Mär 08 18:13:44 pureos kernel: process_one_work+0x208/0x4bc Mär 08 18:13:44 pureos kernel: worker_thread+0x148/0x46c Mär 08 18:13:44 pureos kernel: kthread+0x118/0x120 Mär 08 18:13:44 pureos kernel: ret_from_fork+0x10/0x20 Mär 08 18:15:44 pureos kernel: INFO: task kworker/0:2:5044 blocked for more than 483 seconds. Mär 08 18:15:44 pureos kernel: Tainted: G WC 5.17.0-rc7-librem5-00006-g80df5edbe9cc #50 Mär 08 18:15:44 pureos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mär 08 18:15:44 pureos kernel: task:kworker/0:2 state:D stack: 0 pid: 5044 ppid: 2 flags:0x00000008 Mär 08 18:15:44 pureos kernel: Workqueue: usb_hub_wq hub_event [usbcore] Mär 08 18:15:44 pureos kernel: Call trace: Mär 08 18:15:44 pureos kernel: __switch_to+0xf8/0x150 Mär 08 18:15:44 pureos kernel: __schedule+0x28c/0x72c Mär 08 18:15:44 pureos kernel: schedule+0x60/0x100 Mär 08 18:15:44 pureos kernel: __bio_queue_enter+0xbc/0x18c Mär 08 18:15:44 pureos kernel: blk_mq_submit_bio+0x364/0x65c Mär 08 18:15:44 pureos kernel: __submit_bio+0xac/0xc0 Mär 08 18:15:44 pureos kernel: submit_bio_noacct+0x1ec/0x240 Mär 08 18:15:44 pureos kernel: submit_bio+0x64/0x180 Mär 08 18:15:44 pureos kernel: submit_bh_wbc+0x158/0x1d0 Mär 08 18:15:44 pureos kernel: __block_write_full_page+0x238/0x550 Mär 08 18:15:44 pureos kernel: block_write_full_page+0x118/0x134 Mär 08 18:15:44 pureos kernel: blkdev_writepage+0x28/0x3c Mär 08 18:15:44 pureos kernel: __writepage+0x2c/0xc0 Mär 08 18:15:44 pureos kernel: write_cache_pages+0x188/0x3e0 Mär 08 18:15:44 pureos kernel: generic_writepages+0x68/0xb0 Mär 08 18:15:44 pureos kernel: blkdev_writepages+0x1c/0x2c Mär 08 18:15:44 pureos kernel: do_writepages+0x94/0x1c0 Mär 08 18:15:44 pureos kernel: filemap_fdatawrite_wbc+0x8c/0xc0 Mär 08 18:15:44 pureos kernel: filemap_flush+0x54/0x80 Mär 08 18:15:44 pureos kernel: sync_blockdev_nowait+0x28/0x40 Mär 08 18:15:44 pureos kernel: sync_filesystem+0x74/0xc0 Mär 08 18:15:44 pureos kernel: fsync_bdev+0x6c/0x90 Mär 08 18:15:44 pureos kernel: delete_partition+0x20/0x84 Mär 08 18:15:44 pureos kernel: blk_drop_partitions+0x54/0xa0 Mär 08 18:15:44 pureos kernel: del_gendisk+0x78/0x240 Mär 08 18:15:44 pureos kernel: sd_remove+0x50/0x90 Mär 08 18:15:44 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:15:44 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:15:44 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:15:44 pureos kernel: device_del+0x180/0x39c Mär 08 18:15:44 pureos kernel: __scsi_remove_device+0x100/0x130 Mär 08 18:15:44 pureos kernel: scsi_forget_host+0x80/0xc0 Mär 08 18:15:44 pureos kernel: scsi_remove_host+0x7c/0x130 Mär 08 18:15:44 pureos kernel: usb_stor_disconnect+0x54/0x100 [usb_storage] Mär 08 18:15:44 pureos kernel: usb_unbind_interface+0x84/0x29c [usbcore] Mär 08 18:15:44 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:15:44 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:15:44 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:15:44 pureos kernel: device_del+0x180/0x39c Mär 08 18:15:44 pureos kernel: usb_disable_device+0x104/0x250 [usbcore] Mär 08 18:15:44 pureos kernel: usb_disconnect+0x114/0x300 [usbcore] Mär 08 18:15:44 pureos kernel: usb_disconnect+0xbc/0x300 [usbcore] Mär 08 18:15:44 pureos kernel: hub_event+0xb90/0x18f0 [usbcore] Mär 08 18:15:44 pureos kernel: process_one_work+0x208/0x4bc Mär 08 18:15:44 pureos kernel: worker_thread+0x148/0x46c Mär 08 18:15:44 pureos kernel: kthread+0x118/0x120 Mär 08 18:15:44 pureos kernel: ret_from_fork+0x10/0x20 Mär 08 18:17:45 pureos kernel: INFO: task kworker/0:2:5044 blocked for more than 604 seconds. Mär 08 18:17:45 pureos kernel: Tainted: G WC 5.17.0-rc7-librem5-00006-g80df5edbe9cc #50 Mär 08 18:17:45 pureos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mär 08 18:17:45 pureos kernel: task:kworker/0:2 state:D stack: 0 pid: 5044 ppid: 2 flags:0x00000008 Mär 08 18:17:45 pureos kernel: Workqueue: usb_hub_wq hub_event [usbcore] Mär 08 18:17:45 pureos kernel: Call trace: Mär 08 18:17:45 pureos kernel: __switch_to+0xf8/0x150 Mär 08 18:17:45 pureos kernel: __schedule+0x28c/0x72c Mär 08 18:17:45 pureos kernel: schedule+0x60/0x100 Mär 08 18:17:45 pureos kernel: __bio_queue_enter+0xbc/0x18c Mär 08 18:17:45 pureos kernel: blk_mq_submit_bio+0x364/0x65c Mär 08 18:17:45 pureos kernel: __submit_bio+0xac/0xc0 Mär 08 18:17:45 pureos kernel: submit_bio_noacct+0x1ec/0x240 Mär 08 18:17:45 pureos kernel: submit_bio+0x64/0x180 Mär 08 18:17:45 pureos kernel: submit_bh_wbc+0x158/0x1d0 Mär 08 18:17:45 pureos kernel: __block_write_full_page+0x238/0x550 Mär 08 18:17:45 pureos kernel: block_write_full_page+0x118/0x134 Mär 08 18:17:45 pureos kernel: blkdev_writepage+0x28/0x3c Mär 08 18:17:45 pureos kernel: __writepage+0x2c/0xc0 Mär 08 18:17:45 pureos kernel: write_cache_pages+0x188/0x3e0 Mär 08 18:17:45 pureos kernel: generic_writepages+0x68/0xb0 Mär 08 18:17:45 pureos kernel: blkdev_writepages+0x1c/0x2c Mär 08 18:17:45 pureos kernel: do_writepages+0x94/0x1c0 Mär 08 18:17:45 pureos kernel: filemap_fdatawrite_wbc+0x8c/0xc0 Mär 08 18:17:45 pureos kernel: filemap_flush+0x54/0x80 Mär 08 18:17:45 pureos kernel: sync_blockdev_nowait+0x28/0x40 Mär 08 18:17:45 pureos kernel: sync_filesystem+0x74/0xc0 Mär 08 18:17:45 pureos kernel: fsync_bdev+0x6c/0x90 Mär 08 18:17:45 pureos kernel: delete_partition+0x20/0x84 Mär 08 18:17:45 pureos kernel: blk_drop_partitions+0x54/0xa0 Mär 08 18:17:45 pureos kernel: del_gendisk+0x78/0x240 Mär 08 18:17:45 pureos kernel: sd_remove+0x50/0x90 Mär 08 18:17:45 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:17:45 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:17:45 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:17:45 pureos kernel: device_del+0x180/0x39c Mär 08 18:17:45 pureos kernel: __scsi_remove_device+0x100/0x130 Mär 08 18:17:45 pureos kernel: scsi_forget_host+0x80/0xc0 Mär 08 18:17:45 pureos kernel: scsi_remove_host+0x7c/0x130 Mär 08 18:17:45 pureos kernel: usb_stor_disconnect+0x54/0x100 [usb_storage] Mär 08 18:17:45 pureos kernel: usb_unbind_interface+0x84/0x29c [usbcore] Mär 08 18:17:45 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:17:45 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:17:45 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:17:45 pureos kernel: device_del+0x180/0x39c Mär 08 18:17:45 pureos kernel: usb_disable_device+0x104/0x250 [usbcore] Mär 08 18:17:45 pureos kernel: usb_disconnect+0x114/0x300 [usbcore] Mär 08 18:17:45 pureos kernel: usb_disconnect+0xbc/0x300 [usbcore] Mär 08 18:17:45 pureos kernel: hub_event+0xb90/0x18f0 [usbcore] Mär 08 18:17:45 pureos kernel: process_one_work+0x208/0x4bc Mär 08 18:17:45 pureos kernel: worker_thread+0x148/0x46c Mär 08 18:17:45 pureos kernel: kthread+0x118/0x120 Mär 08 18:17:45 pureos kernel: ret_from_fork+0x10/0x20 Mär 08 18:18:36 pureos kernel: edt_ft5x06 2-0038: Unable to fetch data, error: -6 Mär 08 18:19:46 pureos kernel: INFO: task kworker/0:2:5044 blocked for more than 724 seconds. Mär 08 18:19:46 pureos kernel: Tainted: G WC 5.17.0-rc7-librem5-00006-g80df5edbe9cc #50 Mär 08 18:19:46 pureos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mär 08 18:19:46 pureos kernel: task:kworker/0:2 state:D stack: 0 pid: 5044 ppid: 2 flags:0x00000008 Mär 08 18:19:46 pureos kernel: Workqueue: usb_hub_wq hub_event [usbcore] Mär 08 18:19:46 pureos kernel: Call trace: Mär 08 18:19:46 pureos kernel: __switch_to+0xf8/0x150 Mär 08 18:19:46 pureos kernel: __schedule+0x28c/0x72c Mär 08 18:19:46 pureos kernel: schedule+0x60/0x100 Mär 08 18:19:46 pureos kernel: __bio_queue_enter+0xbc/0x18c Mär 08 18:19:46 pureos kernel: blk_mq_submit_bio+0x364/0x65c Mär 08 18:19:46 pureos kernel: __submit_bio+0xac/0xc0 Mär 08 18:19:46 pureos kernel: submit_bio_noacct+0x1ec/0x240 Mär 08 18:19:46 pureos kernel: submit_bio+0x64/0x180 Mär 08 18:19:46 pureos kernel: submit_bh_wbc+0x158/0x1d0 Mär 08 18:19:46 pureos kernel: __block_write_full_page+0x238/0x550 Mär 08 18:19:46 pureos kernel: block_write_full_page+0x118/0x134 Mär 08 18:19:46 pureos kernel: blkdev_writepage+0x28/0x3c Mär 08 18:19:46 pureos kernel: __writepage+0x2c/0xc0 Mär 08 18:19:46 pureos kernel: write_cache_pages+0x188/0x3e0 Mär 08 18:19:46 pureos kernel: generic_writepages+0x68/0xb0 Mär 08 18:19:46 pureos kernel: blkdev_writepages+0x1c/0x2c Mär 08 18:19:46 pureos kernel: do_writepages+0x94/0x1c0 Mär 08 18:19:46 pureos kernel: filemap_fdatawrite_wbc+0x8c/0xc0 Mär 08 18:19:46 pureos kernel: filemap_flush+0x54/0x80 Mär 08 18:19:46 pureos kernel: sync_blockdev_nowait+0x28/0x40 Mär 08 18:19:46 pureos kernel: sync_filesystem+0x74/0xc0 Mär 08 18:19:46 pureos kernel: fsync_bdev+0x6c/0x90 Mär 08 18:19:46 pureos kernel: delete_partition+0x20/0x84 Mär 08 18:19:46 pureos kernel: blk_drop_partitions+0x54/0xa0 Mär 08 18:19:46 pureos kernel: del_gendisk+0x78/0x240 Mär 08 18:19:46 pureos kernel: sd_remove+0x50/0x90 Mär 08 18:19:46 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:19:46 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:19:46 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:19:46 pureos kernel: device_del+0x180/0x39c Mär 08 18:19:46 pureos kernel: __scsi_remove_device+0x100/0x130 Mär 08 18:19:46 pureos kernel: scsi_forget_host+0x80/0xc0 Mär 08 18:19:46 pureos kernel: scsi_remove_host+0x7c/0x130 Mär 08 18:19:46 pureos kernel: usb_stor_disconnect+0x54/0x100 [usb_storage] Mär 08 18:19:46 pureos kernel: usb_unbind_interface+0x84/0x29c [usbcore] Mär 08 18:19:46 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:19:46 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:19:46 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:19:46 pureos kernel: device_del+0x180/0x39c Mär 08 18:19:46 pureos kernel: usb_disable_device+0x104/0x250 [usbcore] Mär 08 18:19:46 pureos kernel: usb_disconnect+0x114/0x300 [usbcore] Mär 08 18:19:46 pureos kernel: usb_disconnect+0xbc/0x300 [usbcore] Mär 08 18:19:46 pureos kernel: hub_event+0xb90/0x18f0 [usbcore] Mär 08 18:19:46 pureos kernel: process_one_work+0x208/0x4bc Mär 08 18:19:46 pureos kernel: worker_thread+0x148/0x46c Mär 08 18:19:46 pureos kernel: kthread+0x118/0x120 Mär 08 18:19:46 pureos kernel: ret_from_fork+0x10/0x20 Mär 08 18:21:47 pureos kernel: INFO: task kworker/0:2:5044 blocked for more than 845 seconds. Mär 08 18:21:47 pureos kernel: Tainted: G WC 5.17.0-rc7-librem5-00006-g80df5edbe9cc #50 Mär 08 18:21:47 pureos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mär 08 18:21:47 pureos kernel: task:kworker/0:2 state:D stack: 0 pid: 5044 ppid: 2 flags:0x00000008 Mär 08 18:21:47 pureos kernel: Workqueue: usb_hub_wq hub_event [usbcore] Mär 08 18:21:47 pureos kernel: Call trace: Mär 08 18:21:47 pureos kernel: __switch_to+0xf8/0x150 Mär 08 18:21:47 pureos kernel: __schedule+0x28c/0x72c Mär 08 18:21:47 pureos kernel: schedule+0x60/0x100 Mär 08 18:21:47 pureos kernel: __bio_queue_enter+0xbc/0x18c Mär 08 18:21:47 pureos kernel: blk_mq_submit_bio+0x364/0x65c Mär 08 18:21:47 pureos kernel: __submit_bio+0xac/0xc0 Mär 08 18:21:47 pureos kernel: submit_bio_noacct+0x1ec/0x240 Mär 08 18:21:47 pureos kernel: submit_bio+0x64/0x180 Mär 08 18:21:47 pureos kernel: submit_bh_wbc+0x158/0x1d0 Mär 08 18:21:47 pureos kernel: __block_write_full_page+0x238/0x550 Mär 08 18:21:47 pureos kernel: block_write_full_page+0x118/0x134 Mär 08 18:21:47 pureos kernel: blkdev_writepage+0x28/0x3c Mär 08 18:21:47 pureos kernel: __writepage+0x2c/0xc0 Mär 08 18:21:47 pureos kernel: write_cache_pages+0x188/0x3e0 Mär 08 18:21:47 pureos kernel: generic_writepages+0x68/0xb0 Mär 08 18:21:47 pureos kernel: blkdev_writepages+0x1c/0x2c Mär 08 18:21:47 pureos kernel: do_writepages+0x94/0x1c0 Mär 08 18:21:47 pureos kernel: filemap_fdatawrite_wbc+0x8c/0xc0 Mär 08 18:21:47 pureos kernel: filemap_flush+0x54/0x80 Mär 08 18:21:47 pureos kernel: sync_blockdev_nowait+0x28/0x40 Mär 08 18:21:47 pureos kernel: sync_filesystem+0x74/0xc0 Mär 08 18:21:47 pureos kernel: fsync_bdev+0x6c/0x90 Mär 08 18:21:47 pureos kernel: delete_partition+0x20/0x84 Mär 08 18:21:47 pureos kernel: blk_drop_partitions+0x54/0xa0 Mär 08 18:21:47 pureos kernel: del_gendisk+0x78/0x240 Mär 08 18:21:47 pureos kernel: sd_remove+0x50/0x90 Mär 08 18:21:47 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:21:47 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:21:47 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:21:47 pureos kernel: device_del+0x180/0x39c Mär 08 18:21:47 pureos kernel: __scsi_remove_device+0x100/0x130 Mär 08 18:21:47 pureos kernel: scsi_forget_host+0x80/0xc0 Mär 08 18:21:47 pureos kernel: scsi_remove_host+0x7c/0x130 Mär 08 18:21:47 pureos kernel: usb_stor_disconnect+0x54/0x100 [usb_storage] Mär 08 18:21:47 pureos kernel: usb_unbind_interface+0x84/0x29c [usbcore] Mär 08 18:21:47 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:21:47 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:21:47 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:21:47 pureos kernel: device_del+0x180/0x39c Mär 08 18:21:47 pureos kernel: usb_disable_device+0x104/0x250 [usbcore] Mär 08 18:21:47 pureos kernel: usb_disconnect+0x114/0x300 [usbcore] Mär 08 18:21:47 pureos kernel: usb_disconnect+0xbc/0x300 [usbcore] Mär 08 18:21:47 pureos kernel: hub_event+0xb90/0x18f0 [usbcore] Mär 08 18:21:47 pureos kernel: process_one_work+0x208/0x4bc Mär 08 18:21:47 pureos kernel: worker_thread+0x148/0x46c Mär 08 18:21:47 pureos kernel: kthread+0x118/0x120 Mär 08 18:21:47 pureos kernel: ret_from_fork+0x10/0x20 Mär 08 18:23:48 pureos kernel: INFO: task kworker/0:2:5044 blocked for more than 966 seconds. Mär 08 18:23:48 pureos kernel: Tainted: G WC 5.17.0-rc7-librem5-00006-g80df5edbe9cc #50 Mär 08 18:23:48 pureos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mär 08 18:23:48 pureos kernel: task:kworker/0:2 state:D stack: 0 pid: 5044 ppid: 2 flags:0x00000008 Mär 08 18:23:48 pureos kernel: Workqueue: usb_hub_wq hub_event [usbcore] Mär 08 18:23:48 pureos kernel: Call trace: Mär 08 18:23:48 pureos kernel: __switch_to+0xf8/0x150 Mär 08 18:23:48 pureos kernel: __schedule+0x28c/0x72c Mär 08 18:23:48 pureos kernel: schedule+0x60/0x100 Mär 08 18:23:48 pureos kernel: __bio_queue_enter+0xbc/0x18c Mär 08 18:23:48 pureos kernel: blk_mq_submit_bio+0x364/0x65c Mär 08 18:23:48 pureos kernel: __submit_bio+0xac/0xc0 Mär 08 18:23:48 pureos kernel: submit_bio_noacct+0x1ec/0x240 Mär 08 18:23:48 pureos kernel: submit_bio+0x64/0x180 Mär 08 18:23:48 pureos kernel: submit_bh_wbc+0x158/0x1d0 Mär 08 18:23:48 pureos kernel: __block_write_full_page+0x238/0x550 Mär 08 18:23:48 pureos kernel: block_write_full_page+0x118/0x134 Mär 08 18:23:48 pureos kernel: blkdev_writepage+0x28/0x3c Mär 08 18:23:48 pureos kernel: __writepage+0x2c/0xc0 Mär 08 18:23:48 pureos kernel: write_cache_pages+0x188/0x3e0 Mär 08 18:23:48 pureos kernel: generic_writepages+0x68/0xb0 Mär 08 18:23:48 pureos kernel: blkdev_writepages+0x1c/0x2c Mär 08 18:23:48 pureos kernel: do_writepages+0x94/0x1c0 Mär 08 18:23:48 pureos kernel: filemap_fdatawrite_wbc+0x8c/0xc0 Mär 08 18:23:48 pureos kernel: filemap_flush+0x54/0x80 Mär 08 18:23:48 pureos kernel: sync_blockdev_nowait+0x28/0x40 Mär 08 18:23:48 pureos kernel: sync_filesystem+0x74/0xc0 Mär 08 18:23:48 pureos kernel: fsync_bdev+0x6c/0x90 Mär 08 18:23:48 pureos kernel: delete_partition+0x20/0x84 Mär 08 18:23:48 pureos kernel: blk_drop_partitions+0x54/0xa0 Mär 08 18:23:48 pureos kernel: del_gendisk+0x78/0x240 Mär 08 18:23:48 pureos kernel: sd_remove+0x50/0x90 Mär 08 18:23:48 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:23:48 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:23:48 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:23:48 pureos kernel: device_del+0x180/0x39c Mär 08 18:23:48 pureos kernel: __scsi_remove_device+0x100/0x130 Mär 08 18:23:48 pureos kernel: scsi_forget_host+0x80/0xc0 Mär 08 18:23:48 pureos kernel: scsi_remove_host+0x7c/0x130 Mär 08 18:23:48 pureos kernel: usb_stor_disconnect+0x54/0x100 [usb_storage] Mär 08 18:23:48 pureos kernel: usb_unbind_interface+0x84/0x29c [usbcore] Mär 08 18:23:48 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:23:48 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:23:48 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:23:48 pureos kernel: device_del+0x180/0x39c Mär 08 18:23:48 pureos kernel: usb_disable_device+0x104/0x250 [usbcore] Mär 08 18:23:48 pureos kernel: usb_disconnect+0x114/0x300 [usbcore] Mär 08 18:23:48 pureos kernel: usb_disconnect+0xbc/0x300 [usbcore] Mär 08 18:23:48 pureos kernel: hub_event+0xb90/0x18f0 [usbcore] Mär 08 18:23:48 pureos kernel: process_one_work+0x208/0x4bc Mär 08 18:23:48 pureos kernel: worker_thread+0x148/0x46c Mär 08 18:23:48 pureos kernel: kthread+0x118/0x120 Mär 08 18:23:48 pureos kernel: ret_from_fork+0x10/0x20 Mär 08 18:25:49 pureos kernel: INFO: task kworker/0:2:5044 blocked for more than 1087 seconds. Mär 08 18:25:49 pureos kernel: Tainted: G WC 5.17.0-rc7-librem5-00006-g80df5edbe9cc #50 Mär 08 18:25:49 pureos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mär 08 18:25:49 pureos kernel: task:kworker/0:2 state:D stack: 0 pid: 5044 ppid: 2 flags:0x00000008 Mär 08 18:25:49 pureos kernel: Workqueue: usb_hub_wq hub_event [usbcore] Mär 08 18:25:49 pureos kernel: Call trace: Mär 08 18:25:49 pureos kernel: __switch_to+0xf8/0x150 Mär 08 18:25:49 pureos kernel: __schedule+0x28c/0x72c Mär 08 18:25:49 pureos kernel: schedule+0x60/0x100 Mär 08 18:25:49 pureos kernel: __bio_queue_enter+0xbc/0x18c Mär 08 18:25:49 pureos kernel: blk_mq_submit_bio+0x364/0x65c Mär 08 18:25:49 pureos kernel: __submit_bio+0xac/0xc0 Mär 08 18:25:49 pureos kernel: submit_bio_noacct+0x1ec/0x240 Mär 08 18:25:49 pureos kernel: submit_bio+0x64/0x180 Mär 08 18:25:49 pureos kernel: submit_bh_wbc+0x158/0x1d0 Mär 08 18:25:49 pureos kernel: __block_write_full_page+0x238/0x550 Mär 08 18:25:49 pureos kernel: block_write_full_page+0x118/0x134 Mär 08 18:25:49 pureos kernel: blkdev_writepage+0x28/0x3c Mär 08 18:25:49 pureos kernel: __writepage+0x2c/0xc0 Mär 08 18:25:49 pureos kernel: write_cache_pages+0x188/0x3e0 Mär 08 18:25:49 pureos kernel: generic_writepages+0x68/0xb0 Mär 08 18:25:49 pureos kernel: blkdev_writepages+0x1c/0x2c Mär 08 18:25:49 pureos kernel: do_writepages+0x94/0x1c0 Mär 08 18:25:49 pureos kernel: filemap_fdatawrite_wbc+0x8c/0xc0 Mär 08 18:25:49 pureos kernel: filemap_flush+0x54/0x80 Mär 08 18:25:49 pureos kernel: sync_blockdev_nowait+0x28/0x40 Mär 08 18:25:49 pureos kernel: sync_filesystem+0x74/0xc0 Mär 08 18:25:49 pureos kernel: fsync_bdev+0x6c/0x90 Mär 08 18:25:49 pureos kernel: delete_partition+0x20/0x84 Mär 08 18:25:49 pureos kernel: blk_drop_partitions+0x54/0xa0 Mär 08 18:25:49 pureos kernel: del_gendisk+0x78/0x240 Mär 08 18:25:49 pureos kernel: sd_remove+0x50/0x90 Mär 08 18:25:49 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:25:49 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:25:49 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:25:49 pureos kernel: device_del+0x180/0x39c Mär 08 18:25:49 pureos kernel: __scsi_remove_device+0x100/0x130 Mär 08 18:25:49 pureos kernel: scsi_forget_host+0x80/0xc0 Mär 08 18:25:49 pureos kernel: scsi_remove_host+0x7c/0x130 Mär 08 18:25:49 pureos kernel: usb_stor_disconnect+0x54/0x100 [usb_storage] Mär 08 18:25:49 pureos kernel: usb_unbind_interface+0x84/0x29c [usbcore] Mär 08 18:25:49 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:25:49 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:25:49 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:25:49 pureos kernel: device_del+0x180/0x39c Mär 08 18:25:49 pureos kernel: usb_disable_device+0x104/0x250 [usbcore] Mär 08 18:25:49 pureos kernel: usb_disconnect+0x114/0x300 [usbcore] Mär 08 18:25:49 pureos kernel: usb_disconnect+0xbc/0x300 [usbcore] Mär 08 18:25:49 pureos kernel: hub_event+0xb90/0x18f0 [usbcore] Mär 08 18:25:49 pureos kernel: process_one_work+0x208/0x4bc Mär 08 18:25:49 pureos kernel: worker_thread+0x148/0x46c Mär 08 18:25:49 pureos kernel: kthread+0x118/0x120 Mär 08 18:25:49 pureos kernel: ret_from_fork+0x10/0x20 Mär 08 18:27:49 pureos kernel: INFO: task kworker/0:2:5044 blocked for more than 1208 seconds. Mär 08 18:27:49 pureos kernel: Tainted: G WC 5.17.0-rc7-librem5-00006-g80df5edbe9cc #50 Mär 08 18:27:49 pureos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mär 08 18:27:49 pureos kernel: task:kworker/0:2 state:D stack: 0 pid: 5044 ppid: 2 flags:0x00000008 Mär 08 18:27:49 pureos kernel: Workqueue: usb_hub_wq hub_event [usbcore] Mär 08 18:27:49 pureos kernel: Call trace: Mär 08 18:27:49 pureos kernel: __switch_to+0xf8/0x150 Mär 08 18:27:49 pureos kernel: __schedule+0x28c/0x72c Mär 08 18:27:49 pureos kernel: schedule+0x60/0x100 Mär 08 18:27:49 pureos kernel: __bio_queue_enter+0xbc/0x18c Mär 08 18:27:49 pureos kernel: blk_mq_submit_bio+0x364/0x65c Mär 08 18:27:49 pureos kernel: __submit_bio+0xac/0xc0 Mär 08 18:27:49 pureos kernel: submit_bio_noacct+0x1ec/0x240 Mär 08 18:27:49 pureos kernel: submit_bio+0x64/0x180 Mär 08 18:27:49 pureos kernel: submit_bh_wbc+0x158/0x1d0 Mär 08 18:27:49 pureos kernel: __block_write_full_page+0x238/0x550 Mär 08 18:27:49 pureos kernel: block_write_full_page+0x118/0x134 Mär 08 18:27:49 pureos kernel: blkdev_writepage+0x28/0x3c Mär 08 18:27:49 pureos kernel: __writepage+0x2c/0xc0 Mär 08 18:27:49 pureos kernel: write_cache_pages+0x188/0x3e0 Mär 08 18:27:49 pureos kernel: generic_writepages+0x68/0xb0 Mär 08 18:27:49 pureos kernel: blkdev_writepages+0x1c/0x2c Mär 08 18:27:49 pureos kernel: do_writepages+0x94/0x1c0 Mär 08 18:27:49 pureos kernel: filemap_fdatawrite_wbc+0x8c/0xc0 Mär 08 18:27:49 pureos kernel: filemap_flush+0x54/0x80 Mär 08 18:27:49 pureos kernel: sync_blockdev_nowait+0x28/0x40 Mär 08 18:27:49 pureos kernel: sync_filesystem+0x74/0xc0 Mär 08 18:27:49 pureos kernel: fsync_bdev+0x6c/0x90 Mär 08 18:27:49 pureos kernel: delete_partition+0x20/0x84 Mär 08 18:27:49 pureos kernel: blk_drop_partitions+0x54/0xa0 Mär 08 18:27:49 pureos kernel: del_gendisk+0x78/0x240 Mär 08 18:27:49 pureos kernel: sd_remove+0x50/0x90 Mär 08 18:27:49 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:27:49 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:27:49 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:27:49 pureos kernel: device_del+0x180/0x39c Mär 08 18:27:49 pureos kernel: __scsi_remove_device+0x100/0x130 Mär 08 18:27:49 pureos kernel: scsi_forget_host+0x80/0xc0 Mär 08 18:27:49 pureos kernel: scsi_remove_host+0x7c/0x130 Mär 08 18:27:49 pureos kernel: usb_stor_disconnect+0x54/0x100 [usb_storage] Mär 08 18:27:49 pureos kernel: usb_unbind_interface+0x84/0x29c [usbcore] Mär 08 18:27:49 pureos kernel: __device_release_driver+0x244/0x24c Mär 08 18:27:49 pureos kernel: device_release_driver+0x38/0x50 Mär 08 18:27:49 pureos kernel: bus_remove_device+0xdc/0x170 Mär 08 18:27:49 pureos kernel: device_del+0x180/0x39c Mär 08 18:27:49 pureos kernel: usb_disable_device+0x104/0x250 [usbcore] Mär 08 18:27:49 pureos kernel: usb_disconnect+0x114/0x300 [usbcore] Mär 08 18:27:49 pureos kernel: usb_disconnect+0xbc/0x300 [usbcore] Mär 08 18:27:49 pureos kernel: hub_event+0xb90/0x18f0 [usbcore] Mär 08 18:27:49 pureos kernel: process_one_work+0x208/0x4bc Mär 08 18:27:49 pureos kernel: worker_thread+0x148/0x46c Mär 08 18:27:49 pureos kernel: kthread+0x118/0x120 Mär 08 18:27:49 pureos kernel: ret_from_fork+0x10/0x20 Mär 08 18:29:28 pureos kernel: xhci-hcd xhci-hcd.5.auto: WARN: HC couldn't access mem fast enough for slot 3 ep 6 Mär 08 18:29:28 pureos kernel: r8152 4-1.4:1.0 enx00e04c684a8a: intr status -63 Mär 08 18:29:28 pureos kernel: xhci-hcd xhci-hcd.5.auto: remove, state 1 Mär 08 18:29:28 pureos kernel: usb usb4: USB disconnect, device number 1 Mär 08 18:29:28 pureos kernel: usb 4-1: USB disconnect, device number 2 Mär 08 18:29:28 pureos kernel: usb 4-1.4: USB disconnect, device number 3 Mär 08 18:29:28 pureos kernel: tps6598x 0-003f: The interrupt is masked , how did it fire ?? 380100a Mär 08 18:29:28 pureos kernel: bq25890-charger 3-006a: Upstream supply changed: 0. Mär 08 18:29:28 pureos kernel: bq25890-charger 3-006a: Disabling OTG_EN pin Mär 08 18:29:28 pureos kernel: r8152 4-1.4:1.0 enx00e04c684a8a: Stop submitting intr, status -108 Mär 08 18:29:28 pureos kernel: bq25890-charger 3-006a: Upstream supply changed: 0. Mär 08 18:29:28 pureos kernel: bq25890-charger 3-006a: Disabling OTG_EN pin Mär 08 18:29:28 pureos kernel: usb 3-1: USB disconnect, device number 2 Mär 08 18:29:28 pureos kernel: xhci-hcd xhci-hcd.5.auto: USB bus 4 deregistered Mär 08 18:29:28 pureos kernel: xhci-hcd xhci-hcd.5.auto: remove, state 4 Mär 08 18:29:28 pureos kernel: usb usb3: USB disconnect, device number 1 Mär 08 18:29:28 pureos kernel: xhci-hcd xhci-hcd.5.auto: USB bus 3 deregistered Mär 08 18:30:03 pureos kernel: qmi_wwan 1-1.2:1.4: Error autopm - -16 Mär 08 18:34:43 pureos kernel: rfkill: input handler enabled
On 9.3.2022 9.56, Martin Kepplinger wrote: > Am Dienstag, dem 08.03.2022 um 17:17 +0100 schrieb Martin Kepplinger: >> Am Montag, dem 07.03.2022 um 10:49 +0200 schrieb Mathias Nyman: >>> On 4.3.2022 16.17, Greg KH wrote: >>>> On Fri, Mar 04, 2022 at 12:30:57PM +0100, Martin Kepplinger >>>> wrote: >>>>> On the Librem 5 imx8mq system we've seen the stop endpoint >>>>> command >>>>> time out regularly which results in the hub dying. >>>>> >>>>> While on the one hand we see "Port resume timed out, port 1-1: >>>>> 0xfe3" >>>>> before this and on the other hand driver-comments suggest that >>>>> the driver >>>>> might be able to recover instead of dying here, Sarah seemed to >>>>> have a >>>>> workaround for this particulator problem in mind already: >>>>> >>>>> Make it a module parameter. So while it might not be the root >>>>> cause for >>>>> the problem, do this to give users a workaround. >>>> >>>> This is not the 1990's, sorry, please do not add new module >>>> parameters. >>>> They modify code, when you want to modify an individual device. >>>> >>> >>> Agree, I think we really need to find the rootcause here. >>> >>> There's a known problem with this stop endpoint timeout timer. >>> >>> For all other commands we start the timer when the controller >>> starts >>> processing the >>> command, but the stop endpoint timer is started immediately when >>> command is queued. >>> So it might timeout if some other commend before it failed. >>> >>> I have a patchseries for this. It's still work in progress but >>> should >>> be testable. >>> Pushed to a branch named stop_endpoint_fixes >>> >>> git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git >>> stop_endpoint_fixes >>> https://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git/log/?h=stop_endpoint_fixes >>> >>> Can you try it out and see if it helps? >>> >> >> thanks a lot Mathias, I'm running these now. The timeout has not been >> easy to reproduce (or I'm just lazy) but in a few days I should be >> able >> to tell whether that helps. >> >> So this thread has been about >> >> [14145.960512] xhci-hcd xhci-hcd.4.auto: Port resume timed out, port >> 1- >> 1: 0xfe3 >> [14156.308511] xhci-hcd xhci-hcd.4.auto: xHCI host not responding to >> stop endpoint command. >> >> that I previously tried to work around by increasing >> XHCI_MAX_REXIT_TIMEOUT_MS and XHCI_STOP_EP_CMD_TIMEOUT. >> >> >> These patches can't help with the following, right? >> readl_poll_timeout_atomic() with a fixed timeout is called in this >> case: >> >> xhci-hcd xhci-hcd.4.auto: Abort failed to stop command ring: -110 >> >> I see that too from time to time. It results in the HC dying as well. >> >> thanks, >> martin >> > > hi Mathias, > > I already saw "Port resume timed out" and the HC dying running your > patches. I append the logs. > > So for now I saw more success with increasing > XHCI_MAX_REXIT_TIMEOUT_MS. > XHCI_MAX_REXIT_TIMEOUT_MS is only 20ms, that we can probably change. Is 40ms enough? "Port resume timed out, port 1-1: 0xfe3" means port link state is still in resume even if we asked link to go to U0 20ms ago. Maybe this hw combination just resumes slowly. Thanks Mathias
Am Mittwoch, dem 09.03.2022 um 11:29 +0200 schrieb Mathias Nyman: > On 9.3.2022 9.56, Martin Kepplinger wrote: > > Am Dienstag, dem 08.03.2022 um 17:17 +0100 schrieb Martin > > Kepplinger: > > > Am Montag, dem 07.03.2022 um 10:49 +0200 schrieb Mathias Nyman: > > > > On 4.3.2022 16.17, Greg KH wrote: > > > > > On Fri, Mar 04, 2022 at 12:30:57PM +0100, Martin Kepplinger > > > > > wrote: > > > > > > On the Librem 5 imx8mq system we've seen the stop endpoint > > > > > > command > > > > > > time out regularly which results in the hub dying. > > > > > > > > > > > > While on the one hand we see "Port resume timed out, port > > > > > > 1-1: > > > > > > 0xfe3" > > > > > > before this and on the other hand driver-comments suggest > > > > > > that > > > > > > the driver > > > > > > might be able to recover instead of dying here, Sarah > > > > > > seemed to > > > > > > have a > > > > > > workaround for this particulator problem in mind already: > > > > > > > > > > > > Make it a module parameter. So while it might not be the > > > > > > root > > > > > > cause for > > > > > > the problem, do this to give users a workaround. > > > > > > > > > > This is not the 1990's, sorry, please do not add new module > > > > > parameters. > > > > > They modify code, when you want to modify an individual > > > > > device. > > > > > > > > > > > > > Agree, I think we really need to find the rootcause here. > > > > > > > > There's a known problem with this stop endpoint timeout timer. > > > > > > > > For all other commands we start the timer when the controller > > > > starts > > > > processing the > > > > command, but the stop endpoint timer is started immediately > > > > when > > > > command is queued. > > > > So it might timeout if some other commend before it failed. > > > > > > > > I have a patchseries for this. It's still work in progress but > > > > should > > > > be testable. > > > > Pushed to a branch named stop_endpoint_fixes > > > > > > > > git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git > > > > stop_endpoint_fixes > > > > https://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git/log/?h=stop_endpoint_fixes > > > > > > > > Can you try it out and see if it helps? > > > > > > > > > > thanks a lot Mathias, I'm running these now. The timeout has not > > > been > > > easy to reproduce (or I'm just lazy) but in a few days I should > > > be > > > able > > > to tell whether that helps. > > > > > > So this thread has been about > > > > > > [14145.960512] xhci-hcd xhci-hcd.4.auto: Port resume timed out, > > > port > > > 1- > > > 1: 0xfe3 > > > [14156.308511] xhci-hcd xhci-hcd.4.auto: xHCI host not responding > > > to > > > stop endpoint command. > > > > > > that I previously tried to work around by increasing > > > XHCI_MAX_REXIT_TIMEOUT_MS and XHCI_STOP_EP_CMD_TIMEOUT. > > > > > > > > > These patches can't help with the following, right? > > > readl_poll_timeout_atomic() with a fixed timeout is called in > > > this > > > case: > > > > > > xhci-hcd xhci-hcd.4.auto: Abort failed to stop command ring: -110 > > > > > > I see that too from time to time. It results in the HC dying as > > > well. > > > > > > thanks, > > > martin > > > > > > > hi Mathias, > > > > I already saw "Port resume timed out" and the HC dying running your > > patches. I append the logs. > > > > So for now I saw more success with increasing > > XHCI_MAX_REXIT_TIMEOUT_MS. > > > > XHCI_MAX_REXIT_TIMEOUT_MS is only 20ms, that we can probably change. > > Is 40ms enough? > > "Port resume timed out, port 1-1: 0xfe3" means port link state is > still in > resume even if we asked link to go to U0 20ms ago. > > Maybe this hw combination just resumes slowly. > > Thanks > Mathias hi Mathias, sorry for not responding until now. I'm currently testing whether QUIRK_HUB_SLOW_RESET will work too to avoid the HC dying due to the command timeouts: { USB_DEVICE(0x0424, 0x2640), .driver_info = USB_QUIRK_HUB_SLOW_RESET }, But these timeouts usually happen after a port is reset (not just runtime-resumed without resetting, which happens very often). And exactly *that* is what I now want to try to avoid now. I *never* want ports on the Hub in question to be reset. (it causes enough other hick-ups even *if* the reset would be successful and not result in the HC die, so all resets need to go away). Normally, on successful runtime resume (without any reset), the hub port status is: Mär 15 08:24:44.748852 pureos kernel: usb 1-1-port2: status 0503 change 0004 Mär 15 08:24:44.747863 pureos kernel: usb 1-1-port1: status 0507 change 0000 But when the following happens: Mär 15 08:24:52.660348 pureos kernel: usb 1-1-port2: status 0101 change 0005 Mär 15 08:24:52.656107 pureos kernel: usb 1-1-port1: status 0507 change 0000 then hub_activate() sets "reset_resume" (persist is enabled) and it's too late :) Do you have an idea about what could be the cause for "status 0101" here? (it basically means ENABLE and HIGH_SPEED is not set, but why?) I know this is a bit of a different area now, but it's all about avoiding problems on that hub at runtime. thanks, martin
On 15.3.2022 10.43, Martin Kepplinger wrote: > Am Mittwoch, dem 09.03.2022 um 11:29 +0200 schrieb Mathias Nyman: >> On 9.3.2022 9.56, Martin Kepplinger wrote: >>> Am Dienstag, dem 08.03.2022 um 17:17 +0100 schrieb Martin >>> Kepplinger: >>>> Am Montag, dem 07.03.2022 um 10:49 +0200 schrieb Mathias Nyman: >>>>> On 4.3.2022 16.17, Greg KH wrote: >>>>>> On Fri, Mar 04, 2022 at 12:30:57PM +0100, Martin Kepplinger >>>>>> wrote: >>>>>>> On the Librem 5 imx8mq system we've seen the stop endpoint >>>>>>> command >>>>>>> time out regularly which results in the hub dying. >>>>>>> >>>>>>> While on the one hand we see "Port resume timed out, port >>>>>>> 1-1: >>>>>>> 0xfe3" >>>>>>> before this and on the other hand driver-comments suggest >>>>>>> that >>>>>>> the driver >>>>>>> might be able to recover instead of dying here, Sarah >>>>>>> seemed to >>>>>>> have a >>>>>>> workaround for this particulator problem in mind already: >>>>>>> >>>>>>> Make it a module parameter. So while it might not be the >>>>>>> root >>>>>>> cause for >>>>>>> the problem, do this to give users a workaround. >>>>>> >>>>>> This is not the 1990's, sorry, please do not add new module >>>>>> parameters. >>>>>> They modify code, when you want to modify an individual >>>>>> device. >>>>>> >>>>> >>>>> Agree, I think we really need to find the rootcause here. >>>>> >>>>> There's a known problem with this stop endpoint timeout timer. >>>>> >>>>> For all other commands we start the timer when the controller >>>>> starts >>>>> processing the >>>>> command, but the stop endpoint timer is started immediately >>>>> when >>>>> command is queued. >>>>> So it might timeout if some other commend before it failed. >>>>> >>>>> I have a patchseries for this. It's still work in progress but >>>>> should >>>>> be testable. >>>>> Pushed to a branch named stop_endpoint_fixes >>>>> >>>>> git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git >>>>> stop_endpoint_fixes >>>>> https://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git/log/?h=stop_endpoint_fixes >>>>> >>>>> Can you try it out and see if it helps? >>>>> >>>> >>>> thanks a lot Mathias, I'm running these now. The timeout has not >>>> been >>>> easy to reproduce (or I'm just lazy) but in a few days I should >>>> be >>>> able >>>> to tell whether that helps. >>>> >>>> So this thread has been about >>>> >>>> [14145.960512] xhci-hcd xhci-hcd.4.auto: Port resume timed out, >>>> port >>>> 1- >>>> 1: 0xfe3 >>>> [14156.308511] xhci-hcd xhci-hcd.4.auto: xHCI host not responding >>>> to >>>> stop endpoint command. >>>> >>>> that I previously tried to work around by increasing >>>> XHCI_MAX_REXIT_TIMEOUT_MS and XHCI_STOP_EP_CMD_TIMEOUT. >>>> >>>> >>>> These patches can't help with the following, right? >>>> readl_poll_timeout_atomic() with a fixed timeout is called in >>>> this >>>> case: >>>> >>>> xhci-hcd xhci-hcd.4.auto: Abort failed to stop command ring: -110 >>>> >>>> I see that too from time to time. It results in the HC dying as >>>> well. >>>> >>>> thanks, >>>> martin >>>> >>> >>> hi Mathias, >>> >>> I already saw "Port resume timed out" and the HC dying running your >>> patches. I append the logs. >>> >>> So for now I saw more success with increasing >>> XHCI_MAX_REXIT_TIMEOUT_MS. >>> >> >> XHCI_MAX_REXIT_TIMEOUT_MS is only 20ms, that we can probably change. >> >> Is 40ms enough? >> >> "Port resume timed out, port 1-1: 0xfe3" means port link state is >> still in >> resume even if we asked link to go to U0 20ms ago. >> >> Maybe this hw combination just resumes slowly. >> >> Thanks >> Mathias > > > hi Mathias, sorry for not responding until now. I'm currently testing > whether QUIRK_HUB_SLOW_RESET will work too to avoid the HC dying due to > the command timeouts: > > { USB_DEVICE(0x0424, 0x2640), .driver_info = USB_QUIRK_HUB_SLOW_RESET > }, > > But these timeouts usually happen after a port is reset (not just > runtime-resumed without resetting, which happens very often). > > And exactly *that* is what I now want to try to avoid now. I *never* > want ports on the Hub in question to be reset. (it causes enough other > hick-ups even *if* the reset would be successful and not result in the > HC die, so all resets need to go away). > > Normally, on successful runtime resume (without any reset), the hub > port status is: > > Mär 15 08:24:44.748852 pureos kernel: usb 1-1-port2: status 0503 change > 0004 > Mär 15 08:24:44.747863 pureos kernel: usb 1-1-port1: status 0507 change > 0000 > > But when the following happens: > > Mär 15 08:24:52.660348 pureos kernel: usb 1-1-port2: status 0101 change > 0005 > Mär 15 08:24:52.656107 pureos kernel: usb 1-1-port1: status 0507 change > 0000 > > then hub_activate() sets "reset_resume" (persist is enabled) and it's > too late :) > > Do you have an idea about what could be the cause for "status 0101" > here? (it basically means ENABLE and HIGH_SPEED is not set, but why?) > > I know this is a bit of a different area now, but it's all about > avoiding problems on that hub at runtime. > > thanks, > > martin Not sure about this. The failing case has change 0005, meaning the connect status change bit is set. Also HIGH_SPEED bit in status is only relevant when ENABLE bit is set. If there was a connect change detected then I guess port reset is needed to get the USB 2 port back to enable state. -Mathias
diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c index d0b6806275e0..e631d408e6b2 100644 --- a/drivers/usb/host/xhci-ring.c +++ b/drivers/usb/host/xhci-ring.c @@ -1133,7 +1133,7 @@ static void xhci_handle_cmd_stop_ep(struct xhci_hcd *xhci, int slot_id, xhci_stop_watchdog_timer_in_irq(xhci, ep); mod_timer(&ep->stop_cmd_timer, - jiffies + XHCI_STOP_EP_CMD_TIMEOUT * HZ); + jiffies + xhci->stop_ep_cmd_timeout * HZ); xhci_queue_stop_endpoint(xhci, command, slot_id, ep_index, 0); xhci_ring_cmd_db(xhci); diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c index a1c781f70d02..37fd05e75dcf 100644 --- a/drivers/usb/host/xhci.c +++ b/drivers/usb/host/xhci.c @@ -37,6 +37,11 @@ static unsigned long long quirks; module_param(quirks, ullong, S_IRUGO); MODULE_PARM_DESC(quirks, "Bit flags for quirks to be enabled as default"); +static unsigned int stop_ep_cmd_timeout = 5; +module_param(stop_ep_cmd_timeout, uint, S_IRUGO | S_IWUSR); +MODULE_PARM_DESC(stop_ep_cmd_timeout, + "Stop endpoint command timeout (secs) for URB cancel watchdog. default=5"); + static bool td_on_ring(struct xhci_td *td, struct xhci_ring *ring) { struct xhci_segment *seg = ring->first_seg; @@ -1849,7 +1854,7 @@ static int xhci_urb_dequeue(struct usb_hcd *hcd, struct urb *urb, int status) } ep->ep_state |= EP_STOP_CMD_PENDING; ep->stop_cmd_timer.expires = jiffies + - XHCI_STOP_EP_CMD_TIMEOUT * HZ; + xhci->stop_ep_cmd_timeout * HZ; add_timer(&ep->stop_cmd_timer); xhci_queue_stop_endpoint(xhci, command, urb->dev->slot_id, ep_index, 0); @@ -5288,6 +5293,7 @@ int xhci_gen_setup(struct usb_hcd *hcd, xhci_get_quirks_t get_quirks) xhci->hcc_params2 = readl(&xhci->cap_regs->hcc_params2); xhci->quirks |= quirks; + xhci->stop_ep_cmd_timeout = stop_ep_cmd_timeout; get_quirks(dev, xhci); diff --git a/drivers/usb/host/xhci.h b/drivers/usb/host/xhci.h index 8a0026ee9524..80c9ced4a276 100644 --- a/drivers/usb/host/xhci.h +++ b/drivers/usb/host/xhci.h @@ -1674,8 +1674,6 @@ struct urb_priv { #define ERST_NUM_SEGS 1 /* Poll every 60 seconds */ #define POLL_TIMEOUT 60 -/* Stop endpoint command timeout (secs) for URB cancellation watchdog timer */ -#define XHCI_STOP_EP_CMD_TIMEOUT 5 /* XXX: Make these module parameters */ struct s3_save { @@ -1899,6 +1897,7 @@ struct xhci_hcd { #define XHCI_BROKEN_D3COLD BIT_ULL(41) #define XHCI_EP_CTX_BROKEN_DCS BIT_ULL(42) + unsigned int stop_ep_cmd_timeout; unsigned int num_active_eps; unsigned int limit_active_eps; struct xhci_port *hw_ports;
On the Librem 5 imx8mq system we've seen the stop endpoint command time out regularly which results in the hub dying. While on the one hand we see "Port resume timed out, port 1-1: 0xfe3" before this and on the other hand driver-comments suggest that the driver might be able to recover instead of dying here, Sarah seemed to have a workaround for this particulator problem in mind already: Make it a module parameter. So while it might not be the root cause for the problem, do this to give users a workaround. Signed-off-by: Martin Kepplinger <martin.kepplinger@puri.sm> --- drivers/usb/host/xhci-ring.c | 2 +- drivers/usb/host/xhci.c | 8 +++++++- drivers/usb/host/xhci.h | 3 +-- 3 files changed, 9 insertions(+), 4 deletions(-)