raspberrypi / linux

Kernel source tree for Raspberry Pi-provided kernel builds. Issues unrelated to the linux kernel should be posted on the community forum at https://forums.raspberrypi.com/
Other
11.01k stars 4.95k forks source link

Rpi4 crash when using more than 34 USB serial ports #4008

Open r-schmidt opened 3 years ago

r-schmidt commented 3 years ago

Describe the bug The system prints kernel messages about an unhandled fault when accessing more than 34 serial ports (ttyUSB).

To reproduce

Expected behaviour

Actual behaviour

System Raspberry Pi 4B

$ cat /etc/rpi-issue Raspberry Pi reference 2020-05-27 Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 825107f04027269db77426046f5085475b1ea22f, stage2

$ vcgencmd version Nov 30 2020 22:12:08 Copyright (c) 2012 Broadcom version ab1181cc0cb6df52bfae3b1d3fef0ce7c325166c (clean) (release) (start)

$ uname -a Linux raspberrypi 5.4.79-v7l+ #1373 SMP Mon Nov 23 13:27:40 GMT 2020 armv7l GNU/Linux

Logs On the console is printed the following output:

[ 103.715803] 8<--- cut here --- [ 103.720089] Unhandled fault: asynchronous external abort (0x1211) at 0x00000000 [ 103.728619] pgd = d30b99fe [ 103.732532] [00000000] pgd=17787003, pmd=00000000 [ 103.738634] Internal error: : 1211 [#1] SMP ARM [ 103.744388] Modules linked in: sha256_generic libsha256 cfg80211 rfkill 8021q garp stp llc ftdi_sio usbserial vc4 cec rpivid_mem v3d drm_kms_helper gpu_sched drm bcm2835_codec(C) bcm2835_v4l2(C) bcm2835_isp(C) v4l2_mem2mem bcm2835_mmal_vchiq(C) videobuf2_dma_contig videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common drm_panel_orientation_quirks raspberrypi_hwmon snd_soc_core videodev mc vc_sm_cma(C) snd_compress snd_pcm_dmaengine snd_pcm snd_timer snd syscopyarea sysfillrect sysimgblt fb_sys_fops uio_pdrv_genirq uio ip_tables x_tables ipv6 [ 103.797884] CPU: 0 PID: 2336 Comm: sudo Tainted: G C 5.4.79-v7l+ #1373 [ 103.807232] Hardware name: BCM2711 [ 103.812161] PC is at lockref_put_return+0x50/0x9c [ 103.818379] LR is at dput.part.8+0x58/0x3b8 [ 103.824052] pc : [] lr : [] psr: 60000013 [ 103.831839] sp : d6dbbe50 ip : 00000000 fp : d6dbbe6c [ 103.838602] r10: d71f8c70 r9 : 00000001 r8 : 00080060 [ 103.845375] r7 : 00000001 r6 : 00030003 r5 : 00000000 r4 : 00030003 [ 103.853475] r3 : 00000001 r2 : 00030003 r1 : 00000064 r0 : d91b1fb8 [ 103.861570] Flags: nZCv IRQs on FIQs on Mode SVC_32 ISA ARM Segment user [ 103.870286] Control: 30c5383d Table: 177ea000 DAC: fffffffd [ 103.877630] Process sudo (pid: 2336, stack limit = 0xb7a13c6b) [ 103.885085] Stack: (0xd6dbbe50 to 0xd6dbc000) [ 103.891075] be40: d91b1f68 d91b1fb8 c0de3628 00080040 [ 103.900914] be60: d6dbbea4 d6dbbe70 c04287c0 c06a2f54 00000000 c040e3bc 00000000 d6c58180 [ 103.910762] be80: d71f8c70 080a801d ef32e850 d91b1f68 00000010 d71f8c70 d6dbbeb4 d6dbbea8 [ 103.920635] bea0: c0428b38 c0428774 d6dbbef4 d6dbbeb8 c040e42c c0428b2c 00000000 00000000 [ 103.930523] bec0: c020ce54 d6c58188 d6d0eff0 d6c58180 00000000 d6d0eac0 d6d0f01c c12b9d54 [ 103.940423] bee0: d6d0eff0 c1204fc8 d6dbbf04 d6dbbef8 c040e59c c040e34c d6dbbf2c d6dbbf08 [ 103.950351] bf00: c02433f8 c040e590 ffffe000 d6dbbfb0 c02011c4 00000004 fffffe30 5ac3c35a [ 103.960296] bf20: d6dbbfac d6dbbf30 c020ce54 c0243350 d6dbbf4c d6dbbf40 5ac3c35a c1204fcc [ 103.970269] bf40: d6dbbf6c d6dbbf50 c0407de8 c040eb18 00000004 d6d60600 d7a73c00 00000000 [ 103.980258] bf60: d6dbbf94 d6dbbf70 c042fcc0 c0407d84 02008150 b6e63b1c 00000000 8dd7b910 [ 103.990263] bf80: c02011c4 02008150 b6e63b1c 00000000 00000006 c02011c4 d6dba000 00000006 [ 104.000294] bfa0: 00000000 d6dbbfb0 c0201034 c020c8cc 00000000 00000444 b6e636d8 b6d83864 [ 104.010348] bfc0: 02008150 b6e63b1c 00000000 00000006 b66ff29c b66ff298 020082b8 00000000 [ 104.020416] bfe0: 00000000 bef0ef68 b6d85088 b6de8f74 20000010 00000004 00000000 00000000 [ 104.030494] Backtrace: [ 104.034839] [] (lockref_put_return) from [] (dput.part.8+0x58/0x3b8) [ 104.044880] r7:00080040 r6:c0de3628 r5:d91b1fb8 r4:d91b1f68 [ 104.052509] [] (dput.part.8) from [] (dput+0x18/0x1c) [ 104.061293] r10:d71f8c70 r9:00000010 r8:d91b1f68 r7:ef32e850 r6:080a801d r5:d71f8c70 [ 104.071136] r4:d6c58180 [ 104.075682] [] (dput) from [] (fput+0xec/0x244) [ 104.084163] [] (fput) from [] (fput+0x18/0x1c) [ 104.092917] r10:c1204fc8 r9:d6d0eff0 r8:c12b9d54 r7:d6d0f01c r6:d6d0eac0 r5:00000000 [ 104.102826] r4:d6c58180 [ 104.107432] [] (fput) from [] (task_work_run+0xb4/0xd4) [ 104.116843] [] (task_work_run) from [] (do_work_pending+0x594/0x59c) [ 104.127050] r9:5ac3c35a r8:fffffe30 r7:00000004 r6:c02011c4 r5:d6dbbfb0 r4:ffffe000 [ 104.136925] [] (do_work_pending) from [] (slow_work_pending+0xc/0x20) [ 104.147255] Exception stack(0xd6dbbfb0 to 0xd6dbbff8) [ 104.154468] bfa0: 00000000 00000444 b6e636d8 b6d83864 [ 104.164831] bfc0: 02008150 b6e63b1c 00000000 00000006 b66ff29c b66ff298 020082b8 00000000 [ 104.175197] bfe0: 00000000 bef0ef68 b6d85088 b6de8f74 20000010 00000004 [ 104.184017] r10:00000006 r9:d6dba000 r8:c02011c4 r7:00000006 r6:00000000 r5:b6e63b1c [ 104.194070] r4:02008150 [ 104.198818] Code: 1a000002 e1a0cf94 e33c0000 1afffff8 (e1570003) [ 104.207145] ---[ end trace e5ed96736c0aa23a ]--- [ 104.214070] pcieport 0000:00:00.0: AER: Multiple Uncorrected (Non-Fatal) error received: 0000:00:00.0 [ 105.586945] ------------[ cut here ]------------ [ 105.593927] WARNING: CPU: 2 PID: 131 at drivers/firmware/raspberrypi.c:63 rpi_firmware_transaction+0xec/0x128 [ 105.606193] Firmware transaction timeout [ 105.606196] Modules linked in: sha256_generic libsha256 cfg80211 rfkill 8021q garp stp llc ftdi_sio usbserial vc4 cec rpivid_mem v3d drm_kms_helper gpu_sched drm bcm2835_codec(C) bcm2835_v4l2(C) bcm2835_isp(C) v4l2_mem2mem bcm2835_mmal_vchiq(C) videobuf2_dma_contig videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common drm_panel_orientation_quirks raspberrypi_hwmon snd_soc_core videodev mc vc_sm_cma(C) snd_compress snd_pcm_dmaengine snd_pcm snd_timer snd syscopyarea sysfillrect sysimgblt fb_sys_fops uio_pdrv_genirq uio ip_tables x_tables ipv6 [ 105.669241] CPU: 2 PID: 131 Comm: kworker/2:3 Tainted: G D C 5.4.79-v7l+ #1373 [ 105.680175] Hardware name: BCM2711 [ 105.686158] Workqueue: events get_values_poll [raspberrypi_hwmon] [ 105.694845] Backtrace: [ 105.699878] [] (dump_backtrace) from [] (show_stack+0x20/0x24) [ 105.710075] r7:ffffffff r6:00000000 r5:60000013 r4:c129fab0 [ 105.718362] [] (show_stack) from [] (dump_stack+0xd8/0x11c) [ 105.728314] [] (dump_stack) from [] (warn+0xe0/0x108) [ 105.737905] r10:dec12008 r9:00000009 r8:c08dd810 r7:0000003f r6:00000009 r5:c08dd810 [ 105.748380] r4:c0e3a554 r3:00000000 [ 105.754599] [] (warn) from [] (warn_slowpath_fmt+0xa4/0xc0) [ 105.764755] r7:0000003f r6:c0e3a554 r5:c1204fc8 r4:c0e3a574 [ 105.773087] [] (warn_slowpath_fmt) from [] (rpi_firmware_transaction+0xec/0x128) [ 105.784913] r9:efa10440 r8:00000010 r7:00000000 r6:ffffff92 r5:efa10440 r4:c1204fc8 [ 105.795361] [] (rpi_firmware_transaction) from [] (rpi_firmware_property_list+0xbc/0x170) [ 105.808010] r7:c1204fc8 r6:dec12000 r5:00001000 r4:dec1201c [ 105.816340] [] (rpi_firmware_property_list) from [] (rpi_firmware_property+0x70/0x118) [ 105.828626] r10:d6da2bcc r9:00030046 r8:00000010 r7:efa10440 r6:d8b8bee0 r5:00000004 [ 105.839032] r4:d6da2bc0 [ 105.844114] [] (rpi_firmware_property) from [] (get_values_poll+0x4c/0x150 [raspberrypi_hwmon]) [ 105.857144] r10:00000000 r9:00000080 r8:00000000 r7:eff3e600 r6:eff3b300 r5:d87a1a4c [ 105.867582] r4:c1204fc8 r3:00000004 [ 105.873766] [] (get_values_poll [raspberrypi_hwmon]) from [] (process_one_work+0x250/0x570) [ 105.886507] r5:d8be6300 r4:d87a1a4c [ 105.892720] [] (process_one_work) from [] (worker_thread+0x60/0x5d0) [ 105.903490] r10:eff3b300 r9:c1203d00 r8:eff3b318 r7:00000008 r6:eff3b300 r5:d8be6314 [ 105.914007] r4:d8be6300 [ 105.919233] [] (worker_thread) from [] (kthread+0x170/0x174) [ 105.929334] r10:ef939e74 r9:c023eba4 r8:d8be6300 r7:d8b8a000 r6:00000000 r5:d8c63b80 [ 105.939872] r4:d8c63800 [ 105.945104] [] (kthread) from [] (ret_from_fork+0x14/0x28) [ 105.955050] Exception stack(0xd8b8bfb0 to 0xd8b8bff8) [ 105.962811] bfa0: 00000000 00000000 00000000 00000000 [ 105.973718] bfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [ 105.984616] bfe0: 00000000 00000000 00000000 00000000 00000013 00000000 [ 105.993925] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c0245e60 [ 106.004444] r4:d8c63b80 [ 106.009681] ---[ end trace e5ed96736c0aa23b ]--- [ 106.017184] hwmon hwmon1: Failed to get throttled (-110) [ 115.025715] sched: RT throttling activated [ 115.025783] pcieport 0000:00:00.0: AER: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 115.046856] pcieport 0000:00:00.0: AER: device [14e4:2711] error status/mask=00004000/00000000 [ 115.058368] pcieport 0000:00:00.0: AER: [14] CmpltTO (First) [ 115.072822] 8<--- cut here --- [ 115.072914] pcieport 0000:00:00.0: AER: Device recovery failed [ 115.078604] Unhandled fault: asynchronous external abort (0x1211) at 0x00000000 [ 115.078611] pgd = 275d29b4 [ 115.078615] [00000000] pgd=17685003, pmd=7fe40003 [ 115.078628] Internal error: : 1211 [#2] SMP ARM [ 115.087180] pcieport 0000:00:00.0: AER: Uncorrected (Non-Fatal) error received: 0000:00:00.0 [ 115.097149] Modules linked in: sha256_generic libsha256 cfg80211 rfkill 8021q garp stp llc ftdi_sio usbserial vc4 cec rpivid_mem v3d drm_kms_helper gpu_sched drm bcm2835_codec(C) bcm2835_v4l2(C) bcm2835_isp(C) v4l2_mem2mem bcm2835_mmal_vchiq(C) videobuf2_dma_contig videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common drm_panel_orientation_quirks raspberrypi_hwmon snd_soc_core videodev mc vc_sm_cma(C) snd_compress snd_pcm_dmaengine snd_pcm snd_timer snd syscopyarea sysfillrect sysimgblt fb_sys_fops uio_pdrv_genirq uio ip_tables x_tables ipv6 [ 115.102550] pcieport 0000:00:00.0: AER: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID) [ 115.110065] CPU: 2 PID: 2332 Comm: screen Tainted: G D WC 5.4.79-v7l+ #1373 [ 115.110069] Hardware name: BCM2711 [ 115.110079] PC is at xhci_urb_dequeue+0xd8/0x474 [ 115.110084] LR is at 0xefb901a8 [ 115.117270] pcieport 0000:00:00.0: AER: device [14e4:2711] error status/mask=00004000/00000000 [ 115.128351] pc : [] lr : [] psr: 80000093 [ 115.128355] sp : d772faf0 ip : 00000000 fp : d772fb44 [ 115.128359] r10: 20000013 r9 : 00000000 r8 : efb901a0 [ 115.128365] r7 : efb90000 r6 : d6da2c00 r5 : efb90000 r4 : d75316c0 [ 115.185903] pcieport 0000:00:00.0: AER: [14] CmpltTO (First) [ 115.200336] r3 : deaddead r2 : 00000000 r1 : 0000000e r0 : d84da280 [ 115.200342] Flags: Nzcv IRQs off FIQs on Mode SVC_32 ISA ARM Segment user [ 115.200346] Control: 30c5383d Table: 16da2000 DAC: 55555555 [ 115.200353] Process screen (pid: 2332, stack limit = 0xad38c8bd) [ 115.211299] pcieport 0000:00:00.0: AER: Device recovery failed [ 115.217488] Stack: (0xd772faf0 to 0xd7730000) [ 115.217494] fae0: c020bc44 c020cf3c c020bc44 00000000 [ 115.217501] fb00: c081e91c c10a8b10 c0a95480 efb90170 d8171000 00000000 00001388 d75316c0 [ 115.217507] fb20: 60000013 efb90000 fffffffe d772fc18 00001388 d6da20c0 d772fb6c d772fb48 [ 115.225819] 8<--- cut here --- [ 115.231000] fb40: c081cf3c c08360e8 d75316c0 60000013 d87c4000 fffffffe d772fc18 00001388 [ 115.242694] Unhandled fault: asynchronous external abort (0x1211) at 0x00000000 [ 115.251811] fb60: d772fb8c d772fb70 c081e930 c081cf0c d75316c0 c1204fc8 d75316d0 d772fbc8 [ 115.259867] pgd = 6f1d3327 [ 115.267897] fb80: d772fbc4 d772fb90 c0820078 c081e8c4 c025249c 00000100 00000122 8dd7b910 [ 115.277222] [00000000] pgd=1806c003, pmd=7fcd9003 [ 115.287249] fba0: d75316c0 8dd7b910 d75316c0 c1204fc8 00000000 d772fbc8 d772fc04 d772fbc8 [ 115.445710] fbc0: c0820760 c082000c 00000000 00020002 d772fbd0 d772fbd0 00000003 8dd7b910 [ 115.456506] fbe0: c1204fc8 d87c4000 00000002 00000000 00000000 00000005 d772fc4c d772fc08 [ 115.467298] fc00: c0820848 c0820690 c03f3f6c d6da2c40 80000f80 000000c0 000001fc 8dd7b910 [ 115.478086] fc20: d772fc54 d6da2c40 d8209a00 d87c7c00 d772fc92 00000000 ffffb34a d777a900 [ 115.488874] fc40: d772fc8c d772fc50 bf1a56a8 c0820780 00000000 00000003 d6da2c40 00000002 [ 115.499660] fc60: 00001388 c10a8b10 c0a95480 c1204fc8 00000000 d772e000 00000001 c1203d00 [ 115.510434] fc80: d772fcac d772fc90 bf1a57ec bf1a560c 00000000 8dd7b910 d772fcbc d87c7c00 [ 115.521198] fca0: d772fcd4 d772fcb0 bf171200 bf1a57c8 d82fe100 d81e0600 d87c7c00 d82fe158 [ 115.531943] fcc0: 00000000 00000000 d772fcfc d772fcd8 bf16f414 bf171184 00000000 d81e0600 [ 115.542675] fce0: c1204fc8 0000000a d81e0674 00000000 d772fd3c d772fd00 c074fe88 bf16f3bc [ 115.553398] fd00: d772fd24 d772fd10 c0a8fea0 c07512cc d772fd3c 8dd7b910 c07512cc c1204fc8 [ 115.564113] fd20: d777a900 d81e0600 0000000a d81e0674 d772fd94 d772fd40 c07506a8 c074fd90 [ 115.574817] fd40: 00000406 00000000 000018b2 00008a30 7f1c0300 64020415 1a131100 170f1200 [ 115.585512] fd60: 00000016 0001c200 0001c200 8dd7b910 d81e0600 c1204fc8 bebfcbfc d6d7d780 [ 115.596188] fd80: c074c660 bebfcbfc d772fdec d772fd98 c0750b78 c0750574 00000500 00000005 [ 115.606866] fda0: 00000cbd 00008a3b 7f1c0300 01000415 1a131100 c0a8fea0 00000000 d81e0618 [ 115.617535] fdc0: d772fde4 8dd7b910 c0a8fea0 d81e0600 d81e0600 bebfcbfc d6d7d780 c074c660 [ 115.628193] fde0: d772fe0c d772fdf0 c0750dcc c0750868 d81e0600 bebfcbfc c1204fc8 d6d7d780 [ 115.638839] fe00: d772fe34 d772fe10 c074c698 c0750da0 00005403 d81e0600 c1204fc8 d6d7d780 [ 115.649469] fe20: c074c660 bebfcbfc d772fedc d772fe38 c074a5b0 c074c66c bebfcbfc 00000001 [ 115.660099] fe40: d772fe84 d772fe50 c03d1a3c c0211be4 c03c1a70 04e00000 ffffe000 c1204fc8 [ 115.670732] fe60: 75c9f3df 00000040 c13365c0 75c9f3df 00000000 c03c5ffc d772ff24 d772fe88 [ 115.681361] fe80: c03c5ffc c021b7f4 75c9ffdf 04e00000 00000000 d772fea0 c020cf60 c020bbc4 [ 115.691988] fea0: c1204fc8 00000000 d755a600 8dd7b910 d6c96068 c1204fc8 bebfcbfc d6d7d780 [ 115.702620] fec0: 00000004 bebfcbfc 00000004 d84a4778 d772ff6c d772fee0 c0422dcc c074a324 [ 115.713259] fee0: 00000000 ffede3b0 deb34ee8 00000000 d755a600 8dd7b910 d772ff24 d772ffb0 [ 115.723897] ff00: d6d0bd00 d755a600 b6e76e50 0000020b d6c96068 c0a95c40 d772ff74 d772ff28 [ 115.734536] ff20: c0a95c40 c027b438 c020cf60 c020bbc4 c1204fc8 00000000 ffffffff 8dd7b910 [ 115.745197] ff40: 00000000 d6d7d780 d6d7d780 00000000 00005403 bebfcbfc 00000004 00000036 [ 115.755860] ff60: d772ff94 d772ff70 c042354c c0422d18 bebfcc78 00000001 00076c18 00000036 [ 115.766517] ff80: c02011c4 d772e000 d772ffa4 d772ff98 c0423588 c04234ec 00000000 d772ffa8 [ 115.777183] ffa0: c0201000 c042357c bebfcc78 00000001 00000004 00005403 bebfcbfc 00008a30 [ 115.787862] ffc0: bebfcc78 00000001 00076c18 00000036 00000004 b6f55bb0 00000001 00000000 [ 115.798544] ffe0: 00000000 bebfcbf8 00000000 b6dfb7a4 80000010 00000004 00000000 00000000 [ 115.809196] Backtrace: [ 115.814099] [] (xhci_urb_dequeue) from [] (unlink1+0x3c/0x11c) [ 115.824151] r10:d6da20c0 r9:00001388 r8:d772fc18 r7:fffffffe r6:efb90000 r5:60000013 [ 115.834466] r4:d75316c0 [ 115.839475] [] (unlink1) from [] (usb_hcd_unlink_urb+0x78/0x94) [ 115.849631] r9:00001388 r8:d772fc18 r7:fffffffe r6:d87c4000 r5:60000013 r4:d75316c0 [ 115.859876] [] (usb_hcd_unlink_urb) from [] (usb_kill_urb+0x78/0x108) [ 115.870568] r7:d772fbc8 r6:d75316d0 r5:c1204fc8 r4:d75316c0 [ 115.878761] [] (usb_kill_urb) from [] (usb_start_wait_urb+0xdc/0xf0) [ 115.889379] r7:d772fbc8 r6:00000000 r5:c1204fc8 r4:d75316c0 [ 115.897503] [] (usb_start_wait_urb) from [] (usb_control_msg+0xd4/0x12c) [ 115.908359] r9:00000005 r8:00000000 r7:00000000 r6:00000002 r5:d87c4000 r4:c1204fc8 [ 115.918478] [] (usb_control_msg) from [] (ftdi_get_modem_status+0xa8/0x128 [ftdi_sio]) [ 115.930497] r10:d777a900 r9:ffffb34a r8:00000000 r7:d772fc92 r6:d87c7c00 r5:d8209a00 [ 115.940667] r4:d6da2c40 [ 115.945531] [] (ftdi_get_modem_status [ftdi_sio]) from [] (ftdi_tx_empty+0x30/0x5c [ftdi_sio]) [ 115.958280] r8:c1203d00 r7:00000001 r6:d772e000 r5:00000000 r4:c1204fc8 [ 115.967394] [] (ftdi_tx_empty [ftdi_sio]) from [] (usb_serial_generic_wait_until_sent+0x88/0xc8 [usbserial]) [ 115.981391] r4:d87c7c00 [ 115.986343] [] (usb_serial_generic_wait_until_sent [usbserial]) from [] (serial_wait_until_sent+0x64/0x70 [usbserial]) [ 116.001255] r9:00000000 r8:00000000 r7:d82fe158 r6:d87c7c00 r5:d81e0600 r4:d82fe100 [ 116.011503] [] (serial_wait_until_sent [usbserial]) from [] (tty_wait_until_sent+0x104/0x188) [ 116.024295] r9:00000000 r8:d81e0674 r7:0000000a r6:c1204fc8 r5:d81e0600 r4:00000000 [ 116.034575] [] (tty_wait_until_sent) from [] (set_termios+0x140/0x2f4) [ 116.045379] r8:d81e0674 r7:0000000a r6:d81e0600 r5:d777a900 r4:c1204fc8 [ 116.054618] [] (set_termios) from [] (tty_mode_ioctl+0x31c/0x538) [ 116.064999] r9:bebfcbfc r8:c074c660 r7:d6d7d780 r6:bebfcbfc r5:c1204fc8 r4:d81e0600 [ 116.075304] [] (tty_mode_ioctl) from [] (n_tty_ioctl_helper+0x38/0x138) [ 116.086227] r8:c074c660 r7:d6d7d780 r6:bebfcbfc r5:d81e0600 r4:d81e0600 [ 116.095499] [] (n_tty_ioctl_helper) from [] (n_tty_ioctl+0x38/0x13c) [ 116.106170] r7:d6d7d780 r6:c1204fc8 r5:bebfcbfc r4:d81e0600 [ 116.114401] [] (n_tty_ioctl) from [] (tty_ioctl+0x298/0x9f4) [ 116.124377] r9:bebfcbfc r8:c074c660 r7:d6d7d780 r6:c1204fc8 r5:d81e0600 r4:00005403 [ 116.134711] [] (tty_ioctl) from [] (do_vfs_ioctl+0xc0/0x7d4) [ 116.144684] r10:d84a4778 r9:00000004 r8:bebfcbfc r7:00000004 r6:d6d7d780 r5:bebfcbfc [ 116.155090] r4:c1204fc8 [ 116.160176] [] (do_vfs_ioctl) from [] (ksys_ioctl+0x6c/0x90) [ 116.170140] r10:00000036 r9:00000004 r8:bebfcbfc r7:00005403 r6:00000000 r5:d6d7d780 [ 116.180534] r4:d6d7d780 [ 116.185605] [] (ksys_ioctl) from [] (sys_ioctl+0x18/0x1c) [ 116.195297] r9:d772e000 r8:c02011c4 r7:00000036 r6:00076c18 r5:00000001 r4:bebfcc78 [ 116.205607] [] (sys_ioctl) from [] (ret_fast_syscall+0x0/0x28) [ 116.215739] Exception stack(0xd772ffa8 to 0xd772fff0) [ 116.223354] ffa0: bebfcc78 00000001 00000004 00005403 bebfcbfc 00008a30 [ 116.234111] ffc0: bebfcc78 00000001 00076c18 00000036 00000004 b6f55bb0 00000001 00000000 [ 116.244862] ffe0: 00000000 bebfcbf8 00000000 b6dfb7a4 [ 116.252480] Code: e5933004 f57ff04f e3730001 0a00002a (e597c678) [ 116.261144] ---[ end trace e5ed96736c0aa23c ]--- [ 116.277705] raspberrypi-firmware soc:firmware: Request 0x00030046 returned status 0x80000001 [ 137.295291] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [ 137.302984] rcu: 1-...0: (1 GPs behind) idle=cb6/1/0x40000000 softirq=7420/7433 fqs=714 [ 137.312899] (detected by 0, t=2103 jiffies, g=3593, q=2184) [ 137.320295] Sending NMI from CPU 0 to CPUs 1: [ 147.327309] rcu: rcu_sched kthread starved for 1000 jiffies! g3593 f0x0 RCU_GP_DOING_FQS(6) ->state=0x0 ->cpu=2 [ 147.339214] rcu: RCU grace-period kthread stack dump: [ 147.346013] rcu_sched R running task 0 10 2 0x00000000 [ 147.354809] Backtrace: [ 147.358987] [] (schedule) from [] (preempt_schedule_common+0x1c/0x34) [ 147.369088] r10:c1203d00 r9:ef910000 r8:00000000 r7:c120508c r6:00000000 r5:00000000 [ 147.378674] r4:ffffe000 [ 147.382948] [] (preempt_schedule_common) from [] (_cond_resched+0x50/0x58) [ 147.393321] r5:00000000 r4:00000001 [ 147.398650] [] (_cond_resched) from [] (rcu_gp_kthread+0x548/0xa40) [ 147.408420] r5:00000000 r4:c12110c0 [ 147.413752] [] (rcu_gp_kthread) from [] (kthread+0x170/0x174) [ 147.422999] r7:ef910000 [ 147.427282] [] (kthread) from [] (ret_from_fork+0x14/0x28) [ 147.436271] Exception stack(0xef911fb0 to 0xef911ff8) [ 147.443086] 1fa0: 00000000 00000000 00000000 00000000 [ 147.453040] 1fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [ 147.462983] 1fe0: 00000000 00000000 00000000 00000000 00000013 00000000 [ 147.471352] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c0245e60 [ 147.480932] r4:ef86fcc0 [ 156.945148] ------------[ cut here ]------------ [ 156.951535] WARNING: CPU: 3 PID: 24 at net/sched/sch_generic.c:448 dev_watchdog+0x314/0x318 [ 156.961652] NETDEV WATCHDOG: eth0 (bcmgenet): transmit queue 0 timed out [ 156.970115] Modules linked in: sha256_generic libsha256 cfg80211 rfkill 8021q garp stp llc ftdi_sio usbserial vc4 cec rpivid_mem v3d drm_kms_helper gpu_sched drm bcm2835_codec(C) bcm2835_v4l2(C) bcm2835_isp(C) v4l2_mem2mem bcm2835_mmal_vchiq(C) videobuf2_dma_contig videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common drm_panel_orientation_quirks raspberrypi_hwmon snd_soc_core videodev mc vc_sm_cma(C) snd_compress snd_pcm_dmaengine snd_pcm snd_timer snd syscopyarea sysfillrect sysimgblt fb_sys_fops uio_pdrv_genirq uio ip_tables x_tables ipv6 [ 157.024882] CPU: 3 PID: 24 Comm: migration/3 Tainted: G D WC 5.4.79-v7l+ #1373 [ 157.035028] Hardware name: BCM2711 [ 157.040290] Backtrace: [ 157.044593] [] (dump_backtrace) from [] (show_stack+0x20/0x24) [ 157.054024] r7:ffffffff r6:00000000 r5:60000113 r4:c129fab0 [ 157.061536] [] (show_stack) from [] (dump_stack+0xd8/0x11c) [ 157.070704] [] (dump_stack) from [] (warn+0xe0/0x108) [ 157.079504] r10:c12a6f78 r9:00000009 r8:c0982fa0 r7:000001c0 r6:00000009 r5:c0982fa0 [ 157.089182] r4:c0e47714 r3:00000000 [ 157.094581] [] (warn) from [] (warn_slowpath_fmt+0xa4/0xc0) [ 157.103897] r7:000001c0 r6:c0e47714 r5:c1204fc8 r4:c0e476d8 [ 157.111377] [] (warn_slowpath_fmt) from [] (dev_watchdog+0x314/0x318) [ 157.121378] r9:eff48440 r8:ef254000 r7:c1203d00 r6:ef1aa800 r5:ef2542a8 r4:00000000 [ 157.130928] [] (dev_watchdog) from [] (call_timer_fn+0x40/0x1b0) [ 157.140469] r8:00000000 r7:ffffc820 r6:c0982c8c r5:00000101 r4:ef2542a8 [ 157.148947] [] (call_timer_fn) from [] (run_timer_softirq+0x46c/0x640) [ 157.158974] r8:00000000 r7:ffffc820 r6:00000000 r5:ef93fd34 r4:ef2542a8 [ 157.167434] [] (run_timer_softirq) from [] (do_softirq+0x194/0x444) [ 157.177377] r10:ffffe000 r9:ef93e000 r8:00000002 r7:00000101 r6:00000001 r5:00000002 [ 157.186960] r4:c1203084 [ 157.191236] [] (do_softirq) from [] (irq_exit+0xdc/0x100) [ 157.200292] r10:00000000 r9:ef93e000 r8:ef850800 r7:00000001 r6:00000000 r5:00000000 [ 157.209875] r4:ffffe000 [ 157.214149] [] (irq_exit) from [] (handle_domain_irq+0x70/0xc4) [ 157.223725] r5:00000000 r4:c10aa2a4 [ 157.229044] [] (handle_domain_irq) from [] (gic_handle_irq+0x4c/0x88) [ 157.239151] r9:ef93e000 r8:f0815000 r7:ef93fe60 r6:f0814000 r5:f081400c r4:c1205a34 [ 157.248654] [] (gic_handle_irq) from [] (__irq_svc+0x5c/0x7c) [ 157.257884] Exception stack(0xef93fe60 to 0xef93fea8) [ 157.264684] fe60: c1204ff0 00000000 00000002 00000000 ef939e00 00000001 00000001 00000000 [ 157.274622] fe80: c1204ff0 ef939dec 00000000 ef93febc ef93fec0 ef93feb0 c02dd3b8 c02dd338 [ 157.284549] fea0: 60000013 ffffffff [ 157.289772] r9:ef93e000 r8:c1204ff0 r7:ef93fe94 r6:ffffffff r5:60000013 r4:c02dd338 [ 157.299267] [] (stop_machine_yield) from [] (multi_cpu_stop+0x74/0x178) [ 157.309363] [] (multi_cpu_stop) from [] (cpu_stopper_thread+0x90/0x164) [ 157.319463] r10:ef939d8c r9:eff49988 r8:eff49990 r7:ef939dec r6:c02dd344 r5:ffffe000 [ 157.329050] r4:eff49984 [ 157.333316] [] (cpu_stopper_thread) from [] (smpboot_thread_fn+0x110/0x1e8) [ 157.343771] r10:00000000 r9:00000000 r8:00000001 r7:c1204fc8 r6:c1217204 r5:ffffe000 [ 157.353364] r4:ef87f740 [ 157.357651] [] (smpboot_thread_fn) from [] (kthread+0x170/0x174) [ 157.367147] r10:ef8dbda4 r9:c0249cd4 r8:ef87f740 r7:ef93e000 r6:00000000 r5:ef87f7c0 [ 157.376746] r4:ef87f800 [ 157.381032] [] (kthread) from [] (ret_from_fork+0x14/0x28) [ 157.390020] Exception stack(0xef93ffb0 to 0xef93fff8) [ 157.396821] ffa0: 00000000 00000000 00000000 00000000 [ 157.406762] ffc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [ 157.416699] ffe0: 00000000 00000000 00000000 00000000 00000013 00000000 [ 157.425064] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c0245e60 [ 157.434624] r4:ef87f7c0 [ 157.438875] ---[ end trace e5ed96736c0aa23d ]--- [ 200.345089] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [ 200.352737] rcu: 1-...0: (1 GPs behind) idle=cb6/1/0x40000000 softirq=7420/7433 fqs=715 [ 200.362638] (detected by 0, t=8408 jiffies, g=3593, q=2187) [ 200.370014] Sending NMI from CPU 0 to CPUs 1: [ 210.377010] rcu: rcu_sched kthread starved for 7305 jiffies! g3593 f0x2 RCU_GP_DOING_FQS(6) ->state=0x0 ->cpu=0 [ 210.388827] rcu: RCU grace-period kthread stack dump: [ 210.395593] rcu_sched R running task 0 10 2 0x00000000 [ 210.404357] Backtrace: [ 210.408514] [] (schedule) from [] (preempt_schedule_common+0x1c/0x34) [ 210.418579] r10:c1203d00 r9:ef910000 r8:00000000 r7:c120508c r6:00000000 r5:00000000 [ 210.428128] r4:ffffe000 [ 210.432366] [] (preempt_schedule_common) from [] (_cond_resched+0x50/0x58) [ 210.442707] r5:00000000 r4:00000001 [ 210.448000] [] (_cond_resched) from [] (rcu_gp_kthread+0x548/0xa40) [ 210.457742] r5:00000000 r4:c12110c0 [ 210.463051] [] (rcu_gp_kthread) from [] (kthread+0x170/0x174) [ 210.472291] r7:ef910000 [ 210.476563] [] (kthread) from [] (ret_from_fork+0x14/0x28) [ 210.485531] Exception stack(0xef911fb0 to 0xef911ff8) [ 210.492331] 1fa0: 00000000 00000000 00000000 00000000 [ 210.502255] 1fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [ 210.512144] 1fe0: 00000000 00000000 00000000 00000000 00000013 00000000 [ 210.520410] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c0245e60 [ 210.529849] r4:ef86fcc0 [ 263.395085] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [ 263.402601] rcu: 1-...0: (1 GPs behind) idle=cb6/1/0x40000000 softirq=7420/7433 fqs=715 [ 263.412387] (detected by 0, t=14713 jiffies, g=3593, q=2187) [ 263.419739] Sending NMI from CPU 0 to CPUs 1: [ 273.426617] rcu: rcu_sched kthread starved for 13610 jiffies! g3593 f0x2 RCU_GP_DOING_FQS(6) ->state=0x0 ->cpu=0 [ 273.438413] rcu: RCU grace-period kthread stack dump: [ 273.445088] rcu_sched R running task 0 10 2 0x00000000 [ 273.453755] Backtrace: [ 273.457812] [] (__schedule) from [] (preempt_schedule_common+0x1c/0x34) [ 273.467789] r10:c1203d00 r9:ef910000 r8:00000000 r7:c120508c r6:00000000 r5:00000000 [ 273.477251] r4:ffffe000 [ 273.481396] [] (preempt_schedule_common) from [] (_cond_resched+0x50/0x58) [ 273.491646] r5:00000000 r4:00000001 [ 273.496841] [] (_cond_resched) from [] (rcu_gp_kthread+0x548/0xa40) [ 273.506480] r5:00000000 r4:c12110c0 [ 273.511672] [] (rcu_gp_kthread) from [] (kthread+0x170/0x174) [ 273.520777] r7:ef910000 [ 273.524921] [] (kthread) from [] (ret_from_fork+0x14/0x28) [ 273.533763] Exception stack(0xef911fb0 to 0xef911ff8) [ 273.540424] 1fa0: 00000000 00000000 00000000 00000000 [ 273.550232] 1fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [ 273.560026] 1fe0: 00000000 00000000 00000000 00000000 00000013 00000000 [ 273.568242] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c0245e60 [ 273.577668] r4:ef86fcc0

Additional context When connecting the USB serial ports to a different computer (my notebook) this works fine. The original bug report is in the freetserv project: https://github.com/freetserv/freetserv/issues/48

P33M commented 3 years ago

Please post a full dmesg since boot (with the devices connected). Also post the output of lsusb -t.

I would expect the controller to reject more than 31 devices, because it has 32 device slots (minus 1 for the onboard hub).

r-schmidt commented 3 years ago
$ dmesg
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.4.79-v7l+ (dom@buildbot) (gcc version 8.4.0 (Ubuntu/Linaro 8.4.0-3ubuntu1)) #1373 SMP Mon Nov 23 13:27:40 GMT 2020
[    0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.1
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] Reserved memory: created CMA memory pool at 0x000000001ec00000, size 256 MiB
[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[    0.000000] On node 0 totalpages: 504832
[    0.000000]   DMA zone: 2304 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 196608 pages, LIFO batch:63
[    0.000000]   HighMem zone: 308224 pages, LIFO batch:63
[    0.000000] percpu: Embedded 20 pages/cpu s49804 r8192 d23924 u81920
[    0.000000] pcpu-alloc: s49804 r8192 d23924 u81920 alloc=20*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 502528
[    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1  smsc95xx.macaddr=DC:A6:32:3F:EA:97 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=ttyAMA0,115200 console=tty1 root=PARTUUID=53c6fbe5-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] software IO TLB: mapped [mem 0x19400000-0x1d400000] (64MB)
[    0.000000] Memory: 1647796K/2019328K available (10240K kernel code, 739K rwdata, 2816K rodata, 2048K init, 854K bss, 109388K reserved, 262144K cma-reserved, 1232896K highmem)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 31111 entries in 61 pages
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] GIC: Using split EOI/Deactivate mode
[    0.000000] random: get_random_bytes called from start_kernel+0x344/0x518 with crng_init=0
[    0.000007] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[    0.000029] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[    0.000107] bcm2835: system timer (irq = 17)
[    0.000756] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
[    0.000775] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
[    0.000795] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[    0.000811] Switching to timer-based delay loop, resolution 18ns
[    0.001053] Console: colour dummy device 80x30
[    0.001549] printk: console [tty1] enabled
[    0.001616] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000)
[    0.001659] pid_max: default: 32768 minimum: 301
[    0.001821] LSM: Security Framework initializing
[    0.002028] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.002070] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.003432] Disabling memory control group subsystem
[    0.003569] CPU: Testing write buffer coherency: ok
[    0.004086] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.005010] Setting up static identity map for 0x200000 - 0x20003c
[    0.005233] rcu: Hierarchical SRCU implementation.
[    0.005933] smp: Bringing up secondary CPUs ...
[    0.007133] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.008458] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.009720] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.009877] smp: Brought up 1 node, 4 CPUs
[    0.009948] SMP: Total of 4 processors activated (432.00 BogoMIPS).
[    0.009975] CPU: All CPU(s) started in HYP mode.
[    0.009999] CPU: Virtualization extensions available.
[    0.010832] devtmpfs: initialized
[    0.024409] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0
[    0.024687] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.024738] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[    0.031552] pinctrl core: initialized pinctrl subsystem
[    0.032569] NET: Registered protocol family 16
[    0.036411] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.036996] audit: initializing netlink subsys (disabled)
[    0.037259] audit: type=2000 audit(0.030:1): state=initialized audit_enabled=0 res=1
[    0.038328] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.038364] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.038700] Serial: AMBA PL011 UART driver
[    0.042238] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[    0.060827] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-11-30 22:12, variant start
[    0.070843] raspberrypi-firmware soc:firmware: Firmware hash is ab1181cc0cb6df52bfae3b1d3fef0ce7c325166c
[    0.125130] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
[    0.130190] vgaarb: loaded
[    0.130659] SCSI subsystem initialized
[    0.130956] usbcore: registered new interface driver usbfs
[    0.131029] usbcore: registered new interface driver hub
[    0.131164] usbcore: registered new device driver usb
[    0.131490] usb_phy_generic phy: phy supply vcc not found, using dummy regulator
[    0.133282] clocksource: Switched to clocksource arch_sys_counter
[    0.892843] VFS: Disk quotas dquot_6.6.0
[    0.892966] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.893146] FS-Cache: Loaded
[    0.893390] CacheFiles: Loaded
[    0.903904] thermal_sys: Registered thermal governor 'step_wise'
[    0.904270] NET: Registered protocol family 2
[    0.905049] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    0.905102] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    0.905180] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.905263] TCP: Hash tables configured (established 8192 bind 8192)
[    0.905428] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
[    0.905477] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
[    0.905749] NET: Registered protocol family 1
[    0.906494] RPC: Registered named UNIX socket transport module.
[    0.906525] RPC: Registered udp transport module.
[    0.906551] RPC: Registered tcp transport module.
[    0.906576] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.906611] PCI: CLS 0 bytes, default 64
[    0.908454] hw perfevents: enabled with armv7_cortex_a15 PMU driver, 7 counters available
[    0.910680] Initialise system trusted keyrings
[    0.910922] workingset: timestamp_bits=14 max_order=19 bucket_order=5
[    0.921859] FS-Cache: Netfs 'nfs' registered for caching
[    0.922595] NFS: Registering the id_resolver key type
[    0.922643] Key type id_resolver registered
[    0.922669] Key type id_legacy registered
[    0.922704] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.923844] Key type asymmetric registered
[    0.923873] Asymmetric key parser 'x509' registered
[    0.924078] bounce: pool size: 64 pages
[    0.924143] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
[    0.924400] io scheduler mq-deadline registered
[    0.924429] io scheduler kyber registered
[    0.928407] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[    0.928450] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
[    0.928542] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x0603ffffff -> 0x00f8000000
[    0.928633] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x007fffffff -> 0x0000000000
[    0.985405] brcm-pcie fd500000.pcie: link up, 5 GT/s x1 (SSC)
[    0.985745] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[    0.985779] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.985814] pci_bus 0000:00: root bus resource [mem 0x600000000-0x603ffffff] (bus address [0xf8000000-0xfbffffff])
[    0.985892] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[    0.986178] pci 0000:00:00.0: PME# supported from D0 D3hot
[    0.989472] PCI: bus0: Fast back to back transfers disabled
[    0.989729] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
[    0.989892] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[    0.990340] pci 0000:01:00.0: PME# supported from D0 D3cold
[    0.993670] PCI: bus1: Fast back to back transfers disabled
[    0.993745] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[    0.993784] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
[    0.993885] pci 0000:00:00.0: PCI bridge to [bus 01]
[    0.993923] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]
[    0.994253] pcieport 0000:00:00.0: enabling device (0140 -> 0142)
[    0.994498] pcieport 0000:00:00.0: PME: Signaling with IRQ 55
[    0.994920] pcieport 0000:00:00.0: AER: enabled with IRQ 55
[    0.995272] pci 0000:01:00.0: enabling device (0140 -> 0142)
[    1.000037] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled
[    1.002846] iproc-rng200 fe104000.rng: hwrng registered
[    1.003191] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[    1.003932] vc-sm: Videocore shared memory driver
[    1.004506] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[    1.016795] brd: module loaded
[    1.029346] loop: module loaded
[    1.030767] Loading iSCSI transport class v2.0-870.
[    1.032821] libphy: Fixed MDIO Bus: probed
[    1.033502] bcmgenet fd580000.ethernet: failed to get enet clock
[    1.033540] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
[    1.033577] bcmgenet fd580000.ethernet: failed to get enet-wol clock
[    1.033614] bcmgenet fd580000.ethernet: failed to get enet-eee clock
[    1.033655] bcmgenet: Skipping UMAC reset
[    1.053365] libphy: bcmgenet MII bus: probed
[    1.143474] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
[    1.144635] usbcore: registered new interface driver r8152
[    1.144719] usbcore: registered new interface driver lan78xx
[    1.144794] usbcore: registered new interface driver smsc95xx
[    1.145302] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    1.145351] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[    1.147769] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000003000000890
[    1.149101] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.04
[    1.149140] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.149175] usb usb1: Product: xHCI Host Controller
[    1.149203] usb usb1: Manufacturer: Linux 5.4.79-v7l+ xhci-hcd
[    1.149231] usb usb1: SerialNumber: 0000:01:00.0
[    1.149865] hub 1-0:1.0: USB hub found
[    1.149976] hub 1-0:1.0: 1 port detected
[    1.150554] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    1.150595] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[    1.150638] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[    1.151137] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.04
[    1.151175] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.151208] usb usb2: Product: xHCI Host Controller
[    1.151236] usb usb2: Manufacturer: Linux 5.4.79-v7l+ xhci-hcd
[    1.151265] usb usb2: SerialNumber: 0000:01:00.0
[    1.151890] hub 2-0:1.0: USB hub found
[    1.151989] hub 2-0:1.0: 4 ports detected
[    1.153535] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    1.153838] dwc_otg: FIQ enabled
[    1.153851] dwc_otg: NAK holdoff enabled
[    1.153864] dwc_otg: FIQ split-transaction FSM enabled
[    1.153891] Module dwc_common_port init
[    1.154360] usbcore: registered new interface driver uas
[    1.154479] usbcore: registered new interface driver usb-storage
[    1.154692] mousedev: PS/2 mouse device common for all mice
[    1.156556] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    1.159964] sdhci: Secure Digital Host Controller Interface driver
[    1.159995] sdhci: Copyright(c) Pierre Ossman
[    1.160573] sdhci-pltfm: SDHCI platform and OF driver helper
[    1.163898] ledtrig-cpu: registered to indicate activity on CPUs
[    1.164236] hidraw: raw HID events driver (C) Jiri Kosina
[    1.164432] usbcore: registered new interface driver usbhid
[    1.164460] usbhid: USB HID core driver
[    1.165510] vchiq: vchiq_init_state: slot_zero = (ptrval)
[    1.167454] [vc_sm_connected_init]: start
[    1.176289] [vc_sm_connected_init]: end - returning 0
[    1.178286] Initializing XFRM netlink socket
[    1.178340] NET: Registered protocol family 17
[    1.178477] Key type dns_resolver registered
[    1.178830] Registering SWP/SWPB emulation handler
[    1.179168] registered taskstats version 1
[    1.179201] Loading compiled-in X.509 certificates
[    1.179746] Key type ._fscrypt registered
[    1.179774] Key type .fscrypt registered
[    1.190430] uart-pl011 fe201000.serial: cts_event_workaround enabled
[    1.190524] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 29, base_baud = 0) is a PL011 rev2
[    2.366793] printk: console [ttyAMA0] enabled
[    2.378450] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[    2.423932] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA
[    2.434409] of_cfs_init
[    2.436973] of_cfs_init: OK
[    2.440932] Waiting for root device PARTUUID=53c6fbe5-02...
[    2.473204] mmc0: new high speed SDHC card at address 211d
[    2.479829] mmcblk0: mmc0:211d APPSD 14.8 GiB
[    2.486900]  mmcblk0: p1 p2
[    2.516801] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    2.525013] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    2.541810] devtmpfs: mounted
[    2.553487] Freeing unused kernel memory: 2048K
[    2.558315] Run /sbin/init as init process
[    2.633342] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[    2.816022] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
[    2.824141] random: fast init done
[    2.824286] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[    2.834827] usb 1-1: Product: USB2.0 Hub
[    2.840599] hub 1-1:1.0: USB hub found
[    2.844663] hub 1-1:1.0: 4 ports detected
[    3.173342] usb 1-1.4: new full-speed USB device number 3 using xhci_hcd
[    3.307254] usb 1-1.4: New USB device found, idVendor=0451, idProduct=2046, bcdDevice= 1.25
[    3.315684] usb 1-1.4: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.325918] hub 1-1.4:1.0: USB hub found
[    3.332745] hub 1-1.4:1.0: 4 ports detected
[    3.397948] systemd[1]: System time before build time, advancing clock.
[    3.547034] NET: Registered protocol family 10
[    3.552816] Segment Routing with IPv6
[    3.591954] systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid)
[    3.614735] systemd[1]: Detected architecture arm.
[    3.683376] usb 1-1.4.1: new full-speed USB device number 4 using xhci_hcd
[    3.691817] systemd[1]: Set hostname to <raspberrypi>.
[    3.824951] usb 1-1.4.1: not running at top speed; connect to a high speed hub
[    3.837213] usb 1-1.4.1: New USB device found, idVendor=0403, idProduct=6011, bcdDevice= 8.00
[    3.845826] usb 1-1.4.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    3.853374] usb 1-1.4.1: Product: Quad RS232-HS
[    3.857942] usb 1-1.4.1: Manufacturer: FTDI
[    3.887436] uart-pl011 fe201000.serial: no DMA platform data
[    3.993364] usb 1-1.4.2: new full-speed USB device number 5 using xhci_hcd
[    4.134742] usb 1-1.4.2: not running at top speed; connect to a high speed hub
[    4.146997] usb 1-1.4.2: New USB device found, idVendor=0403, idProduct=6011, bcdDevice= 8.00
[    4.155589] usb 1-1.4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    4.163096] usb 1-1.4.2: Product: Quad RS232-HS
[    4.167680] usb 1-1.4.2: Manufacturer: FTDI
[    4.293373] usb 1-1.4.3: new full-speed USB device number 6 using xhci_hcd
[    4.444782] usb 1-1.4.3: not running at top speed; connect to a high speed hub
[    4.457036] usb 1-1.4.3: New USB device found, idVendor=0403, idProduct=6011, bcdDevice= 8.00
[    4.465639] usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    4.473146] usb 1-1.4.3: Product: Quad RS232-HS
[    4.477721] usb 1-1.4.3: Manufacturer: FTDI
[    4.481544] random: systemd: uninitialized urandom read (16 bytes read)
[    4.502109] random: systemd: uninitialized urandom read (16 bytes read)
[    4.512447] systemd[1]: Created slice system-systemd\x2dfsck.slice.
[    4.519803] random: systemd: uninitialized urandom read (16 bytes read)
[    4.527422] systemd[1]: Listening on Journal Socket.
[    4.533686] systemd[1]: Listening on Journal Socket (/dev/log).
[    4.540143] systemd[1]: Condition check resulted in Kernel Module supporting RPCSEC_GSS being skipped.
[    4.555729] systemd[1]: Starting Create list of required static device nodes for the current kernel...
[    4.572468] systemd[1]: Starting Set the console keyboard layout...
[    4.581067] systemd[1]: Listening on udev Kernel Socket.
[    4.633414] usb 1-1.4.4: new full-speed USB device number 7 using xhci_hcd
[    4.787361] usb 1-1.4.4: New USB device found, idVendor=0451, idProduct=2046, bcdDevice= 1.25
[    4.796030] usb 1-1.4.4: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    4.842081] hub 1-1.4.4:1.0: USB hub found
[    4.844869] hub 1-1.4.4:1.0: 4 ports detected
[    5.173361] usb 1-1.4.4.1: new full-speed USB device number 8 using xhci_hcd
[    5.304783] usb 1-1.4.4.1: not running at top speed; connect to a high speed hub
[    5.309035] usb 1-1.4.4.1: New USB device found, idVendor=0403, idProduct=6011, bcdDevice= 8.00
[    5.309054] usb 1-1.4.4.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    5.309071] usb 1-1.4.4.1: Product: Quad RS232-HS
[    5.309088] usb 1-1.4.4.1: Manufacturer: FTDI
[    5.423326] usb 1-1.4.4.2: new full-speed USB device number 9 using xhci_hcd
[    5.554818] usb 1-1.4.4.2: not running at top speed; connect to a high speed hub
[    5.559068] usb 1-1.4.4.2: New USB device found, idVendor=0403, idProduct=6011, bcdDevice= 8.00
[    5.559086] usb 1-1.4.4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    5.559103] usb 1-1.4.4.2: Product: Quad RS232-HS
[    5.559118] usb 1-1.4.4.2: Manufacturer: FTDI
[    5.673335] usb 1-1.4.4.3: new full-speed USB device number 10 using xhci_hcd
[    5.804727] usb 1-1.4.4.3: not running at top speed; connect to a high speed hub
[    5.808979] usb 1-1.4.4.3: New USB device found, idVendor=0403, idProduct=6011, bcdDevice= 8.00
[    5.808996] usb 1-1.4.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    5.809012] usb 1-1.4.4.3: Product: Quad RS232-HS
[    5.809028] usb 1-1.4.4.3: Manufacturer: FTDI
[    5.873971] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    5.923380] usb 1-1.4.4.4: new full-speed USB device number 11 using xhci_hcd
[    5.964514] systemd-journald[114]: Received request to flush runtime journal from PID 1
[    6.057280] usb 1-1.4.4.4: New USB device found, idVendor=0451, idProduct=2046, bcdDevice= 1.25
[    6.057300] usb 1-1.4.4.4: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    6.059972] hub 1-1.4.4.4:1.0: USB hub found
[    6.062767] hub 1-1.4.4.4:1.0: 4 ports detected
[    6.393376] usb 1-1.4.4.4.1: new full-speed USB device number 12 using xhci_hcd
[    6.530170] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000
[    6.533435] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000
[    6.534879] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000
[    6.541862] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000
[    6.543615] usb 1-1.4.4.4.1: not running at top speed; connect to a high speed hub
[    6.547849] usb 1-1.4.4.4.1: New USB device found, idVendor=0403, idProduct=6011, bcdDevice= 8.00
[    6.547869] usb 1-1.4.4.4.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    6.547886] usb 1-1.4.4.4.1: Product: Quad RS232-HS
[    6.547902] usb 1-1.4.4.4.1: Manufacturer: FTDI
[    6.593675] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    6.596059] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[    6.596082] [vc_sm_connected_init]: start
[    6.598953] mc: Linux media interface: v0.10
[    6.610370] [vc_sm_connected_init]: installed successfully
[    6.636425] videodev: Linux video capture interface: v2.00
[    6.673348] usb 1-1.4.4.4.2: new full-speed USB device number 13 using xhci_hcd
[    6.676695] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    6.693075] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[    6.720826] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[    6.741259] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
[    6.742054] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[    6.742097] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[    6.751571] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[    6.751613] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[    6.759274] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
[    6.759873] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
[    6.760480] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[    6.760524] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[    6.760672] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
[    6.761071] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
[    6.761096] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
[    6.761127] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
[    6.761155] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
[    6.761185] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
[    6.761411] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
[    6.804895] usb 1-1.4.4.4.2: not running at top speed; connect to a high speed hub
[    6.809149] usb 1-1.4.4.4.2: New USB device found, idVendor=0403, idProduct=6011, bcdDevice= 8.00
[    6.809170] usb 1-1.4.4.4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    6.809187] usb 1-1.4.4.4.2: Product: Quad RS232-HS
[    6.809214] usb 1-1.4.4.4.2: Manufacturer: FTDI
[    6.943419] usb 1-1.4.4.4.3: new full-speed USB device number 14 using xhci_hcd
[    6.966543] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 0
[    7.065346] usbcore: registered new interface driver usbserial_generic
[    7.065414] usbserial: USB Serial support registered for generic
[    7.070432] [drm] No displays found. Consider forcing hotplug if HDMI is attached
[    7.070561] vc4-drm gpu: bound fe600000.firmwarekms (ops vc4_fkms_ops [vc4])
[    7.076901] usbcore: registered new interface driver ftdi_sio
[    7.076990] usbserial: USB Serial support registered for FTDI USB Serial Device
[    7.077247] ftdi_sio 1-1.4.1:1.0: FTDI USB Serial Device converter detected
[    7.077409] usb 1-1.4.1: Detected FT4232H
[    7.085417] usb 1-1.4.1: FTDI USB Serial Device converter now attached to ttyUSB0
[    7.085745] ftdi_sio 1-1.4.1:1.1: FTDI USB Serial Device converter detected
[    7.085922] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    7.085937] [drm] No driver support for vblank timestamp query.
[    7.085941] usb 1-1.4.1: Detected FT4232H
[    7.085950] [drm] Setting vblank_disable_immediate to false because get_vblank_timestamp == NULL
[    7.086537] [drm] Initialized vc4 0.0.0 20140616 for gpu on minor 1
[    7.087722] usb 1-1.4.4.4.3: not running at top speed; connect to a high speed hub
[    7.087933] usb 1-1.4.1: FTDI USB Serial Device converter now attached to ttyUSB1
[    7.088238] ftdi_sio 1-1.4.1:1.2: FTDI USB Serial Device converter detected
[    7.088423] usb 1-1.4.1: Detected FT4232H
[    7.091176] usb 1-1.4.1: FTDI USB Serial Device converter now attached to ttyUSB2
[    7.091448] ftdi_sio 1-1.4.1:1.3: FTDI USB Serial Device converter detected
[    7.091601] usb 1-1.4.1: Detected FT4232H
[    7.104406] usb 1-1.4.1: FTDI USB Serial Device converter now attached to ttyUSB3
[    7.104704] ftdi_sio 1-1.4.2:1.0: FTDI USB Serial Device converter detected
[    7.104877] usb 1-1.4.2: Detected FT4232H
[    7.105189] usb 1-1.4.4.4.3: New USB device found, idVendor=0403, idProduct=6011, bcdDevice= 8.00
[    7.105209] usb 1-1.4.4.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    7.105227] usb 1-1.4.4.4.3: Product: Quad RS232-HS
[    7.105243] usb 1-1.4.4.4.3: Manufacturer: FTDI
[    7.106996] usb 1-1.4.2: FTDI USB Serial Device converter now attached to ttyUSB4
[    7.107288] ftdi_sio 1-1.4.2:1.1: FTDI USB Serial Device converter detected
[    7.107530] usb 1-1.4.2: Detected FT4232H
[    7.109624] usb 1-1.4.2: FTDI USB Serial Device converter now attached to ttyUSB5
[    7.109885] ftdi_sio 1-1.4.2:1.2: FTDI USB Serial Device converter detected
[    7.110038] usb 1-1.4.2: Detected FT4232H
[    7.112909] usb 1-1.4.2: FTDI USB Serial Device converter now attached to ttyUSB6
[    7.113188] ftdi_sio 1-1.4.2:1.3: FTDI USB Serial Device converter detected
[    7.113449] usb 1-1.4.2: Detected FT4232H
[    7.116753] usb 1-1.4.2: FTDI USB Serial Device converter now attached to ttyUSB7
[    7.117454] ftdi_sio 1-1.4.3:1.0: FTDI USB Serial Device converter detected
[    7.117972] usb 1-1.4.3: Detected FT4232H
[    7.122508] usb 1-1.4.3: FTDI USB Serial Device converter now attached to ttyUSB8
[    7.122653] ftdi_sio 1-1.4.4.4.3:1.0: FTDI USB Serial Device converter detected
[    7.122760] ftdi_sio 1-1.4.3:1.1: FTDI USB Serial Device converter detected
[    7.122832] usb 1-1.4.4.4.3: Detected FT4232H
[    7.122944] usb 1-1.4.3: Detected FT4232H
[    7.125636] usb 1-1.4.3: FTDI USB Serial Device converter now attached to ttyUSB10
[    7.125893] ftdi_sio 1-1.4.3:1.2: FTDI USB Serial Device converter detected
[    7.126054] usb 1-1.4.3: Detected FT4232H
[    7.127929] usb 1-1.4.4.4.3: FTDI USB Serial Device converter now attached to ttyUSB9
[    7.128645] usb 1-1.4.3: FTDI USB Serial Device converter now attached to ttyUSB11
[    7.128896] ftdi_sio 1-1.4.3:1.3: FTDI USB Serial Device converter detected
[    7.129044] usb 1-1.4.3: Detected FT4232H
[    7.130643] ftdi_sio 1-1.4.4.4.3:1.1: FTDI USB Serial Device converter detected
[    7.130808] usb 1-1.4.4.4.3: Detected FT4232H
[    7.133202] usb 1-1.4.3: FTDI USB Serial Device converter now attached to ttyUSB12
[    7.133574] ftdi_sio 1-1.4.4.1:1.0: FTDI USB Serial Device converter detected
[    7.133746] usb 1-1.4.4.1: Detected FT4232H
[    7.134191] usb 1-1.4.4.4.3: FTDI USB Serial Device converter now attached to ttyUSB13
[    7.136403] usb 1-1.4.4.1: FTDI USB Serial Device converter now attached to ttyUSB14
[    7.136618] ftdi_sio 1-1.4.4.4.3:1.2: FTDI USB Serial Device converter detected
[    7.136694] ftdi_sio 1-1.4.4.1:1.1: FTDI USB Serial Device converter detected
[    7.136790] usb 1-1.4.4.4.3: Detected FT4232H
[    7.136858] usb 1-1.4.4.1: Detected FT4232H
[    7.139760] usb 1-1.4.4.1: FTDI USB Serial Device converter now attached to ttyUSB16
[    7.139918] usb 1-1.4.4.4.3: FTDI USB Serial Device converter now attached to ttyUSB15
[    7.140043] ftdi_sio 1-1.4.4.1:1.2: FTDI USB Serial Device converter detected
[    7.140213] usb 1-1.4.4.1: Detected FT4232H
[    7.142657] ftdi_sio 1-1.4.4.4.3:1.3: FTDI USB Serial Device converter detected
[    7.142836] usb 1-1.4.4.4.3: Detected FT4232H
[    7.143010] usb 1-1.4.4.1: FTDI USB Serial Device converter now attached to ttyUSB17
[    7.143426] ftdi_sio 1-1.4.4.1:1.3: FTDI USB Serial Device converter detected
[    7.143618] usb 1-1.4.4.1: Detected FT4232H
[    7.147970] usb 1-1.4.4.1: FTDI USB Serial Device converter now attached to ttyUSB19
[    7.147991] usb 1-1.4.4.4.3: FTDI USB Serial Device converter now attached to ttyUSB18
[    7.148228] ftdi_sio 1-1.4.4.2:1.0: FTDI USB Serial Device converter detected
[    7.148411] usb 1-1.4.4.2: Detected FT4232H
[    7.150290] usb 1-1.4.4.2: FTDI USB Serial Device converter now attached to ttyUSB20
[    7.150556] ftdi_sio 1-1.4.4.2:1.1: FTDI USB Serial Device converter detected
[    7.150712] usb 1-1.4.4.2: Detected FT4232H
[    7.153692] usb 1-1.4.4.2: FTDI USB Serial Device converter now attached to ttyUSB21
[    7.153961] ftdi_sio 1-1.4.4.2:1.2: FTDI USB Serial Device converter detected
[    7.154135] usb 1-1.4.4.2: Detected FT4232H
[    7.156816] usb 1-1.4.4.2: FTDI USB Serial Device converter now attached to ttyUSB22
[    7.157116] ftdi_sio 1-1.4.4.2:1.3: FTDI USB Serial Device converter detected
[    7.157313] usb 1-1.4.4.2: Detected FT4232H
[    7.160076] usb 1-1.4.4.2: FTDI USB Serial Device converter now attached to ttyUSB23
[    7.160338] ftdi_sio 1-1.4.4.3:1.0: FTDI USB Serial Device converter detected
[    7.160507] usb 1-1.4.4.3: Detected FT4232H
[    7.162181] usb 1-1.4.4.3: FTDI USB Serial Device converter now attached to ttyUSB24
[    7.162466] ftdi_sio 1-1.4.4.3:1.1: FTDI USB Serial Device converter detected
[    7.162637] usb 1-1.4.4.3: Detected FT4232H
[    7.165480] usb 1-1.4.4.3: FTDI USB Serial Device converter now attached to ttyUSB25
[    7.165752] ftdi_sio 1-1.4.4.3:1.2: FTDI USB Serial Device converter detected
[    7.165914] usb 1-1.4.4.3: Detected FT4232H
[    7.172166] usb 1-1.4.4.3: FTDI USB Serial Device converter now attached to ttyUSB26
[    7.172472] ftdi_sio 1-1.4.4.3:1.3: FTDI USB Serial Device converter detected
[    7.172702] usb 1-1.4.4.3: Detected FT4232H
[    7.175881] usb 1-1.4.4.3: FTDI USB Serial Device converter now attached to ttyUSB27
[    7.176210] ftdi_sio 1-1.4.4.4.1:1.0: FTDI USB Serial Device converter detected
[    7.176391] usb 1-1.4.4.4.1: Detected FT4232H
[    7.178962] usb 1-1.4.4.4.1: FTDI USB Serial Device converter now attached to ttyUSB28
[    7.179235] ftdi_sio 1-1.4.4.4.1:1.1: FTDI USB Serial Device converter detected
[    7.179397] usb 1-1.4.4.4.1: Detected FT4232H
[    7.182197] usb 1-1.4.4.4.1: FTDI USB Serial Device converter now attached to ttyUSB29
[    7.182503] ftdi_sio 1-1.4.4.4.1:1.2: FTDI USB Serial Device converter detected
[    7.182685] usb 1-1.4.4.4.1: Detected FT4232H
[    7.187519] usb 1-1.4.4.4.1: FTDI USB Serial Device converter now attached to ttyUSB30
[    7.187794] ftdi_sio 1-1.4.4.4.1:1.3: FTDI USB Serial Device converter detected
[    7.187960] usb 1-1.4.4.4.1: Detected FT4232H
[    7.190744] usb 1-1.4.4.4.1: FTDI USB Serial Device converter now attached to ttyUSB31
[    7.191026] ftdi_sio 1-1.4.4.4.2:1.0: FTDI USB Serial Device converter detected
[    7.191213] usb 1-1.4.4.4.2: Detected FT4232H
[    7.194206] usb 1-1.4.4.4.2: FTDI USB Serial Device converter now attached to ttyUSB32
[    7.194533] ftdi_sio 1-1.4.4.4.2:1.1: FTDI USB Serial Device converter detected
[    7.194738] usb 1-1.4.4.4.2: Detected FT4232H
[    7.197445] usb 1-1.4.4.4.2: FTDI USB Serial Device converter now attached to ttyUSB33
[    7.197746] ftdi_sio 1-1.4.4.4.2:1.2: FTDI USB Serial Device converter detected
[    7.197909] usb 1-1.4.4.4.2: Detected FT4232H
[    7.200707] usb 1-1.4.4.4.2: FTDI USB Serial Device converter now attached to ttyUSB34
[    7.200978] ftdi_sio 1-1.4.4.4.2:1.3: FTDI USB Serial Device converter detected
[    7.201143] usb 1-1.4.4.4.2: Detected FT4232H
[    7.204269] usb 1-1.4.4.4.2: FTDI USB Serial Device converter now attached to ttyUSB35
[    7.243408] usb 1-1.4.4.4.4: new full-speed USB device number 15 using xhci_hcd
[    7.377509] usb 1-1.4.4.4.4: New USB device found, idVendor=0451, idProduct=2046, bcdDevice= 1.25
[    7.377530] usb 1-1.4.4.4.4: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    7.383610] hub 1-1.4.4.4.4:1.0: USB hub found
[    7.384985] hub 1-1.4.4.4.4:1.0: 4 ports detected
[    7.703356] usb 1-1.4.4.4.4.1: new full-speed USB device number 16 using xhci_hcd
[    7.836888] usb 1-1.4.4.4.4.1: not running at top speed; connect to a high speed hub
[    7.857071] usb 1-1.4.4.4.4.1: New USB device found, idVendor=0403, idProduct=6011, bcdDevice= 8.00
[    7.857093] usb 1-1.4.4.4.4.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    7.857110] usb 1-1.4.4.4.4.1: Product: Quad RS232-HS
[    7.857126] usb 1-1.4.4.4.4.1: Manufacturer: FTDI
[    7.906560] ftdi_sio 1-1.4.4.4.4.1:1.0: FTDI USB Serial Device converter detected
[    7.906732] usb 1-1.4.4.4.4.1: Detected FT4232H
[    7.909866] usb 1-1.4.4.4.4.1: FTDI USB Serial Device converter now attached to ttyUSB36
[    7.912530] ftdi_sio 1-1.4.4.4.4.1:1.1: FTDI USB Serial Device converter detected
[    7.912717] usb 1-1.4.4.4.4.1: Detected FT4232H
[    7.915797] usb 1-1.4.4.4.4.1: FTDI USB Serial Device converter now attached to ttyUSB37
[    7.918499] ftdi_sio 1-1.4.4.4.4.1:1.2: FTDI USB Serial Device converter detected
[    7.918665] usb 1-1.4.4.4.4.1: Detected FT4232H
[    7.921769] usb 1-1.4.4.4.4.1: FTDI USB Serial Device converter now attached to ttyUSB38
[    7.925421] ftdi_sio 1-1.4.4.4.4.1:1.3: FTDI USB Serial Device converter detected
[    7.925727] usb 1-1.4.4.4.4.1: Detected FT4232H
[    7.932057] usb 1-1.4.4.4.4.1: FTDI USB Serial Device converter now attached to ttyUSB39
[    8.033394] usb 1-1.4.4.4.4.2: new full-speed USB device number 17 using xhci_hcd
[    8.164835] usb 1-1.4.4.4.4.2: not running at top speed; connect to a high speed hub
[    8.169107] usb 1-1.4.4.4.4.2: New USB device found, idVendor=0403, idProduct=6011, bcdDevice= 8.00
[    8.169127] usb 1-1.4.4.4.4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    8.169143] usb 1-1.4.4.4.4.2: Product: Quad RS232-HS
[    8.169159] usb 1-1.4.4.4.4.2: Manufacturer: FTDI
[    8.210675] ftdi_sio 1-1.4.4.4.4.2:1.0: FTDI USB Serial Device converter detected
[    8.210861] usb 1-1.4.4.4.4.2: Detected FT4232H
[    8.218414] usb 1-1.4.4.4.4.2: FTDI USB Serial Device converter now attached to ttyUSB40
[    8.220683] ftdi_sio 1-1.4.4.4.4.2:1.1: FTDI USB Serial Device converter detected
[    8.220847] usb 1-1.4.4.4.4.2: Detected FT4232H
[    8.231254] usb 1-1.4.4.4.4.2: FTDI USB Serial Device converter now attached to ttyUSB41
[    8.232667] ftdi_sio 1-1.4.4.4.4.2:1.2: FTDI USB Serial Device converter detected
[    8.232837] usb 1-1.4.4.4.4.2: Detected FT4232H
[    8.235957] usb 1-1.4.4.4.4.2: FTDI USB Serial Device converter now attached to ttyUSB42
[    8.238690] ftdi_sio 1-1.4.4.4.4.2:1.3: FTDI USB Serial Device converter detected
[    8.238853] usb 1-1.4.4.4.4.2: Detected FT4232H
[    8.241963] usb 1-1.4.4.4.4.2: FTDI USB Serial Device converter now attached to ttyUSB43
[    8.343357] usb 1-1.4.4.4.4.3: new full-speed USB device number 18 using xhci_hcd
[    8.474889] usb 1-1.4.4.4.4.3: not running at top speed; connect to a high speed hub
[    8.479139] usb 1-1.4.4.4.4.3: New USB device found, idVendor=0403, idProduct=6011, bcdDevice= 8.00
[    8.479159] usb 1-1.4.4.4.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    8.479176] usb 1-1.4.4.4.4.3: Product: Quad RS232-HS
[    8.479192] usb 1-1.4.4.4.4.3: Manufacturer: FTDI
[    8.502581] ftdi_sio 1-1.4.4.4.4.3:1.0: FTDI USB Serial Device converter detected
[    8.502748] usb 1-1.4.4.4.4.3: Detected FT4232H
[    8.509920] usb 1-1.4.4.4.4.3: FTDI USB Serial Device converter now attached to ttyUSB44
[    8.512593] ftdi_sio 1-1.4.4.4.4.3:1.1: FTDI USB Serial Device converter detected
[    8.512794] usb 1-1.4.4.4.4.3: Detected FT4232H
[    8.521936] usb 1-1.4.4.4.4.3: FTDI USB Serial Device converter now attached to ttyUSB45
[    8.525670] ftdi_sio 1-1.4.4.4.4.3:1.2: FTDI USB Serial Device converter detected
[    8.525854] usb 1-1.4.4.4.4.3: Detected FT4232H
[    8.527867] usb 1-1.4.4.4.4.3: FTDI USB Serial Device converter now attached to ttyUSB46
[    8.530592] ftdi_sio 1-1.4.4.4.4.3:1.3: FTDI USB Serial Device converter detected
[    8.530770] usb 1-1.4.4.4.4.3: Detected FT4232H
[    8.543409] usb 1-1.4.4.4.4.3: FTDI USB Serial Device converter now attached to ttyUSB47
[   14.384353] random: crng init done
[   14.384375] random: 7 urandom warning(s) missed due to ratelimiting
[   14.934939] 8021q: 802.1Q VLAN Support v1.8
[   15.078601] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[   15.141105] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[   15.188851] bcmgenet: Skipping UMAC reset
[   15.190536] bcmgenet fd580000.ethernet: configuring instance for external RGMII
[   15.190751] bcmgenet fd580000.ethernet eth0: Link is Down
[   20.393488] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
[   20.393537] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
$ lsusb -t
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 5000M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/1p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M
        |__ Port 4: Dev 3, If 0, Class=Hub, Driver=hub/4p, 12M
            |__ Port 1: Dev 4, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 1: Dev 4, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 1: Dev 4, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 1: Dev 4, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 2: Dev 5, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 2: Dev 5, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 2: Dev 5, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 2: Dev 5, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 6, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 6, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 6, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 6, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 4: Dev 7, If 0, Class=Hub, Driver=hub/4p, 12M
                |__ Port 1: Dev 8, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                |__ Port 1: Dev 8, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                |__ Port 1: Dev 8, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                |__ Port 1: Dev 8, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                |__ Port 2: Dev 9, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                |__ Port 2: Dev 9, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                |__ Port 2: Dev 9, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                |__ Port 2: Dev 9, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                |__ Port 3: Dev 10, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                |__ Port 3: Dev 10, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                |__ Port 3: Dev 10, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                |__ Port 3: Dev 10, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                |__ Port 4: Dev 11, If 0, Class=Hub, Driver=hub/4p, 12M
                    |__ Port 3: Dev 14, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                    |__ Port 3: Dev 14, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                    |__ Port 3: Dev 14, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                    |__ Port 3: Dev 14, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                    |__ Port 1: Dev 12, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                    |__ Port 1: Dev 12, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                    |__ Port 1: Dev 12, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                    |__ Port 1: Dev 12, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                    |__ Port 4: Dev 15, If 0, Class=Hub, Driver=hub/4p, 12M
                        |__ Port 3: Dev 18, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                        |__ Port 3: Dev 18, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                        |__ Port 3: Dev 18, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                        |__ Port 3: Dev 18, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                        |__ Port 1: Dev 16, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                        |__ Port 1: Dev 16, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                        |__ Port 1: Dev 16, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                        |__ Port 1: Dev 16, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                        |__ Port 2: Dev 17, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                        |__ Port 2: Dev 17, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                        |__ Port 2: Dev 17, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                        |__ Port 2: Dev 17, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                    |__ Port 2: Dev 13, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                    |__ Port 2: Dev 13, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                    |__ Port 2: Dev 13, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
                    |__ Port 2: Dev 13, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
P33M commented 3 years ago

The first device in this huge chain is a TUSB2046 hub - which is running at full speed. All downstream devices have messages similar to usb 1-1.4.4.4.4.2: not running at top speed; connect to a high speed hub. Why is the first external hub in the chain at full-speed? This limits the entire bus segment to 12mbit/s, and in practice the useable bandwidth will be even lower because of the vast numbers of endpoints that will be active (i.e. polled regularly).

r-schmidt commented 3 years ago

The TUSB2046B only supports full speed. So it is to be expected that it only runs at 12 MBit/s. The 48 serial ports running at 115200 kBit/s would in total need 5529600 kBit/s. That is less than half of the gross USB speed so there is still more than 50% left for the USB overhead. And the crash happens even when there is nothing actually transmitting or receiving on those ports.

Also as I wrote in the bug report, the crash doesn't happen when the serial port chain is connected to my notebook. So it is something specific to the Raspi.

P33M commented 3 years ago

Weird hardware design decisions aside, the controller is crashing - not the kernel. The clue is

[ 115.025783] pcieport 0000:00:00.0: AER: PCIe Bus Error: severity=Uncorrected (Non-Fatal), type=Transaction Layer, (Requester ID)
[ 115.046856] pcieport 0000:00:00.0: AER: device [14e4:2711] error status/mask=00004000/00000000
[ 115.058368] pcieport 0000:00:00.0: AER: [14] CmpltTO (First)

Which is the root complex timing out on a read transaction.

It'll probably be easier/cheaper to buy a boatload of FT4232H adapters to replicate the issue rather than try and source this specialist hardware.

r-schmidt commented 3 years ago

So the VL805 connected to the PCIe bridge crashes or enters a state that isn't handled? I'm actually surprised to learn that this USB controller has a firmware. As a firmware developer myself I know how often limits in there are not properly checked because "that can never happen"...

You can't simply buy this HW, you would have to build it yourself, it is open hardware. And one of the reasons to use a full speed hub chip (aside from the simpler board layout) is probably that the chances of getting high speed USB reliably across pin connectors are low.

So yes, buying 9 FT4232H adapters (e.g. Digitus DA-70159) and a few switches is the only other way to replicate it. Still quite the investment, though. But definitely faster than getting the PCBs produced and assembled. I'm happy to do whatever is needed to debug this. Though that has to wait until after New Years.

P33M commented 3 years ago

The fact that a read returned a completion timeout indicates an access to one of the xhci controller registers (nominally hardware) failed.

It's not clear what the interaction is between the firmware and controller hardware in this case. We know it has supervisory functions and can e.g. write to power state control registers inside the PCIe endpoint based on controller activity, but any clarification would have to come from VIA.

r-schmidt commented 3 years ago

To eliminate the HUB daisy chain as the cause for the issue I split the 48 ports into 4x12 ports and connected 3 of those so the USB tree looked like this:

/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 5000M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/1p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M
        |__ Port 1: Dev 7, If 0, Class=Hub, Driver=hub/4p, 12M
            |__ Port 2: Dev 9, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 2: Dev 9, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 2: Dev 9, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 2: Dev 9, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 10, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 10, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 10, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 10, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 1: Dev 8, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 1: Dev 8, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 1: Dev 8, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 1: Dev 8, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
        |__ Port 3: Dev 11, If 0, Class=Hub, Driver=hub/4p, 12M
            |__ Port 1: Dev 12, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 1: Dev 12, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 1: Dev 12, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 1: Dev 12, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 2: Dev 13, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 2: Dev 13, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 2: Dev 13, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 2: Dev 13, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 14, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 14, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 14, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 14, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
        |__ Port 4: Dev 3, If 0, Class=Hub, Driver=hub/4p, 12M
            |__ Port 2: Dev 5, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 2: Dev 5, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 2: Dev 5, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 2: Dev 5, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 6, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 6, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 6, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 3: Dev 6, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 1: Dev 4, If 2, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 1: Dev 4, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 1: Dev 4, If 3, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
            |__ Port 1: Dev 4, If 1, Class=Vendor Specific Class, Driver=ftdi_sio, 12M

The result was the same, with the 35th serial connection opened, the kernel driver prints errors and the system is unresponsive.

I then tested with a Rpi 1 (with some rather old Linux on it) and there it was working with the full 48 port chain, pretty slow but at least no hangs or crash.

Thinking that the Rpi 3B+ had a similar USB layout to the Rpi 1 (i.e. no PCIe device) I tried that one and the result was even worse than with the Rpi 4. The Rpi 3B+ silently hangs after about 10-20 seconds after connecting the chain. The only indication of a problem was in dmesg before the system got unresponsive:

[ 2029.999363] usb 1-1.2.4.4.3: Detected FT4232H
[ 2030.010073] usb 1-1.2.4.4.3: FTDI USB Serial Device converter now attached to ttyUSB35
[ 2030.109891] usb 1-1.2.4.4.4: new full-speed USB device number 44 using dwc_otg
[ 2030.241726] usb 1-1.2.4.4.4: New USB device found, idVendor=0451, idProduct=2046, bcdDevice= 1.25
[ 2030.241742] usb 1-1.2.4.4.4: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 2030.242544] hub 1-1.2.4.4.4:1.0: USB hub found
[ 2030.243091] hub 1-1.2.4.4.4:1.0: 4 ports detected
[ 2030.559810] usb 1-1.2.4.4.4.1: new full-speed USB device number 45 using dwc_otg
[ 2030.690575] usb 1-1.2.4.4.4.1: not running at top speed; connect to a high speed hub
[ 2030.693822] usb 1-1.2.4.4.4.1: New USB device found, idVendor=0403, idProduct=6011, bcdDevice= 8.00
[ 2030.693831] usb 1-1.2.4.4.4.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 2030.693838] usb 1-1.2.4.4.4.1: Product: Quad RS232-HS
[ 2030.693844] usb 1-1.2.4.4.4.1: Manufacturer: FTDI
[ 2030.694943] ftdi_sio 1-1.2.4.4.4.1:1.0: FTDI USB Serial Device converter detected
[ 2030.695052] usb 1-1.2.4.4.4.1: Detected FT4232H

[ 2030.695194] ERROR::assign_and_init_hc:1440: assign_and_init_hc: Failed to allocate memory to handle non-dword aligned buffer case

[ 2035.760273] WARN::dwc_otg_hcd_urb_dequeue:639: Timed out waiting for FSM NP transfer to complete on 3
[ 2035.760311] ftdi_sio ttyUSB36: Unable to read latency timer: -110

[ 2040.800272] WARN::dwc_otg_hcd_urb_dequeue:639: Timed out waiting for FSM NP transfer to complete on 7
[ 2040.800299] ftdi_sio ttyUSB36: Unable to write latency timer: -110
[ 2040.800546] usb 1-1.2.4.4.4.1: FTDI USB Serial Device converter now attached to ttyUSB36

[ 2045.840247] WARN::dwc_otg_hcd_urb_dequeue:639: Timed out waiting for FSM NP transfer to complete on 0

[ 2050.880318] WARN::dwc_otg_hcd_urb_dequeue:639: Timed out waiting for FSM NP transfer to complete on 5
[ 2050.880642] ftdi_sio 1-1.2.4.4.4.1:1.1: FTDI USB Serial Device converter detected
[ 2050.880847] usb 1-1.2.4.4.4.1: Detected FT4232H

Reducing the chain to 36 ports everything was fine on the Rpi3B+. Trying to attach the last 12 ports separately again triggered the memory allocation error. After some searching the solution was simple: Adding _coherentpool=2M to cmdline.txt allows the use of all 48 ports on the Rpi3B+.