Fix lockups and IRQ jitter on multicore RasPis

[l1k]

Backport v5.7 commit bd59b34 to rpi-4.19.y to fix random lockups as well as jittery IRQ latency on multicore Raspberry Pis.

These issues are caused by the bootloader erroneously leaving the USB IRQ enabled. Once the FIQ-enabled USB driver probes, both the regular USB IRQ (on cpu0) as well as the USB FIQ (on cpu1) are enabled. Because no handler is registered for the regular USB IRQ, cpu0 spins upon a USB interrupt until cpu1 has handled it. This provokes a deadlock when cpu1 has temporarily disabled the FIQ and is trying to acquire a global lock which happens to be held by cpu0, which in turn is spinning in the IRQ handler waiting for cpu1 to handle the USB interrupt.

The bootloader still leaves the USB IRQ enabled in the latest version of raspberrypi-bootloader, which is 2020-06-01.

Please consider cherry-picking to rpi-5.4.y if/when merging. Thanks.

Cc: @naruxde

[pelwell]

That looks plausible - anything that prevents random stalls and lockup is a good thing.

Any thoughts or concerns, @P33M?

[P33M]

I'm slightly confused by the rationale - Linux is the first thing to run on the ARM complex, there is no "bootloader". The only things I can think of that would touch the ARM interrupt control registers before Linux booted are something like u-boot, a prior kernel before calling kexec or NOOBS. Alternatively if these registers are not reset by a watchdog reset, then a reboot would leave them in the bad state.

@i1k do you have evidence that FIQ and IRQ are simultaneously enabled for USB (e.g. by an error message from your patch)?

[popcornmix]

@P33M I think the arm stubs are considered the bootloader in linux kernel terms.
It does configure the GIC.

[pelwell]

I can attest that running rpi-5.7.y on an 3B+ you get:

[    0.000000] [Firmware Bug]: Bootloader left irq enabled: bank 1 irq 9

[pelwell]

And that was running from a cold power-on.

[popcornmix]

It may also be firmware doing stuff. What is bank 1 irq 9?

[P33M]

Firmware is indeed bugged - start.elf is fiddling with the ARM interrupt control block and unmasking the USB interrupt. We should probably stop it doing that.

[popcornmix]

Agreed - while this commit is worth having to tell us something's wrong, fixing the firmware to leave interrupts in expected state should be done as the real fix.

[pelwell]

@l1k Did you not think to create an issue in the firmware repo when you discovered this bug?

[l1k]

Thanks a lot guys for looking into this.

@pelwell: Sorry, no, I assume by firmware repo you mean https://github.com/RPi-Distro/firmware? The thought of creating an issue there didn't occur to me I'm afraid. I did cc you and @XECDesign however when submitting v1 of the patch to the mailing list back in February.

That initial version of the patch contains a more detailed rationale. I had to trim it in a later version to address an objection by @ffainelli of Broadcom. I apologize if the initial commit message comes across as snarky. The issue was nontrivial to debug due in part to the closed-source nature of the firmware. Though I suppose that may be a necessity caused by whatever agreements exist with Broadcom.

More background info is in the announcement in our forum.

Although the patch went into v5.7, it wasn't picked up by stable maintainers despite my explicit request, hence didn't automatically percolate down into rpi-4.19.y. Which necessitated the present pull. Thanks again.

[pelwell]

I was thinking of https://github.com/raspberrypi/firmware:

This repository contains pre-compiled binaries of the current Raspberry Pi kernel and modules, userspace libraries, and bootloader/GPU firmware.

Anyway, the patch is now in rpi-5.4.y and rpi-5.6.y as well.

[P33M]

I'm quite interested in the use-case that causes the deadlock. This has never to my knowledge been seen on downstream kernels, and we've got about 6 years worth of units in the field that were exposed to this bug.

[l1k]

Sorry for the delay @P33M.

One of our customers came up with a test script that repeated each of the following two commands 10 times:

stress --io 24 -t 2700
stress --cpu 4 --io 4 --vm 2 --vm-bytes 128M -t 2700

This exposed the deadlock on a portion of our devices, seemingly at random. I used the same commands when trying to reproduce the issue in our lab and additionally generated traffic to an attached USB flash stick. I was able to reproduce the issue within 2 or 3 days that way.

We apply the RT patch set on top of the Foundation's downstream kernel and it's possible that the deadlock occurs only or more easily on an RT kernel, but I doubt it.

I only reproduced the issue twice because that was already sufficient to root-cause it.

The first time I reproduced it, cpu2 and cpu3 were busy with the stress program. cpu0 was busy in ktimersoftd/0 with the following stack trace: kthread do_current_softirqs() -> process_timeout() -> wake_up_process(). And the task that it woke was rcu_preempt() with task_struct->cpu=1. Right at the end of try_to_wake_up() there's a call to raw_spin_unlock_irqrestore(), so that re-enabled interrupts and the cpu then got an irq exception and was in bcm2836_arm_irqchip_handle_irq() -> __handle_domain_irq() -> generic_handle_irq() -> bcm2836_chained_handle_irq() -> generic_handle_irq(). cpu1 was in task rcu_preempt(just woken by cpu0) and was stuck in rcu_gp_kthread() -> schedule_timeout() -> del_timer_sync() -> rt_spin_lock(&base->expiry_lock). That lock was apparently held by cpu0.

The second time I reproduced it, both cpu0 and cpu1 showed the same stacktrace, namely rcu_cpu_kthread() -> rcu_process_callbacks() -> __rcu_process_callbacks() -> invoke_rcu_callbacks() -> rcu_do_batch() -> __put_task_struct_cb() -> free_task() -> release_task_stack() -> __free_pages() -> __free_pages_ok() -> __my_cpu_offset() -> free_one_page(). cpu0 had apparently won the race for a spinlock in that latter function, then got an irq exception and was spinning in bcm2836_chained_handle_irq(), while cpu1 was waiting for the same spinlock and the CPSR register showed that the FIQ was temporarily disabled on cpu1 (0x20000153).

Stopping and re-starting via JTAG showed that cpu0 was spinning suspiciously long in bcm2836_chained_handle_irq(), so I instrumented that function to show which interrupts had fired and required multiple loop iterations and most of the time it was the USB interrupt. I knew that the USB interrupt isn't used at all by dwc_otg if FIQ is enabled, so the question was what had enabled it in the first place. A few years back I had a case where Apple's EFI firmware left the BCM4331 WiFi interrupt enabled (see abb2baf), so I checked if the USB interrupt was left enabled by the bootloader and sure enough, that turned out to be the case.

[mtausk]

Hi. What's the solution for this?
I see [Firmware Bug]: Bootloader left irq enabled: bank 1 irq 9. .. and the system is not moving anywhere. It's the newest Hifiberry OS.
Doing rpi-update should fix this?

[popcornmix]

What does vcgencmd version report? 13th July or newer should have the fix in.

[gr4viton]

I have exactly the same error on bootup with a freeze
[Firmware Bug]: Bootloader left irq enabled: bank 1 irq 9

freshly flashed Ubuntu Mint for raspberry pi

• ubuntu-mate-20.04.1-desktop-armhf+raspi.img.xz
• from: https://ubuntu-mate.org/download/armhf/focal/

running on Raspberry Pi 3B vol2

will try 20.10 version.

(I just want to play with ROS on Rpi and then buy rpi 4 if i'll enjoy :) )

[pelwell]

It sounds like you are running an older firmware - this was fixed in early July.

[gr4viton]

Yes I probably had.
When I installed the the Ubuntu MATE 20.10 version it worked flawlessly. So the firmware version was probably bumped :).

Problem solved for me. Would it work also with MATE 20.04 if I just copied the firmware files somehow? Is it only about the rpi-4.19.y file?