linux-kernel - Re: Kernel 4.9: strange behavior with fifo scheduler

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [day] [month] [year] [list]

Date:   Thu, 7 Feb 2019 12:27:08 +0100
From:   Dietmar Eggemann <dietmar.eggemann@....com>
To:     Frédéric Mathieu <frederic.mathieu@...lis.com>,
        linux-kernel@...r.kernel.org
Subject: Re: Kernel 4.9: strange behavior with fifo scheduler

On 2/6/19 2:25 PM, Frédéric Mathieu wrote:
> Hi Dietmar,
> 
> Attention !, these tests were executed on a kernel with the patch RT and the option CONFIG_PREEMPT_RT_FULL = y. I confirm the truth of my priority settings
> On a vanilla kernel, I get the same results as you.
> 
> After talking with mike Galbraith, I turned my attention to the priority of kernel threads. The following link explains in the behavior of the scheduler :
> https://wiki.linuxfoundation.org/realtime/documentation/technical_details/hr_timers
> 
> Contrary to what I thought, there is no dynamic adjustment of the priority according to the priority of the calling task.
> 
> -----Message d'origine-----
> De : linux-kernel-owner@...r.kernel.org [mailto:linux-kernel-owner@...r.kernel.org] De la part de Dietmar Eggemann
> Envoyé : mercredi 6 février 2019 11:55
> À : Frédéric Mathieu <frederic.mathieu@...lis.com>; linux-kernel@...r.kernel.org
> Objet : Re: Kernel 4.9: strange behavior with fifo scheduler
> 
> Hi Frédéric,
> 
> On 2/5/19 11:47 AM, Frédéric Mathieu wrote:
>> Hi,
>>
>> on an X86_64 architecture (Intel(R) Core(TM) i3-6100U CPU @ 2.30GHz),
>> I use the linux kernel 4.9.146 with patch rt 125.
>> uname -a: Linux 4.9.146-rt125 #1 SMP PREEMPT RT Tue Jan 29 14:17:55
>> CET 2019
>> x86_64 GNU/Linux

Ah, OK, I should have read it more carefully! So you're talking about 
the ktimersoftd/0 thread in this case which makes cyclictest show the 
latency of ~6ms every 5th time.

v4.9 + rt 125 on ARM64 Juno: (test prio (49) > cyclictest prio (50)

    ...
    ktimersoftd/0-4     [000]    54.948862: sched_pi_setprio:
comm=ktimersoftd/0 pid=4 oldprio=49 newprio=98
    ktimersoftd/0-4     [000]    54.948867: sched_waking: 
comm=cyclictest pid=2730 prio=49 target_cpu=000
    ktimersoftd/0-4     [000]    54.948870: sched_wakeup: 
cyclictest:2730 [49] success=1 CPU:000
    ktimersoftd/0-4     [000]    54.948874: sched_switch: 
ktimersoftd/0:4 [98] R ==> cyclictest:2730 [49]
       cyclictest-2730  [000]    54.948890: sched_switch: 
cyclictest:2730 [49] S ==> ktimersoftd/0:4 [98]
    ktimersoftd/0-4     [000]    54.948906: sched_switch: 
ktimersoftd/0:4 [98] S ==> swapper/0:0 [120]
           <idle>-0     [000]    54.949087: sched_waking: 
comm=test pid=2723 prio=50 target_cpu=000
           <idle>-0     [000]    54.949090: sched_wakeup: 
test:2723 [50] success=1 CPU:000
           <idle>-0     [000]    54.949098: sched_switch: 
swapper/0:0 [120] R ==> test:2723 [50]
             test-2723  [000]    54.949784: sched_waking: 
comm=ktimersoftd/0 pid=4 prio=98 target_cpu=000
             test-2723  [000]    54.949787: sched_wakeup: 
ktimersoftd/0:4 [98] success=1 CPU:000
             test-2723  [000]    54.951979: sched_waking: 
comm=ksoftirqd/0 pid=3 prio=120 target_cpu=000
             test-2723  [000]    54.951983: sched_wakeup: 
ksoftirqd/0:3 [120] success=1 CPU:000
             test-2723  [000]    54.955111: sched_switch: 
test:2723 [50] S ==> ktimersoftd/0:4 [98]
    ktimersoftd/0-4     [000]    54.955125: sched_waking: 
comm=cyclictest pid=2730 prio=49 target_cpu=000
    ktimersoftd/0-4     [000]    54.955128: sched_wakeup: 
cyclictest:2730 [49] success=1 CPU:000
    ktimersoftd/0-4     [000]    54.955132: sched_switch: 
ktimersoftd/0:4 [98] R ==> cyclictest:2730 [49]
       cyclictest-2730  [000]    54.955138: sched_pi_setprio: 
comm=ktimersoftd/0 pid=4 oldprio=98 newprio=49
       cyclictest-2730  [000]    54.955145: sched_switch: 
cyclictest:2730 [49] D ==> ktimersoftd/0:4 [49]
    ktimersoftd/0-4     [000]    54.955149: sched_pi_setprio: 
comm=ktimersoftd/0 pid=4 oldprio=49 newprio=98
    ktimersoftd/0-4     [000]    54.955154: sched_waking: 
comm=cyclictest pid=2730 prio=49 target_cpu=000
    ktimersoftd/0-4     [000]    54.955157: sched_wakeup: 
cyclictest:2730 [49] success=1 CPU:000
    ...

[...]