Linux scheduler debugging
===
Sched Debug Version: v0.11, 5.14.21-yocto-standard #1
ktime : 9658379.116281
sched_clk : 9658818.225737
cpu_clk : 9658510.544222
jiffies : 4304325641
sched_clock_stable() : 1
sysctl_sched
.sysctl_sched_latency : 18.000000
.sysctl_sched_min_granularity : 2.250000
.sysctl_sched_wakeup_granularity : 3.000000
.sysctl_sched_child_runs_first : 0
.sysctl_sched_features : 29306427
.sysctl_sched_tunable_scaling : 1 (logarithmic)
cpu#0, 2999.998 MHz
.nr_running : 0
.nr_switches : 2792068
.nr_uninterruptible : 4294967294
.next_balance : 4304.325628
.curr->pid : 0
.clock : 9658510.557916
.clock_task : 9658510.557916
.avg_idle : 1000000
.max_idle_balance_cost : 500000
cfs_rq[0]:/
.exec_clock : 0.000000
.MIN_vruntime : 0.000001
.min_vruntime : 65380619.197303
.max_vruntime : 0.000001
.spread : 0.000000
.spread0 : 0.000000
.nr_spread_over : 0
.nr_running : 0
.load : 0
.load_avg : 0
.runnable_avg : 15
.util_avg : 15
.util_est_enqueued : 0
.removed.load_avg : 0
.removed.util_avg : 0
.removed.runnable_avg : 0
.tg_load_avg_contrib : 0
.tg_load_avg : 0
rt_rq[0]:
.rt_nr_running : 0
.rt_nr_migratory : 0
.rt_throttled : 0
.rt_time : 0.000000
.rt_runtime : 950.000000
dl_rq[0]:
.dl_nr_running : 0
.dl_nr_migratory : 0
.dl_bw->bw : 996147
.dl_bw->total_bw : 0
runnable tasks:
S task PID tree-key switches prio wait-time sum-exec sum-sleep
-------------------------------------------------------------------------------------------------------------
I rcu_gp 3 8.008063 2 100 0.000000 0.003087 0.000000 /
I rcu_par_gp 4 10.008413 2 100 0.000000 0.001572 0.000000 /
I kworker/0:0H 6 4438.925467 4 100 0.000000 0.026988 0.000000 /
I mm_percpu_wq 8 16.760605 2 100 0.000000 0.001725 0.000000 /
S rcu_tasks_trace 11 20.266652 2 120 0.000000 0.001412 0.000000 /
S ksoftirqd/0 12 34200376.771876 59 120 0.000000 3.827592 0.000000 /
S migration/0 14 0.000000 6 0 0.000000 0.264390 0.000000 /
S cpuhp/0 15 646095.298369 13 120 0.000000 0.201616 0.000000 /
I kworker/0:1 34 1332530.180402 6373 120 0.000000 334.083695 0.000000 /
I kworker/0:1H 86 1340363.841197 33 100 0.000000 0.694651 0.000000 /
S rb_consumer 89 65380619.197303 1554321 139 0.000000 1084318.016247 0.000000 /
I cifsiod 93 4506.689915 2 100 0.000000 0.011424 0.000000 /
I smb3decryptd 94 4515.697781 2 100 0.000000 0.008315 0.000000 /
I cifsfileinfoput 95 4524.705131 2 100 0.000000 0.007731 0.000000 /
I cifsoplockd 96 4533.712643 2 100 0.000000 0.007877 0.000000 /
I deferredclose 97 4542.720972 2 100 0.000000 0.009150 0.000000 /
I nvme-delete-wq 103 7614.582478 2 100 0.000000 0.009800 0.000000 /
I scsi_tmf_1 107 7731.268772 2 100 0.000000 0.017519 0.000000 /
I scsi_tmf_2 109 7749.302952 2 100 0.000000 0.016339 0.000000 /
I scsi_tmf_5 115 7846.254709 2 100 0.000000 0.018737 0.000000 /
I dm_bufio_cache 123 10815.496672 2 100 0.000000 0.003658 0.000000 /
I kworker/0:2 195 65380035.439233 7915 120 0.000000 1367.425541 0.000000 /
S jbd2/vda-8 2698 1340364.189515 24 120 0.000000 0.995336 0.000000 /
I ext4-rsv-conver 2699 1332382.252868 2 100 0.000000 0.010106 0.000000 /
S systemd-udevd 2727 1336233.230285 135 120 0.000000 32.800273 0.000000 /
S rngd 2855 1340358.359685 122 120 0.000000 7180.982608 0.000000 /
S bluetoothd 2879 1333496.414214 22 120 0.000000 3.506378 0.000000 /
S start_getty 2899 1333513.643612 7 120 0.000000 1.154104 0.000000 /
S getty 2904 1333627.743331 3 120 0.000000 2.686937 0.000000 /
cpu#1, 2999.998 MHz
.nr_running : 1
.nr_switches : 359614
.nr_uninterruptible : 4294967295
.next_balance : 4304.325703
.curr->pid : 2941
.clock : 9658510.147990
.clock_task : 9658510.147990
.avg_idle : 1000000
.max_idle_balance_cost : 500000
cfs_rq[1]:/
.exec_clock : 0.000000
.MIN_vruntime : 0.000001
.min_vruntime : 23801794.858588
.max_vruntime : 0.000001
.spread : 0.000000
.spread0 : -41578824.338715
.nr_spread_over : 0
.nr_running : 1
.load : 1048576
.load_avg : 1024
.runnable_avg : 516
.util_avg : 516
.util_est_enqueued : 0
.removed.load_avg : 0
.removed.util_avg : 0
.removed.runnable_avg : 0
.tg_load_avg_contrib : 0
.tg_load_avg : 0
rt_rq[1]:
.rt_nr_running : 0
.rt_nr_migratory : 0
.rt_throttled : 0
.rt_time : 0.041216
.rt_runtime : 950.000000
dl_rq[1]:
.dl_nr_running : 0
.dl_nr_migratory : 0
.dl_bw->bw : 996147
.dl_bw->total_bw : 0
runnable tasks:
S task PID tree-key switches prio wait-time sum-exec sum-sleep
-------------------------------------------------------------------------------------------------------------
S cpuhp/1 16 26978.582679 13 120 0.000000 0.761858 0.000000 /
S migration/1 17 0.000000 11 0 0.000000 58.121507 0.000000 /
S ksoftirqd/1 18 23801107.686172 31 120 0.000000 6.019812 0.000000 /
I kworker/1:0H 20 -1.438787 3 100 0.000000 0.005162 0.000000 /
I kworker/1:1 35 23801764.190645 6075 120 0.000000 350.375240 0.000000 /
S oom_reaper 41 26.167750 2 120 0.000000 0.005391 0.000000 /
S kcompactd0 43 23801776.474325 19156 120 0.000000 289.039527 0.000000 /
I kblockd 80 53.173618 2 100 0.000000 0.000000 0.000000 /
I blkcg_punt_bio 81 53.173618 2 100 0.000000 0.000000 0.000000 /
I md 83 53.177770 2 100 0.000000 0.004152 0.000000 /
I rpciod 85 71.260940 2 100 0.000000 0.034061 0.000000 /
I kworker/u9:0 87 89.277771 2 100 0.000000 0.009853 0.000000 /
I xprtiod 88 98.286659 2 100 0.000000 0.009343 0.000000 /
I kworker/u8:5 118 23801785.521988 92577 120 0.000000 1473.905380 0.000000 /
I kworker/1:2 176 855248.470963 6673 120 0.000000 405.266389 0.000000 /
S rngd 2861 990983.536008 157 120 0.000000 7171.826502 0.000000 /
S wpa_supplicant 2866 23801775.224075 975 120 0.000000 47.845538 0.000000 /
>R cat 2941 23801794.858588 0 120 0.000000 0.336605 0.000000 /
cpu#2, 2999.998 MHz
.nr_running : 1
.nr_switches : 343428
.nr_uninterruptible : 5
.next_balance : 4304.325699
.curr->pid : 90
.clock : 9658510.273537
.clock_task : 9658510.273537
.avg_idle : 905155
.max_idle_balance_cost : 500000
cfs_rq[2]:/
.exec_clock : 0.000000
.MIN_vruntime : 0.000001
.min_vruntime : 306015303.373981
.max_vruntime : 0.000001
.spread : 0.000000
.spread0 : 240634684.176678
.nr_spread_over : 0
.nr_running : 1
.load : 15360
.load_avg : 15
.runnable_avg : 1024
.util_avg : 1024
.util_est_enqueued : 768
.removed.load_avg : 0
.removed.util_avg : 0
.removed.runnable_avg : 0
.tg_load_avg_contrib : 0
.tg_load_avg : 0
rt_rq[2]:
.rt_nr_running : 0
.rt_nr_migratory : 0
.rt_throttled : 0
.rt_time : 0.006634
.rt_runtime : 950.000000
dl_rq[2]:
.dl_nr_running : 0
.dl_nr_migratory : 0
.dl_bw->bw : 996147
.dl_bw->total_bw : 0
runnable tasks:
S task PID tree-key switches prio wait-time sum-exec sum-sleep
-------------------------------------------------------------------------------------------------------------
S kthreadd 2 716228.856734 2694 120 0.000000 486.967987 0.000000 /
I kworker/u8:0 7 190812531.721923 772 120 0.000000 42.436476 0.000000 /
S cpuhp/2 21 1066.961151 13 120 0.000000 0.758248 0.000000 /
S migration/2 22 53.665873 13 0 0.000000 63.598802 0.000000 /
S ksoftirqd/2 23 104803923.859321 150 120 0.000000 2.427778 0.000000 /
I kworker/2:0H 25 995.322475 5 100 0.000000 0.050631 0.000000 /
S kdevtmpfs 31 715108.969408 149 120 0.000000 1.469191 0.000000 /
I netns 32 7.956038 2 100 0.000000 0.004613 0.000000 /
I kworker/2:1 36 715868.426785 7487 120 0.000000 495.482926 0.000000 /
I writeback 42 26.084351 2 100 0.000000 0.000000 0.000000 /
I ata_sff 82 26.095415 2 100 0.000000 0.005118 0.000000 /
>R rb_producer 90 306015303.373981 35687 139 0.000000 4710737.636259 0.000000 /
I nfsiod 92 397.959929 2 100 0.000000 0.012598 0.000000 /
I nvme-wq 101 739.468448 2 100 0.000000 0.012132 0.000000 /
I nvme-reset-wq 102 748.477009 2 100 0.000000 0.009152 0.000000 /
S scsi_eh_0 104 949.978143 25 120 0.000000 1.193927 0.000000 /
I scsi_tmf_0 105 775.520383 2 100 0.000000 0.010157 0.000000 /
S scsi_eh_1 106 949.878511 25 120 0.000000 2.577967 0.000000 /
S scsi_eh_2 108 716226.229248 47 120 0.000000 5.003861 0.000000 /
S scsi_eh_3 110 949.984960 25 120 0.000000 2.645526 0.000000 /
I scsi_tmf_3 111 793.549676 2 100 0.000000 0.013485 0.000000 /
S scsi_eh_4 112 949.977300 25 120 0.000000 1.221488 0.000000 /
I scsi_tmf_4 113 811.572130 2 100 0.000000 0.008881 0.000000 /
S scsi_eh_5 114 954.203444 25 120 0.000000 5.382381 0.000000 /
I kworker/2:2 121 306007573.067465 49898 120 0.000000 1728.017576 0.000000 /
I raid5wq 122 869.830639 2 100 0.000000 0.005617 0.000000 /
I mld 124 878.841507 2 100 0.000000 0.011719 0.000000 /
I ipv6_addrconf 125 887.851587 2 100 0.000000 0.010540 0.000000 /
I kworker/2:1H 133 723783.694177 8 100 0.000000 0.114606 0.000000 /
S dbus-daemon 2845 1017226.516264 85 120 0.000000 5.417629 0.000000 /
S rngd 2862 723792.693829 405 120 0.000000 7189.848347 0.000000 /
S sshd 2873 716688.238665 1 120 0.000000 0.251730 0.000000 /
S klogd 2889 716843.817003 160 120 0.000000 7.743130 0.000000 /
S start_getty 2898 716928.853758 4 120 0.000000 1.180184 0.000000 /
S getty 2900 717029.698947 4 120 0.000000 0.952685 0.000000 /
cpu#3, 2999.998 MHz
.nr_running : 0
.nr_switches : 214530
.nr_uninterruptible : 4294967294
.next_balance : 4304.322151
.curr->pid : 0
.clock : 9658510.197088
.clock_task : 9658510.197088
.avg_idle : 910494
.max_idle_balance_cost : 500000
cfs_rq[3]:/
.exec_clock : 0.000000
.MIN_vruntime : 0.000001
.min_vruntime : 478540.597813
.max_vruntime : 0.000001
.spread : 0.000000
.spread0 : -64902078.599490
.nr_spread_over : 0
.nr_running : 0
.load : 0
.load_avg : 10
.runnable_avg : 10
.util_avg : 10
.util_est_enqueued : 0
.removed.load_avg : 0
.removed.util_avg : 0
.removed.runnable_avg : 0
.tg_load_avg_contrib : 0
.tg_load_avg : 0
rt_rq[3]:
.rt_nr_running : 0
.rt_nr_migratory : 0
.rt_throttled : 0
.rt_time : 0.000000
.rt_runtime : 950.000000
dl_rq[3]:
.dl_nr_running : 0
.dl_nr_migratory : 0
.dl_bw->bw : 996147
.dl_bw->total_bw : 0
runnable tasks:
S task PID tree-key switches prio wait-time sum-exec sum-sleep
-------------------------------------------------------------------------------------------------------------
S init 1 478531.654494 13688 120 0.000000 13600.659552 0.000000 /
S rcu_tasks_rude_ 10 470116.341760 13 120 0.000000 0.063663 0.000000 /
I rcu_sched 13 478531.603734 31821 120 0.000000 1097.969180 0.000000 /
S cpuhp/3 26 452254.938713 13 120 0.000000 0.807613 0.000000 /
S migration/3 27 81.665876 8 0 0.000000 66.133001 0.000000 /
S ksoftirqd/3 28 478526.716453 57 120 0.000000 3.698396 0.000000 /
I kworker/3:0H 30 124.101080 5 100 0.000000 0.032188 0.000000 /
I inet_frag_wq 33 7.958726 2 100 0.000000 0.007301 0.000000 /
I kworker/3:1 37 478527.354196 9948 120 0.000000 475.878320 0.000000 /
S kswapd0 91 69.540042 3 120 0.000000 0.043568 0.000000 /
I acpi_thermal_pm 99 70.120609 2 100 0.000000 0.037096 0.000000 /
S hwrng 100 70.421936 8 120 0.000000 0.299257 0.000000 /
I kworker/3:1H 126 477653.389057 49 100 0.000000 0.300914 0.000000 /
I kworker/3:2 158 470098.083784 4553 120 0.000000 317.259835 0.000000 /
S rngd 2848 478519.953127 277 120 0.000000 75.788441 0.000000 /
S rngd 2863 477627.169579 159 120 0.000000 7193.127785 0.000000 /
S connmand 2856 478527.916470 1491 120 0.000000 130.793915 0.000000 /
S syslogd 2886 477620.423111 16 120 0.000000 8.886792 0.000000 /
S ofonod 2892 470714.769165 35 120 0.000000 21.794525 0.000000 /
S sh 2903 478540.597813 613 120 0.000000 114.566833 0.000000 /