Re: About the output interpretation of the wip RV

[richard clark <richard.xnu.clark@gmail.com>]

Hi Daniel,

On Tue, Oct 25, 2022 at 3:16 PM Daniel Bristot de Oliveira
<bristot@kernel.org> wrote:
>
> Hi Richard!
>
> On 10/25/22 09:10, richard clark wrote:
> > Hi Daniel,
> > I got several dmsg outputs like this after I insmod the 'wip' into
> > system(with printk+dump_stack reactor, trivial changes for the wip):
>
> Which version of the monitor are you using? I make this question because the
> latest version of the monitor is not "loadable module" yet. So my guess is that
> you are using a version from the paper?

After switching to the builtin 'wip' monitor and enable it and the
'printk' reactor...
>
> > [78706.972957] event sched_waking not expected in the state preemptive
> > [78706.972963] CPU: 2 PID: 410 Comm: kworker/2:4 Tainted: G
> > OE     5.15.70-rt50 #1
> > [78706.972972] Workqueue: events igb_watchdog_task [igb]
> > [78706.973000] Call Trace:
> > [78706.973003]  <IRQ>
> > [78706.973006]  dump_stack_lvl+0x61/0x86
> > [78706.973016]  dump_stack+0x10/0x18
> > [78706.973022]  handle_sched_wakeup+0x92/0xd0 [rv_poc]
> > [78706.973028]  ttwu_do_wakeup+0xc3/0x1d0
> > [78706.973038]  ttwu_do_activate+0x6e/0x100
> > [78706.973044]  try_to_wake_up+0x209/0x700
> > [78706.973049]  ? hrtimer_interrupt+0x11f/0x230
> > [78706.973059]  wake_up_process+0x15/0x30
> > [78706.973065]  irq_exit_rcu+0x9b/0xe0
> > [78706.973074]  sysvec_apic_timer_interrupt+0x92/0xd0
> > [78706.973082]  </IRQ>
> > [78706.973083]  <TASK>
> > [78706.973084]  asm_sysvec_apic_timer_interrupt+0x1b/0x20
> >
> > Does that mean something is not unexpected in the system?
>
> Not necessarily, this monitor shows a limitation of tracing, as explained in
> the kernel documentation:

the dmesg shows below information with that enabled 'wip' monitor:

root@robotics:/sys/kernel/debug/tracing/rv/monitors# dmesg
...
[  332.834168] rv: monitor wip does not allow event sched_waking on
state preemptive
[  353.833699] rv: monitor wip does not allow event sched_waking on
state preemptive
[  354.833679] rv: monitor wip does not allow event sched_waking on
state preemptive
...
I took a look at the discussion at
https://lore.kernel.org/all/f2ca7336162b6dc45f413cfe4e0056e6aa32e7ed.1559051152.git.bristot@redhat.com/
seems that patch was trying to resolve the limitation of the tracing:
the __preempt_count_add() and its trace func is not atomic, does that
mean this issue is still in my system from the dmesg output above?
Another question is, except that the trace limitation, do we have some
specific examples to show that maybe an 'unexpected' event happens
against the current state?

Thanks!

>
> https://docs.kernel.org/trace/rv/monitor_wip.html
>
> Anyway, I suggest you using the upstream version of the monitors...
>
> -- Daniel
>
> > Thanks,
> > Richard
>