On 2019-08-15 14:33:41 [+0200], John Ogness wrote: > On 2019-08-15, Sebastian Andrzej Siewior <bigeasy@xxxxxxxxxxxxx> wrote: > >> The attachment is here: > >> https://bugzilla.kernel.org/attachment.cgi?id=284391 > > > > both traces have `printk' in it. Could you please explain what it is > > doing? It should print something to the console. The printk code in > > v4.19 vs later changed and now (by default) ERR levels are printed > > immediately and will cause latency spikes. > > > > This would explain the spike but I don't understand how lazy preempt > > is related here. > > Where in this trace is there a latency spike? I could not see one. | printk-873 1....111 84243670us : cdns_uart_console_putchar <-uart_console_write | printk-873 1....111 84243711us : cdns_uart_console_putchar <-uart_console_write | printk-873 1d...111 84243731us : gic_handle_irq <-el1_irq … | printk-873 1dN..111 84243791us : idle_cpu <-irq_exit | printk-873 1dN..111 84243792us : rcu_irq_exit <-irq_exit | printk-873 1dN..111 84244822us : gic_handle_irq <-el1_irq it prints. Then an interrupts arrives, gets handled, wakes cyclictest. But instead switching to cyclictest from the irq_exit it gets back to printing and another interrupt arrives. And then it says that preempt disable, migrate disable, lazy preempt disable is all one. But preemption should be enabled. Looking at the whole trace, the preemption counter is always >= 1 so this might be arm64 specific increment during recording. > Emergency messages are not involved here. You can see at 84239098us that Right, we don't have that. Let me boot my arm64, print something and check how it goes… > John Ogness Sebastian
