Kernel 4.9: strange behavior with fifo scheduler

["Frédéric Mathieu" <frederic.mathieu@dualis.com>]

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

I observed a strange behavior of the scheduler when several tasks are
executed in FIFO mode on a CPU core and a significant CPU activity.

first test (reference: cpu load=0%):
cyclictest -m -D 5 -i 1000 -p 50 -a 0
      	# / dev / cpu_dma_latency set to 0us
      	policy: fifo: loadavg: 1.95 1.06 0.43 1/159 14305
      	T: 0 (14145) P: 50 I: 1000 C: 4997 Min: 7 Act: 7 Avg: 7 Max: 18
work fine

now, i'm loading the system on the cpu core 0 with a homemade process:
      cpu load 60%, sched FIFO prio 1, cpu 0
code snippet 
      	active_time = 6000;
      	sleep_time = 4000;
                do {
                               clock_gettime(CLOCK_MONOTONIC, &start_time);
                               // active loop                    
                               do {
                                               for( cptdelay=0; cptdelay <
100; cptdelay++ );
                                              
clock_gettime(CLOCK_MONOTONIC, &now);
                                               diff  = timespec_diff_us(
&start_time, &now );
                               } while (diff < active_time);
                               // sleep : suspend time
                               usleep(sleep_time);
                } while( 1 );


In this case cyclictest detects very long latencies
      cyclictest -m -D 5 -i 1000 -p 50 -a 0 -v 

Max CPUs = 2
# /dev/cpu_dma_latency set to 0us
Thread 0 Interval: 1500
       0:       0:      13
       0:       1:       8
       0:       2:       7
       0:       3:    5648
       0:       4:       8
       0:       5:       7
       0:       6:       7
       0:       7:       7
       0:       8:    5649
       0:       9:       7
       0:      10:       7
       0:      11:       7
       0:      12:       7
       0:      13:    5651
       0:      14:       7
       0:      15:       7
       0:      16:       7
       0:      17:       7
       0:      18:    5655
       0:      19:       7
       0:      20:       7
       0:      21:       7
       0:      22:       7
       0:      23:    5658
       0:      24:       7
       0:      25:       7
       0:      26:       7
       0:      27:       7
       0:      28:    5663
       0:      29:       7
       0:      30:       7
       0:      31:       7
       0:      32:       7
       0:      33:    5664
       0:      34:       7
       0:      35:       7
       0:      36:       7
       0:      37:       7
       0:      38:    5667
       0:      39:       7
       0:      40:       7
       0:      41:       7
       0:      42:       7
       0:      43:    5671
       0:      44:       8
       0:      45:       7
       0:      46:       7
       0:      47:       7
       0:      48:    5673
       0:      49:       7
       0:      50:       7
       0:      51:       7
       0:      52:       7
       0:      53:    5676
       0:      54:       7
       0:      55:       7
       0:      56:       7
       0:      57:       7
       0:      58:    5679
       0:      59:       7
       0:      60:       7
       0:      61:       7
       0:      62:       7
       0:      63:    5682
       0:      64:       7
       0:      65:       7
       0:      66:       7
       0:      67:       7
       0:      68:    5685


After verification, although no other process is running with real time
scheduler, I see a latency of about 5.6 ms at regular intervals.

it seems that the priority task 1 (fifo) is not pre-empted by the cyclictest
process with a priority of 50 (fifo) when the low priority task is active. 
This  corresponds to the cycle recorded in the file: 6 ms of latency
followed by 4 "normal" latencies of 7 us.

Does anyone have any idea of this problem?

Best regards
Frederic MATHIEU