lkml.org 
[lkml]   [2021]   [May]   [7]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
SubjectRe: [PATCH] printk: stop spining waiter when console resume to flush prb
From
Date

On 2021/5/6 23:14, John Ogness wrote:
> On 2021-05-06, Sergey Senozhatsky <senozhatsky@chromium.org> wrote:
>>> Can we count the number of lines that we print from the `current` context
>>> in console_unlock() and if after N messages there is no console_lock waiter
>>> waiting for the `current` to handover console lock ownership, then create
>>> one: schedule IRQ work that will become a console lock owner, spin on
>>> console lock and call console_unlock() once it acquired the ownership.
>>> That 'artificial' console lock owner will do the same - print N
>>> messages, if nothing wants to become a console lock owner then it'll
>>> queue another IRQ work.
>> Or even simpler
>>
>> console_unlock()
>> {
>> ...
>>
>> if (printed_messages > limit && !console_lock_spinning_disable_and_check()) {
>> printk_safe_exit_irqrestore(flags);
>>
>> console_locked = 0;
>> up_console_sem();
>>
>> defer_console_output();
>> return;
>> }
>>
>> ...
>> }
> Or instead to keep it suspend/resume related maybe...
>
> void resume_console(void)
> {
> if (!console_suspend_enabled)
> return;
> down_console_sem();
> console_suspended = 0;
> - console_unlock();
> + console_locked = 0;
> + up_console_sem();
> + defer_console_output();


Hi, john, I test this and found a calltrace below:

[  467.670366] hisi_sas_v3_hw 0000:b4:02.0: print test
[  467.670367] hisi_sas_v3_hw 0000:b4:02.0: print test
[  467.670368] hisi_sas_v3_hw 0000:b4:02.0: print test
[  467.670369] hisi_sas_v3_hw 0000:b4:02.0: print test
[  467.670370] hisi_sas_v3_hw 0000:b4:02.0: print test
[  467.670371] hisi_sas_v3_hw 0000:b4:02.0: print test
[  468.297467] hisi_sas_v3_hw 0000:b4:02.0: print test
[  489.298709] rcu: INFO: rcu_preempt self-detected stall on CPU
[  489.298712] rcu:     44-....: (4324 ticks this GP)
idle=e6e/1/0x4000000000000002 softirq=1212/1212 fqs=2625
[  489.298722]  (t=5250 jiffies g=3285 q=1820)
[  489.298725] Task dump for CPU 44:
[  489.298726] task:bash            state:R  running task stack:    0
pid:16937 ppid: 16935 flags:0x00000206
[  489.298731] Call trace:
[  489.298732]  dump_backtrace+0x0/0x1a4
[  489.298738]  show_stack+0x24/0x40
[  489.298740]  sched_show_task+0x148/0x170
[  489.298744]  dump_cpu_task+0x50/0x60
[  489.298748]  rcu_dump_cpu_stacks+0x10c/0x154
[  489.298751]  rcu_sched_clock_irq+0x8d4/0xd94
[  489.298755]  update_process_times+0xa8/0xf4
[  489.298758]  tick_sched_handle+0x38/0x74
[  489.298760]  tick_sched_timer+0x58/0xb0
[  489.298762]  __hrtimer_run_queues+0x18c/0x3a0
[  489.298764]  hrtimer_interrupt+0xf4/0x2cc
[  489.298767]  arch_timer_handler_phys+0x40/0x50
[  489.298771]  handle_percpu_devid_irq+0x94/0x280
[  489.298775]  __handle_domain_irq+0x88/0xf0
[  489.298777]  gic_handle_irq+0xd8/0x2c0
[  489.298779]  el1_irq+0xbc/0x180
[  489.298780]  console_unlock+0x390/0x580
[  489.298782]  vprintk_emit+0x104/0x280
[  489.298784]  dev_vprintk_emit+0x14c/0x184
[  489.298787]  dev_printk_emit+0x64/0x8c
[  489.298789]  __dev_printk+0x60/0x84
[  489.298792]  _dev_info+0x6c/0x94
[  489.298794]  debugfs_test_if_1_write+0xc0/0x14c [hisi_sas_v3_hw]
[  489.298801]  full_proxy_write+0x6c/0xc0
[  489.298804]  vfs_write+0xfc/0x2b0
[  489.298807]  ksys_write+0x74/0x100
[  489.298809]  __arm64_sys_write+0x28/0x34
[  489.298812]  el0_svc_common.constprop.0+0x70/0x1a4
[  489.298815]  do_el0_svc+0x28/0x3c
[  489.298817]  el0_svc+0x2c/0x70
[  489.298820]  el0_sync_handler+0x1a4/0x1b0
[  489.298822]  el0_sync+0x170/0x180
[  492.474266] hisi_sas_v3_hw 0000:b4:02.0: print test
[  492.479137] hisi_sas_v3_hw 0000:b4:02.0: print test
[  492.483996] hisi_sas_v3_hw 0000:b4:02.0: print test
[  492.488857] hisi_sas_v3_hw 0000:b4:02.0: print test
[  492.493716] hisi_sas_v3_hw 0000:b4:02.0: print test
[  492.498574] hisi_sas_v3_hw 0000:b4:02.0: print test


My test method is as follows: Use a kernel thread to make the console
enter suspend, sleep for 10 seconds, and then resume.

At the same time, another thread repeatedly calls printk() for output.


Thanks

Jiaxing


> }
>
> John Ogness
>
> .
>

\
 
 \ /
  Last update: 2021-05-07 09:59    [W:0.223 / U:0.108 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site