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

[Geert Uytterhoeven]

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