VLI firmware v2.0 - powersaving features enabled

[trejan]

The following command fixes it:

Code: Select all

sudo setpci -s 01:00.0 0xD4.B=0x41

You sure you're using the latest firmware? What version of the firmware are you using? There were severe throughput issues on the old versions but 000137ab should be okay. There is a slight performance penalty but not as bad as the early test version.

[iEvgeny]

You sure you're using the latest firmware?

Absolutely.

Code: Select all

pi@dev-onboard:~ $ sudo rpi-eeprom-update
BOOTLOADER: up-to-date
CURRENT: Tue 10 Sep 10:41:50 UTC 2019 (1568112110)
 LATEST: Tue 10 Sep 10:41:50 UTC 2019 (1568112110)
VL805: up-to-date
CURRENT: 000137ab
 LATEST: 000137ab

Also, the rollback to the firmware v00013701 fixes this problem.
I think the problem is connecting multiple cameras. If I lower the bandwidth requirements for the second camera by half, the devices will still not be able to work simultaneously.

[jdb]

Wierd. I would expect performance degradation (in the off-chance we've not explored some set of wakeup latency/servicing interval required by the cams) and not a complete failure.

Can you capture an xhci debug trace?

Code: Select all

sudo -s
cd /sys/kernel/debug/tracing
echo 1 > events/xhci-hcd/enable
[Plug device(s) in]
[Run the command that doesn't work as expected]
[Disconnect device]
cat trace > /home/pi/some-sensible-filename.txt

The trace is going to be large, so it may be better to upload somewhere like a github gist.

To clear a previous trace (events will still be enabled):

Code: Select all

# echo > /sys/kernel/debug/tracing/trace

Also, you may want to do this without any other USB devices attached. Keyboards and mice will generate dozens of events per second which is tedious to sift through.

[jdoscher]

The setpci command worked for me, and I had a similar issue with two 4K webcams getting throttled from USB3 to USB2. Directly connected, no hub, etc. My thread is here:
https://www.raspberrypi.org/forums/view ... 0#p1560660

[iEvgeny]

Wierd. I would expect performance degradation (in the off-chance we've not explored some set of wakeup latency/servicing interval required by the cams) and not a complete failure.

I don't think this is a complete failure. With reduced bandwidth requirements, I can sometimes capture individual frames. I believe that this is a strong degradation.

Can you capture an xhci debug trace?

I have prepared two traces for you:

1. Only what you asked for
2. Additionally called the setpci ...0x41 command before the end of the debug

[jdb]

Which model of webcam(s) do the traces correspond to?

Edit: the second trace only has a single active endpoint transferring data. Are both cameras being used/working?

Edit2: github truncated the trace. The raw download is complete.

[jdb]

In the case where it goes wrong, there are multiple successful transfers from both cameras and then it seems to fall apart:

Code: Select all

    <idle>-0     [000] d.h.   308.914257: xhci_handle_event: EVENT: TRB 000000001edc4890 status 'Short Packet' len 3060 slot 3 ep 3 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914261: xhci_handle_event: EVENT: TRB 000000001edc7100 status 'Short Packet' len 1588 slot 2 ep 5 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914265: xhci_handle_event: EVENT: TRB 000000001edc48a0 status 'Short Packet' len 3060 slot 3 ep 3 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914268: xhci_handle_event: EVENT: TRB 000000001edc7110 status 'Short Packet' len 1588 slot 2 ep 5 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914272: xhci_handle_event: EVENT: TRB 000000001edc48b0 status 'Short Packet' len 1532 slot 3 ep 3 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914276: xhci_handle_event: EVENT: TRB 000000001edc7120 status 'Short Packet' len 1588 slot 2 ep 5 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914280: xhci_handle_event: EVENT: TRB 000000001edc48c0 status 'Short Packet' len 652 slot 3 ep 3 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914283: xhci_handle_event: EVENT: TRB 000000001edc7130 status 'Short Packet' len 1588 slot 2 ep 5 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914287: xhci_handle_event: EVENT: TRB 000000001edc48d0 status 'Short Packet' len 596 slot 3 ep 3 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914291: xhci_handle_event: EVENT: TRB 0000000000000000 status 'Missed Service Error' len 0 slot 2 ep 5 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914293: xhci_handle_event: EVENT: TRB 000000001edc48e0 status 'Short Packet' len 1004 slot 3 ep 3 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914296: xhci_handle_event: EVENT: TRB 000000001edc7150 status 'Short Packet' len 1588 slot 2 ep 5 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914309: xhci_handle_event: EVENT: TRB 000000001edc48f0 status 'Short Packet' len 4 slot 3 ep 3 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914313: xhci_handle_event: EVENT: TRB 000000001edc7160 status 'Short Packet' len 1588 slot 2 ep 5 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914316: xhci_handle_event: EVENT: TRB 000000001edc4900 status 'USB Transaction Error' len 3072 slot 3 ep 3 type 'Transfer Event' flags e:c
          <idle>-0     [000] d.h.   308.914320: xhci_handle_event: EVENT: TRB 000000001edc7170 status 'USB Transaction Error' len 1600 slot 2 ep 5 type 'Transfer Event' flags e:c

Note the truncated packet lengths and then a "missed service error", followed by a dribble of more completed packets. After the first "USB transaction error" message appears, there are no further successful transfers from either endpoint.

In the broken state (i.e. after you've had a failure transferring data from both cameras), what's the state of the PCIe link? Please post the output of sudo lspci -vvv.

[iEvgeny]

Which model of webcam(s) do the traces correspond to?

1. First Cam (AliExpress No Name)
2. Second Cam (AliExpress No Name)

Unfortunately, the camera microcontroller does not have markings: https://imgur.com/lJNM3UA

Please post the output of sudo lspci -vvv.

Command output stdout+stderr

[jdb]

Troubleshooting noname USB webcams isn't going to be possible - unless there's a generic issue with the transport protocol in question.

Command output stdout+stderr

That's not the output of the lspci command. It does however confirm that both cameras are UVC compliant devices so it should be reproducible with two other ones.

[iEvgeny]

Sorry...

Code: Select all

$ sudo lspci -vvv          
00:00.0 PCI bridge: Broadcom Limited Device 2711 (rev 10) (prog-if 00 [Normal decode])
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B- DisINTx-
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0, Cache Line Size: 64 bytes
        Interrupt: pin A routed to IRQ 53
        Bus: primary=00, secondary=01, subordinate=01, sec-latency=0
        I/O behind bridge: 00000000-00000fff
        Memory behind bridge: f8000000-f80fffff
        Prefetchable memory behind bridge: 00000000fff00000-00000000000fffff
        Secondary status: 66MHz- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- <SERR- <PERR-
        BridgeCtl: Parity+ SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
                PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
        Capabilities: [48] Power Management version 3
                Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold-)
                Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=1 PME-
        Capabilities: [ac] Express (v2) Root Port (Slot-), MSI 00
                DevCap: MaxPayload 512 bytes, PhantFunc 0
                        ExtTag- RBE+
                DevCtl: Report errors: Correctable+ Non-Fatal+ Fatal+ Unsupported+
                        RlxdOrd+ ExtTag- PhantFunc- AuxPwr+ NoSnoop+
                        MaxPayload 128 bytes, MaxReadReq 512 bytes
                DevSta: CorrErr- UncorrErr- FatalErr- UnsuppReq- AuxPwr- TransPend-
                LnkCap: Port #0, Speed 5GT/s, Width x1, ASPM L0s L1, Exit Latency L0s <2us, L1 <4us
                        ClockPM+ Surprise- LLActRep- BwNot+ ASPMOptComp+
                LnkCtl: ASPM Disabled; RCB 64 bytes Disabled- CommClk-
                        ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
                LnkSta: Speed 5GT/s, Width x1, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt+
                RootCtl: ErrCorrectable- ErrNon-Fatal- ErrFatal- PMEIntEna+ CRSVisible+
                RootCap: CRSVisible+
                RootSta: PME ReqID 0000, PMEStatus- PMEPending-
                DevCap2: Completion Timeout: Range ABCD, TimeoutDis+, LTR+, OBFF Via WAKE# ARIFwd-
                DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled ARIFwd-
                LnkCtl2: Target Link Speed: 5GT/s, EnterCompliance- SpeedDis-
                         Transmit Margin: Normal Operating Range, EnterModifiedCompliance- ComplianceSOS-
                         Compliance De-emphasis: -6dB
                LnkSta2: Current De-emphasis Level: -6dB, EqualizationComplete-, EqualizationPhase1-
                         EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest-
        Capabilities: [100 v1] Advanced Error Reporting
                UESta:  DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
                UEMsk:  DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
                UESvrt: DLP+ SDES+ TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt- RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
                CESta:  RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr-
                CEMsk:  RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr+
                AERCap: First Error Pointer: 00, GenCap- CGenEn- ChkCap- ChkEn-
        Capabilities: [180 v1] Vendor Specific Information: ID=0000 Rev=0 Len=028 <?>
        Capabilities: [240 v1] L1 PM Substates
                L1SubCap: PCI-PM_L1.2+ PCI-PM_L1.1+ ASPM_L1.2+ ASPM_L1.1+ L1_PM_Substates+
                          PortCommonModeRestoreTime=8us PortTPowerOnTime=10us
                L1SubCtl1: PCI-PM_L1.2- PCI-PM_L1.1- ASPM_L1.2- ASPM_L1.1-
                           T_CommonMode=1us LTR1.2_Threshold=0ns
                L1SubCtl2: T_PwrOn=10us
        Kernel driver in use: pcieport

01:00.0 USB controller: VIA Technologies, Inc. VL805 USB 3.0 Host Controller (rev 01) (prog-if 30 [XHCI])
        Subsystem: VIA Technologies, Inc. VL805 USB 3.0 Host Controller
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B- DisINTx+
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0, Cache Line Size: 64 bytes
        Interrupt: pin A routed to IRQ 54
        Region 0: Memory at 600000000 (64-bit, non-prefetchable) [size=4K]
        Capabilities: [80] Power Management version 3
                Flags: PMEClk- DSI- D1- D2- AuxCurrent=375mA PME(D0+,D1-,D2-,D3hot-,D3cold+)
                Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME-
        Capabilities: [90] MSI: Enable+ Count=1/4 Maskable- 64bit+
                Address: 0000000ffffffffc  Data: 6540
        Capabilities: [c4] Express (v2) Endpoint, MSI 00
                DevCap: MaxPayload 256 bytes, PhantFunc 0, Latency L0s <64ns, L1 <1us
                        ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset- SlotPowerLimit 0.000W
                DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported-
                        RlxdOrd+ ExtTag- PhantFunc- AuxPwr- NoSnoop+
                        MaxPayload 128 bytes, MaxReadReq 512 bytes
                DevSta: CorrErr- UncorrErr- FatalErr- UnsuppReq- AuxPwr+ TransPend-
                LnkCap: Port #0, Speed 5GT/s, Width x1, ASPM L0s L1, Exit Latency L0s <2us, L1 <16us
                        ClockPM+ Surprise- LLActRep- BwNot- ASPMOptComp-
                LnkCtl: ASPM L0s L1 Enabled; RCB 64 bytes Disabled- CommClk+
                        ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
                LnkSta: Speed 5GT/s, Width x1, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
                DevCap2: Completion Timeout: Range B, TimeoutDis+, LTR-, OBFF Not Supported
                DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled
                LnkCtl2: Target Link Speed: 5GT/s, EnterCompliance- SpeedDis+
                         Transmit Margin: Normal Operating Range, EnterModifiedCompliance- ComplianceSOS-
                         Compliance De-emphasis: -6dB
                LnkSta2: Current De-emphasis Level: -3.5dB, EqualizationComplete-, EqualizationPhase1-
                         EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest-
        Capabilities: [100 v1] Advanced Error Reporting
                UESta:  DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
                UEMsk:  DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
                UESvrt: DLP+ SDES+ TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt- RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
                CESta:  RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr-
                CEMsk:  RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr+
                AERCap: First Error Pointer: 00, GenCap- CGenEn- ChkCap- ChkEn-
        Kernel driver in use: xhci_hcd

[wcndave]

I have not seen any posts saying what I am about to say, so I hope I've just done something wrong.... but I can't see what.

I have installed the "ab" version, exactly as per instructions:

Code: Select all

Pi4-LibreELEC:~ # ./vl805
VL805 FW version: 000137ab

The pi is now idling at 7 degrees hotter...

I have two USB devices plugged in, a keyboard, and a FLIRC.

Device is running LibreElec/Kodi, however idle, CPU is 90% idle.

With heatsink only, my temps increased from 64 to 71
with fan running at 50% PWM, temp increased from 49 to 58

Reverted to older version, idle temp now back to 64.

[PhilE]

It should go without saying, but that's not the expected behaviour. The flashing process includes a verification phase, but you can explicitly verify the EEPROM contents with "./vl805 -v vl805_fw_0137ab.bin" (which will need a "sudo" if you aren't already running as root).

[wcndave]

It should go without saying, but that's not the expected behaviour. The flashing process includes a verification phase, but you can explicitly verify the EEPROM contents with "./vl805 -v vl805_fw_0137ab.bin" (which will need a "sudo" if you aren't already running as root).

Yes, quite. I ran the verification, and get an all clear response:

Code: Select all

VL805 EEPROM data verified

[PhilE]

<insert expression of bafflement>

[jdb]

Does the same temperature rise happen with no USB devices plugged in?

[iEvgeny]

Troubleshooting noname USB webcams isn't going to be possible - unless there's a generic issue with the transport protocol in question.

Unfortunately, I do not have other information, but I still do not think that this is a problem with the cameras. These models were used by me on various devices without any problems. Including on Raspberry Pi 4 before updating the firmware...
A little later I will try to reproduce the problem with Logitech cameras.

[wcndave]

Does the same temperature rise happen with no USB devices plugged in?

Right, I tried it again, and a different (and better) result I think.

I was doing stress and cooling testing, when I came upon this update. I had an idle heatsink only temp of 64.
I did the FW update, and it jumped to 71 right there and then.
I did the reboot, which was fine, and it stayed at 71
I then installed the old FW, and it stayed at 71
I rebooted, and it went to 64 again....

However, whilst I was getting ready to test some python fan control stuff, and letting the temp settle at idle, it jumped to 71.
After doing all the fan testing, it idled back to about 68.

Now after FW update second time, I had the often mentioned problem of the reboot freezing, and after hard reboot it has in fact come back a few degrees cooler.

I have run the same services each time, and when I then rebooted again, it was yet another few degrees cooler.

Ambient temperature is static, so I don't know what's going on really....

However, given that I don't have the problem anymore, and that no one else reported it, I think we can put it down to "Eddie's in the space time continuum"....

BTW: is it correct that the Pi4 idles about 20 deg hotter than 3B+ ?
65 seems quite hot for an idle CPU.

[5ft24dave]

You said your idle temp increased when you added a heatsink. Some of those cheap heatsinks use regular double sided tape which is a good insulator for heat and they cause issues. You need to get either a good thermal adhesive pad, or thermal compound and a way to anchor the heatsink, otherwise these tests aren't really going to show anything close to normal

[5ft24dave]

Does the same temperature rise happen with no USB devices plugged in?

BTW: is it correct that the Pi4 idles about 20 deg hotter than 3B+ ?
65 seems quite hot for an idle CPU.

Not correct
My 3B+ with no heatsink in a 28 deg C room idles about 32 degrees. Pi4B next to it, again no heatsink, idles about 38 degrees

[pfletch101]

Not correct
My 3B+ with no heatsink in a 28 deg C room idles about 32 degrees. Pi4B next to it, again no heatsink, idles about 38 degrees

Both those temperatures seem very low, from my experience. How idle is idle? Is this running a standard Buster GUI with no I/O, running a bare bones CLI system with no I/O and minimal services, or shut down with power still connected?

[5ft24dave]

I run everything I have headless with a couple exceptions. So this is Buster light, all updates applied, powered on and booted.
My fun one is the Pi4B with the Ice Tower cooler. running the buster full plus extras image, remote desktop server running on it and BOINC with Seti@Home running 4 threads at 100%. With that cooler, in a 26 degree room, it idles at 28 Deg, and while running full tilt on the Seti threads, I go about 32 Deg C max LOL

[Paul Webster]

See a sub-thread in the firmware update discussions from someone with what might be the same issue
https://www.raspberrypi.org/forums/view ... 5#p1560515

[pfavr]

Hi,

Troubleshooting noname USB webcams isn't going to be possible - unless there's a generic issue with the transport protocol in question.

I have four Raspberry Pi 4 each with a Logitech BRIO 4K USB3 webcam attached.

They used to record 4K mjpeg streams using ffmpeg (to a file server) in full 3840x2160 resolution at 30 fps.

Using VL805 FW version: 000137ab the webcams were only able to do 1920x1080 resolution.

After downgrade using:

sudo vl805 -w /lib/firmware/raspberrypi/bootloader/beta/vl805-00013701.bin

4K worked again

Best regards,

Peter

[Serveurperso]

Hello

How to prevent VL805 from updating ? The last version kill performances and make my low latency system as an useless brick.
I must launch this after each apt upgrade + reboot
rpi-eeprom-update -u /lib/firmware/raspberrypi/bootloader/critical/vl805-00013701.bin

Thanks
Pascal

EDIT : look like a performance issue on my software telemetry but it's more complex because I can't see the problem inside ffmpeg debug traces!

[iEvgeny]

Hi!

How to prevent VL805 from updating ?

Just try it:

Code: Select all

sudo setpci -s 01:00.0 0xD4.B=0x41