RPi 4B - USB issues with latest kernel

    Updated to latest nightly, rebooted ok, turned off tv for 3 hrs, turned tv back on, No signal.

    SSH "systemctl restart kodi" dosent help, only way to get it working is to pull the power and restart with the nightly from 25/9.

    My Banana Pi M5 with latest CoreELEC nightly still works fine on same tv.

    I tried to reproduce the issue a few days ago ,but i couldn't ,so i will try again asap.

    Did exactly what you did,shutdown the TV and after 3h powered on again....no problem .

    BTW ,my RPi4 is connected to a Soundbar which is connected to the TV via HDMI ARC.

    CEC is also enabled .

    Quote from Pretoriano

    I tried to reproduce the issue a few days ago ,but i couldn't ,so i will try again asap.

    Did exactly what you did,shutdown the TV and after 3h powered on again....no problem .

    BTW ,my RPi4 is connected to a Soundbar which is connected to the TV via HDMI ARC.

    CEC is also enabled .

    Mine is straight to tv, CEC disabled, booting from USB-connected SSD. When on nightly from 25/9 and before i can have tv shut off for days without any problems when turned on again.

    I'm also using a SSD for boot,but usually ,if there's an error with the USB crapping out,then you shouldn't be able to access the device thru SSH.

    That makes me think that your issue is different from the one reported by the OP.

    Best thing would be to enable debug logging before powering OFF your TV,then ,after the error occurs ,grab the logs (you can do it from the SSH with the "pastekodi" command ).

    Edited once, last by Pretoriano (October 20, 2022 at 7:13 PM).

    Quote from Pretoriano

    I'm also using a SSD for boot,but usually ,if there's an error with the USB crapping out,then you shouldn't be able to access the device thru SSH.

    That makes me think that your issue is different from the one reported by the OP.

    Best thing would be to enable debug logging before powering OFF your TV,then ,after the error occurs ,grab the logs (you can do it from the SSH with the "pastekodi" command ).

    SSH dosent do sh_t.

    I can connect but thats all.

    MatteN i tested this overnight and still no problem here,this morning LibreELEC/Kodi was still running fine.

    I will try to disable CEC and test again tonight (even if an USB issue should be triggered regardless ).

    LibreELEC-RPi4.arm-11.0-nightly-20220925-b1d73ad on for 40 hrs now with tv turned off most of the time (well over 30hrs) and no problems, newer nighly's renders "No signal" after tv is off for less than 3 hrs.

    But no logs from you so far...

    I'm trying to help,but if can't reproduce ,i can't get any useful logs.

    I don't know what relation might be between "TV OFF" and a USB failure ,it looks more related to HDMI or CEC (and that's what i'm trying to find).

    You said that CEC is disabled ,so try enabling that .

    Also ,you could try switching to a different HDMI port on Rpi4 .

    There's clearly a regression on the newer LE11 builds ,but without logs is almost impossible to find out what's wrong .

    Edited once, last by Pretoriano (October 25, 2022 at 12:16 PM).

    The same issue with LE 11 Nightly 20221022-7fb1002

    [101093.491670] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101095.625218] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101097.758675] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101099.892185] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101102.025683] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101104.159168] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101106.292724] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101108.426156] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101110.559630] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101112.693203] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101114.826629] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101116.960112] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101119.093620] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101121.227110] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101123.360567] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101125.494044] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101127.627568] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    [101129.761016] usb 1-1.4: dvb_usb_v2: usb_bulk_msg() failed=-110

    This issue makes the LiveTV unusable in my case. :(

    It happens most often after switching channel, often during Timeshift moving and sometimes completely randomly.

    ghtester how often it happens on your other configuration ,the one running from USB-SATA adapter ?

    I'm asking because i'm testing this ,but after 24h+ the system is still running fine.

    I don't have a DVB-T stick available ,but my system use a SSD (boot ) connected thru USB-SATA adapter (connected to USB3) and a Sonoff USB Dongle (Zigbee Coordinator) connected to USB2.

    Currently the second HW configuration works better, I think the last issue was encountered 9 days ago as reported here.

    In the meantime also the EEPROM on both RPi's was updated to 2022-10-12 release.

    It looks to me like the old issue with MyGica driver is back ( https://github.com/raspberrypi/linux/issues/3809 )...

    I'll try to swap DVB-T2 sticks between RPis to see if there's any change / if the issue transfers (despite it's more dangerous for the configuration which boots from USB ).

    I switched to LE11 as daily driver ,so i will let you know if this issue will occur at some point (the bad part about being a daily driver is that i can't keep the debugging always on).

    As a side note,regarding USB on Rpi4 ,I'm pretty sure i bumped into this several times -> https://github.com/raspberrypi/linux/issues/5192 <-- but in my case it was the other way around ,removing the Wi-Fi USB dongle caused a system freeze (using SSD as boot drive) .

    The same issue with LE 11 Nightly 20221113-ba9b18d with 6.08 kernel release.

    After swapping the DVB-T2 sticks between RPis the issue also moved to second RPi.

    So it really looks the old issue with MyGica driver is back ( https://github.com/raspberrypi/linux/issues/3809 )...


    [94294.049273] rpivid feb10000.codec: Missing DPB ent 0, timestamp=0, index=-1

    [94312.854527] rpivid feb10000.codec: rpivid_h265_stop

    [94330.842402] usb 1-1.2.3: dvb_usb_v2: 2nd usb_bulk_msg() failed=-110

    [94332.972344] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94335.105740] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94337.239067] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94339.372393] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94341.505730] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94343.639086] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94345.772448] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94347.905776] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94350.039089] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94352.172489] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94354.305851] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94356.439164] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94358.572524] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94360.705877] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94362.839322] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94364.972578] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94367.105931] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94369.239271] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94371.372633] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94373.505960] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94375.639354] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94377.772695] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94379.905980] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94382.039373] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94384.172775] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94386.306125] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94388.439421] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94390.572768] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94392.706116] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94394.839450] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94396.972827] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    [94399.106261] usb 1-1.2.3: dvb_usb_v2: usb_bulk_msg() failed=-110

    ....

    ....

    nightly-20221220-d479071

    :(

    [191629.143413] rpivid feb10000.codec: Missing DPB ent 1, timestamp=0

    [191629.160188] rpivid feb10000.codec: Missing DPB ent 1, timestamp=0

    [191629.176883] rpivid feb10000.codec: Missing DPB ent 1, timestamp=0

    [192927.110293] rpivid feb10000.codec: phase1_cb: Post wait: 0xffffffff

    [192927.127463] rpivid feb10000.codec: phase1_cb: Post wait: 0xffffffff

    [192927.143682] rpivid feb10000.codec: phase1_cb: Post wait: 0xffffffff

    [192954.847859] usb 1-1.2.3: dvb_usb_v2: rc.query() failed=-71

    [192955.061855] usb 1-1.2.3: USB disconnect, device number 6

    [192955.330633] r820t 23-003a: r820t_write: i2c wr failed=-19 reg=0c len=1: f1

    [192955.804693] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192956.804750] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192957.804824] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192958.804902] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192959.804977] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192960.805052] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192961.805232] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192962.805325] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192963.805666] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192964.805738] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192965.805815] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192966.805889] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192967.805969] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192968.806048] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192969.806428] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192970.806508] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192971.806590] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192972.806715] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192973.806822] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192974.806896] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192975.806946] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192976.807001] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192977.807072] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192978.807145] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192979.807222] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192980.807293] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192981.807364] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192982.807438] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192983.807510] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192984.807582] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192985.807666] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [192986.807740] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    ....

    ....

    .....

    .....

    [194046.890247] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [194047.890341] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [194048.890403] r820t 23-003a: r820t_read: i2c rd failed=-19 reg=00 len=4: f1 5d 7a 1f

    [194049.307364] r820t 23-003a: r820t_write: i2c wr failed=-19 reg=06 len=1: b1

    [194049.309619] r820t 23-003a: destroying instance

    [194049.312272] dvb_usb_v2: 'Astrometa DVB-T2:1-1.2.3' successfully deinitialized and disconnected

    [194049.538224] usb 1-1.2.3: new high-speed USB device number 8 using xhci_hcd

    [194049.541745] systemd-journald[310]: Data hash table of /run/log/journal/877ce4b44928576324bb64375caf6b34/system.journal has a fill level at 75.1 (1537 of 2047 items, 524288 file size, 341 bytes per hash table item), suggesting rotation.

    [194049.541768] systemd-journald[310]: /run/log/journal/877ce4b44928576324bb64375caf6b34/system.journal: Journal header limits reached or header out-of-date, rotating.

    [194049.655522] usb 1-1.2.3: New USB device found, idVendor=15f4, idProduct=0131, bcdDevice= 1.00

    [194049.655545] usb 1-1.2.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0

    [194049.655552] usb 1-1.2.3: Product: dvbt2

    [194049.655559] usb 1-1.2.3: Manufacturer: astrometadvbt2

    [194049.663486] usb 1-1.2.3: dvb_usb_v2: found a 'Astrometa DVB-T2' in warm state

    [194049.822230] usb 1-1.2.3: dvb_usb_v2: will pass the complete MPEG2 transport stream to the software demuxer

    [194049.822284] dvbdev: DVB: registering new adapter (Astrometa DVB-T2)

    [194049.822301] usb 1-1.2.3: media controller created

    [194049.823994] dvbdev: dvb_create_media_entity: media entity 'dvb-demux' registered.

    [194049.844763] i2c i2c-22: Added multiplexed i2c bus 23

    [194049.844798] rtl2832 22-0010: Realtek RTL2832 successfully attached

    [194049.854807] mn88473 22-0018: Panasonic MN88473 successfully identified

    [194049.854948] usb 1-1.2.3: DVB: registering adapter 5 frontend 0 (Realtek RTL2832 (DVB-T))...

    [194049.854984] dvbdev: dvb_create_media_entity: media entity 'Realtek RTL2832 (DVB-T)' registered.

    [194049.855275] usb 1-1.2.3: DVB: registering adapter 5 frontend 1 (Panasonic MN88473)...

    [194049.855299] dvbdev: dvb_create_media_entity: media entity 'Panasonic MN88473' registered.

    [194049.855489] r820t 23-003a: creating new instance

    [194049.862459] r820t 23-003a: Rafael Micro r820t successfully identified, chip type: R828D

    [194049.862520] r820t 23-003a: attaching existing instance

    [194049.867375] r820t 23-003a: Rafael Micro r820t successfully identified, chip type: R828D

    [194049.873534] rtl2832_sdr rtl2832_sdr.2.auto: Registered as swradio0

    [194049.873560] rtl2832_sdr rtl2832_sdr.2.auto: Realtek RTL2832 SDR attached

    [194049.873572] rtl2832_sdr rtl2832_sdr.2.auto: SDR API is still slightly experimental and functionality changes may follow

    [194049.884539] Registered IR keymap rc-astrometa-t2hybrid

    [194049.884684] rc rc2: Astrometa DVB-T2 as /devices/platform/scb/http://fd500000.pcie/pci0000:00/000…/1-1.2.3/rc/rc2

    [194049.884878] rc rc2: lirc_dev: driver dvb_usb_rtl28xxu registered at minor = 2, raw IR receiver, no transmitter

    [194049.885039] input: Astrometa DVB-T2 as /devices/platform/scb/http://fd500000.pcie/pci0000:00/000…3/rc/rc2/input4

    [194049.885380] usb 1-1.2.3: dvb_usb_v2: schedule remote query interval to 200 msecs

    [194049.893558] usb 1-1.2.3: dvb_usb_v2: 'Astrometa DVB-T2' successfully initialized and connected

    [194050.081504] input: eventlircd as /devices/virtual/input/input5

    [194054.133910] usb 1-1.2.3: DVB: adapter 5 frontend 0 frequency 0 out of range (174000000..862000000)

    [194054.738647] mn88473 22-0018: downloading firmware from file 'dvb-demod-mn88473-01.fw'

    [194055.380340] usb 1-1.2.3: DVB: adapter 5 frontend 1 frequency 0 out of range (42000000..1002000000)

    [194061.527528] rpivid feb10000.codec: Missing DPB ent 0, timestamp=0

    [194061.544059] rpivid feb10000.codec: Missing DPB ent 1, timestamp=0

    [194061.577107] rpivid feb10000.codec: Missing DPB ent 1, timestamp=0

    [194061.594200] rpivid feb10000.codec: Missing DPB ent 1, timestamp=0

    [194066.339629] rpivid feb10000.codec: Missing DPB ent 0, timestamp=0

    [194066.339657] rpivid feb10000.codec: Missing DPB ent for col

    [194066.339926] rpivid feb10000.codec: Missing DPB ent 1, timestamp=0

    [194066.340277] rpivid feb10000.codec: Missing DPB ent 1, timestamp=0

    [194066.340468] rpivid feb10000.codec: Missing DPB ent 1, timestamp=0

    [194083.848780] rpivid feb10000.codec: rpivid_h265_stop

    [194086.303269] rpivid feb10000.codec: rpivid_h265_start: (1024x544)

    [194086.306228] rpivid feb10000.codec: SPS changed

    [194086.306251] rpivid feb10000.codec: PPS changed