Re: [RFC PATCH v1 00/25] printk: new implementation

From: Geert Uytterhoeven
Date: Wed Jan 22 2020 - 14:48:29 EST


Hi Eugeniu,

On Wed, Jan 22, 2020 at 5:59 PM Eugeniu Rosca <erosca@xxxxxxxxxxxxxx> wrote:
> On Wed, Jan 22, 2020 at 08:31:44AM +0100, Geert Uytterhoeven wrote:
> > On Wed, Jan 22, 2020 at 3:34 AM Eugeniu Rosca <erosca@xxxxxxxxxxxxxx> wrote:
> > > So, what's specific to R-Car3, based on my testing, is that the issue
> > > can only be reproduced if the printk storm originates on CPU0 (it does
> > > not matter if from interrupt or task context, both have been tested). If
> > > the printk storm is initiated on any other CPU (there are 7 secondary
> > > ones on R-Car H3), there is no regression in the audio quality/latency.
> >
> > The secure stuff is running on CPU0, isn't it?
> > Is that a coincidence?
>
> Nobody has ruled this out so far. As a side note, except for the ARMv8
> generic IPs, there seems to be quite poor IRQ balancing between the
> CPU cores of R-Car H3 (although this might be unrelated to the issue):
>
> $ cat /proc/interrupts | egrep -v "(0[ ]*){8}"
> CPU0 CPU1 CPU2 CPU3 CPU4 CPU5 CPU6 CPU7
> 3: 55879 17835 14132 33882 6626 4331 6710 4532 GICv2 30 Level arch_timer
> 16: 1 0 0 0 0 0 0 0 GICv2 38 Level e6052000.gpio
> 32: 203 0 0 0 0 0 0 0 GICv2 51 Level e66d8000.i2c
> 33: 95 0 0 0 0 0 0 0 GICv2 205 Level e60b0000.i2c
> 94: 19339 0 0 0 0 0 0 0 GICv2 71 Level eth0:ch0:rx_be
> 112: 20599 0 0 0 0 0 0 0 GICv2 89 Level eth0:ch18:tx_be
> 118: 2 0 0 0 0 0 0 0 GICv2 95 Level eth0:ch24:emac
> 122: 442092 0 0 0 0 0 0 0 GICv2 196 Level e6e88000.serial:mux
> 124: 2776685 0 0 0 0 0 0 0 GICv2 352 Level ec700000.dma-controller:0
> 160: 2896 0 0 0 0 0 0 0 GICv2 197 Level ee100000.sd
> 161: 5652 0 0 0 0 0 0 0 GICv2 199 Level ee140000.sd
> 162: 147 0 0 0 0 0 0 0 GICv2 200 Level ee160000.sd
> 197: 5 0 0 0 0 0 0 0 GICv2 384 Level ec500000.sound
> 208: 1 0 0 0 0 0 0 0 gpio-rcar 11 Level e6800000.ethernet-ffffffff:00
> IPI0: 12701 366358 545059 1869017 9817 8065 9327 10644 Rescheduling interrupts
> IPI1: 21 34 111 86 238 191 149 161 Function call interrupts
> IPI5: 16422 709 509 637 0 0 3346 0 IRQ work interrupts

Yeah, cpu0 is always heavily loaded w.r.t. interrupts.
Can you reproduce the problem after forcing all interrupts to e.g. cpu1?

Gr{oetje,eeting}s,

Geert

--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@xxxxxxxxxxxxxx

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds