Re: 5.6-rc3: WARNING: CPU: 48 PID: 17435 at kernel/sched/fair.c:380 enqueue_task_fair+0x328/0x440

From: Christian Borntraeger
Date: Wed Mar 04 2020 - 14:38:53 EST




On 04.03.20 20:19, Dietmar Eggemann wrote:
>> I just realized that this system has something special. Some month ago I created 2 slices
>> $ head /etc/systemd/system/*.slice
>> ==> /etc/systemd/system/machine-production.slice <==
>> [Unit]
>> Description=VM production
>> Before=slices.target
>> Wants=machine.slice
>> [Slice]
>> CPUQuota=2000%
>> CPUWeight=1000
>>
>> ==> /etc/systemd/system/machine-test.slice <==
>> [Unit]
>> Description=VM production
>> Before=slices.target
>> Wants=machine.slice
>> [Slice]
>> CPUQuota=300%
>> CPUWeight=100
>>
>>
>> And the guests are then put into these slices. that also means that this test will never use more than the 2300%.
>> No matter how much CPUs the system has.
>
> If you could run this debug patch on top of your un-patched kernel, it would tell us which task (in the enqueue case)
> and which taskgroup is causing that.
>
> You could then further dump the appropriate taskgroup directory under the cpu cgroup mountpoint
> (to see e.g. the CFS bandwidth data).
>
> I expect more than one hit since assert_list_leaf_cfs_rq() uses SCHED_WARN_ON, hence WARN_ONCE.

That was quick. FWIW, I messed up dumping the cgroup mountpoint (since I restarted my guests after this happened).
Will retry. See the dmesg attached.
[ 0.179552] Linux version 5.6.0-rc4+ (cborntra@xxxxxxxxxxxxxxxxx) (gcc version 9.2.1 20190827 (Red Hat 9.2.1-1) (GCC)) #157 SMP Wed Mar 4 20:28:33 CET 2020
[ 0.179554] setup: Linux is running natively in 64-bit mode
[ 0.179600] setup: The maximum memory size is 131072MB
[ 0.179605] setup: Reserving 1024MB of memory at 130048MB for crashkernel (System RAM: 130048MB)
[ 0.179616] numa: NUMA mode: plain
[ 0.179690] cpu: 64 configured CPUs, 0 standby CPUs
[ 0.179754] cpu: The CPU configuration topology of the machine is: 0 0 4 2 3 10 / 4
[ 0.180454] Write protected kernel read-only data: 13532k
[ 0.181204] Zone ranges:
[ 0.181205] DMA [mem 0x0000000000000000-0x000000007fffffff]
[ 0.181207] Normal [mem 0x0000000080000000-0x0000001fffffffff]
[ 0.181208] Movable zone start for each node
[ 0.181209] Early memory node ranges
[ 0.181210] node 0: [mem 0x0000000000000000-0x0000001fffffffff]
[ 0.181217] Initmem setup node 0 [mem 0x0000000000000000-0x0000001fffffffff]
[ 0.181218] On node 0 totalpages: 33554432
[ 0.181218] DMA zone: 8192 pages used for memmap
[ 0.181219] DMA zone: 0 pages reserved
[ 0.181220] DMA zone: 524288 pages, LIFO batch:63
[ 0.198887] Normal zone: 516096 pages used for memmap
[ 0.198887] Normal zone: 33030144 pages, LIFO batch:63
[ 0.215007] percpu: Embedded 33 pages/cpu s97280 r8192 d29696 u135168
[ 0.215015] pcpu-alloc: s97280 r8192 d29696 u135168 alloc=33*4096
[ 0.215016] pcpu-alloc: [0] 000 [0] 001 [0] 002 [0] 003
[ 0.215018] pcpu-alloc: [0] 004 [0] 005 [0] 006 [0] 007
[ 0.215019] pcpu-alloc: [0] 008 [0] 009 [0] 010 [0] 011
[ 0.215020] pcpu-alloc: [0] 012 [0] 013 [0] 014 [0] 015
[ 0.215021] pcpu-alloc: [0] 016 [0] 017 [0] 018 [0] 019
[ 0.215022] pcpu-alloc: [0] 020 [0] 021 [0] 022 [0] 023
[ 0.215023] pcpu-alloc: [0] 024 [0] 025 [0] 026 [0] 027
[ 0.215025] pcpu-alloc: [0] 028 [0] 029 [0] 030 [0] 031
[ 0.215026] pcpu-alloc: [0] 032 [0] 033 [0] 034 [0] 035
[ 0.215027] pcpu-alloc: [0] 036 [0] 037 [0] 038 [0] 039
[ 0.215028] pcpu-alloc: [0] 040 [0] 041 [0] 042 [0] 043
[ 0.215029] pcpu-alloc: [0] 044 [0] 045 [0] 046 [0] 047
[ 0.215030] pcpu-alloc: [0] 048 [0] 049 [0] 050 [0] 051
[ 0.215032] pcpu-alloc: [0] 052 [0] 053 [0] 054 [0] 055
[ 0.215033] pcpu-alloc: [0] 056 [0] 057 [0] 058 [0] 059
[ 0.215034] pcpu-alloc: [0] 060 [0] 061 [0] 062 [0] 063
[ 0.215035] pcpu-alloc: [0] 064 [0] 065 [0] 066 [0] 067
[ 0.215036] pcpu-alloc: [0] 068 [0] 069 [0] 070 [0] 071
[ 0.215037] pcpu-alloc: [0] 072 [0] 073 [0] 074 [0] 075
[ 0.215038] pcpu-alloc: [0] 076 [0] 077 [0] 078 [0] 079
[ 0.215039] pcpu-alloc: [0] 080 [0] 081 [0] 082 [0] 083
[ 0.215040] pcpu-alloc: [0] 084 [0] 085 [0] 086 [0] 087
[ 0.215042] pcpu-alloc: [0] 088 [0] 089 [0] 090 [0] 091
[ 0.215043] pcpu-alloc: [0] 092 [0] 093 [0] 094 [0] 095
[ 0.215044] pcpu-alloc: [0] 096 [0] 097 [0] 098 [0] 099
[ 0.215045] pcpu-alloc: [0] 100 [0] 101 [0] 102 [0] 103
[ 0.215046] pcpu-alloc: [0] 104 [0] 105 [0] 106 [0] 107
[ 0.215047] pcpu-alloc: [0] 108 [0] 109 [0] 110 [0] 111
[ 0.215048] pcpu-alloc: [0] 112 [0] 113 [0] 114 [0] 115
[ 0.215050] pcpu-alloc: [0] 116 [0] 117 [0] 118 [0] 119
[ 0.215051] pcpu-alloc: [0] 120 [0] 121 [0] 122 [0] 123
[ 0.215052] pcpu-alloc: [0] 124 [0] 125 [0] 126 [0] 127
[ 0.215053] pcpu-alloc: [0] 128 [0] 129 [0] 130 [0] 131
[ 0.215054] pcpu-alloc: [0] 132 [0] 133 [0] 134 [0] 135
[ 0.215055] pcpu-alloc: [0] 136 [0] 137 [0] 138 [0] 139
[ 0.215056] pcpu-alloc: [0] 140 [0] 141 [0] 142 [0] 143
[ 0.215058] pcpu-alloc: [0] 144 [0] 145 [0] 146 [0] 147
[ 0.215059] pcpu-alloc: [0] 148 [0] 149 [0] 150 [0] 151
[ 0.215060] pcpu-alloc: [0] 152 [0] 153 [0] 154 [0] 155
[ 0.215061] pcpu-alloc: [0] 156 [0] 157 [0] 158 [0] 159
[ 0.215062] pcpu-alloc: [0] 160 [0] 161 [0] 162 [0] 163
[ 0.215063] pcpu-alloc: [0] 164 [0] 165 [0] 166 [0] 167
[ 0.215065] pcpu-alloc: [0] 168 [0] 169 [0] 170 [0] 171
[ 0.215066] pcpu-alloc: [0] 172 [0] 173 [0] 174 [0] 175
[ 0.215067] pcpu-alloc: [0] 176 [0] 177 [0] 178 [0] 179
[ 0.215068] pcpu-alloc: [0] 180 [0] 181 [0] 182 [0] 183
[ 0.215069] pcpu-alloc: [0] 184 [0] 185 [0] 186 [0] 187
[ 0.215070] pcpu-alloc: [0] 188 [0] 189 [0] 190 [0] 191
[ 0.215072] pcpu-alloc: [0] 192 [0] 193 [0] 194 [0] 195
[ 0.215073] pcpu-alloc: [0] 196 [0] 197 [0] 198 [0] 199
[ 0.215074] pcpu-alloc: [0] 200 [0] 201 [0] 202 [0] 203
[ 0.215075] pcpu-alloc: [0] 204 [0] 205 [0] 206 [0] 207
[ 0.215076] pcpu-alloc: [0] 208 [0] 209 [0] 210 [0] 211
[ 0.215077] pcpu-alloc: [0] 212 [0] 213 [0] 214 [0] 215
[ 0.215079] pcpu-alloc: [0] 216 [0] 217 [0] 218 [0] 219
[ 0.215080] pcpu-alloc: [0] 220 [0] 221 [0] 222 [0] 223
[ 0.215081] pcpu-alloc: [0] 224 [0] 225 [0] 226 [0] 227
[ 0.215082] pcpu-alloc: [0] 228 [0] 229 [0] 230 [0] 231
[ 0.215083] pcpu-alloc: [0] 232 [0] 233 [0] 234 [0] 235
[ 0.215084] pcpu-alloc: [0] 236 [0] 237 [0] 238 [0] 239
[ 0.215085] pcpu-alloc: [0] 240 [0] 241 [0] 242 [0] 243
[ 0.215087] pcpu-alloc: [0] 244 [0] 245 [0] 246 [0] 247
[ 0.215088] pcpu-alloc: [0] 248 [0] 249 [0] 250 [0] 251
[ 0.215089] pcpu-alloc: [0] 252 [0] 253 [0] 254 [0] 255
[ 0.215090] pcpu-alloc: [0] 256 [0] 257 [0] 258 [0] 259
[ 0.215091] pcpu-alloc: [0] 260 [0] 261 [0] 262 [0] 263
[ 0.215093] pcpu-alloc: [0] 264 [0] 265 [0] 266 [0] 267
[ 0.215094] pcpu-alloc: [0] 268 [0] 269 [0] 270 [0] 271
[ 0.215095] pcpu-alloc: [0] 272 [0] 273 [0] 274 [0] 275
[ 0.215096] pcpu-alloc: [0] 276 [0] 277 [0] 278 [0] 279
[ 0.215097] pcpu-alloc: [0] 280 [0] 281 [0] 282 [0] 283
[ 0.215098] pcpu-alloc: [0] 284 [0] 285 [0] 286 [0] 287
[ 0.215099] pcpu-alloc: [0] 288 [0] 289 [0] 290 [0] 291
[ 0.215101] pcpu-alloc: [0] 292 [0] 293 [0] 294 [0] 295
[ 0.215102] pcpu-alloc: [0] 296 [0] 297 [0] 298 [0] 299
[ 0.215103] pcpu-alloc: [0] 300 [0] 301 [0] 302 [0] 303
[ 0.215104] pcpu-alloc: [0] 304 [0] 305 [0] 306 [0] 307
[ 0.215105] pcpu-alloc: [0] 308 [0] 309 [0] 310 [0] 311
[ 0.215106] pcpu-alloc: [0] 312 [0] 313 [0] 314 [0] 315
[ 0.215108] pcpu-alloc: [0] 316 [0] 317 [0] 318 [0] 319
[ 0.215109] pcpu-alloc: [0] 320 [0] 321 [0] 322 [0] 323
[ 0.215110] pcpu-alloc: [0] 324 [0] 325 [0] 326 [0] 327
[ 0.215111] pcpu-alloc: [0] 328 [0] 329 [0] 330 [0] 331
[ 0.215112] pcpu-alloc: [0] 332 [0] 333 [0] 334 [0] 335
[ 0.215114] pcpu-alloc: [0] 336 [0] 337 [0] 338 [0] 339
[ 0.215137] Built 1 zonelists, mobility grouping on. Total pages: 33030144
[ 0.215138] Policy zone: Normal
[ 0.215139] Kernel command line: root=/dev/disk/by-path/ccw-0.0.3318-part1 rd.dasd=0.0.3318 cio_ignore=all,!condev rd.znet=qeth,0.0.bd00,0.0.bd01,0.0.bd02,layer2=1,portno=0,portname=OSAPORT zfcp.allow_lun_scan=0 BOOT_IMAGE=0 crashkernel=1G dyndbg="module=vhost +plt" BOOT_IMAGE=
[ 0.216115] printk: log_buf_len individual max cpu contribution: 4096 bytes
[ 0.216115] printk: log_buf_len total cpu_extra contributions: 1388544 bytes
[ 0.216116] printk: log_buf_len min size: 131072 bytes
[ 0.216409] printk: log_buf_len: 2097152 bytes
[ 0.216409] printk: early log buf free: 123836(94%)
[ 0.225460] Dentry cache hash table entries: 8388608 (order: 14, 67108864 bytes, linear)
[ 0.230020] Inode-cache hash table entries: 4194304 (order: 13, 33554432 bytes, linear)
[ 0.230032] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.261020] Memory: 2316420K/134217728K available (10460K kernel code, 2016K rwdata, 3072K rodata, 3932K init, 852K bss, 3354384K reserved, 0K cma-reserved)
[ 0.261421] SLUB: HWalign=256, Order=0-3, MinObjects=0, CPUs=340, Nodes=1
[ 0.261450] ftrace: allocating 31562 entries in 124 pages
[ 0.265986] ftrace: allocated 124 pages with 5 groups
[ 0.266642] rcu: Hierarchical RCU implementation.
[ 0.266642] rcu: RCU event tracing is enabled.
[ 0.266643] rcu: RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=340.
[ 0.266643] Tasks RCU enabled.
[ 0.266644] rcu: RCU calculated value of scheduler-enlistment delay is 11 jiffies.
[ 0.266644] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=340
[ 0.269449] NR_IRQS: 3, nr_irqs: 3, preallocated irqs: 3
[ 0.269541] clocksource: tod: mask: 0xffffffffffffffff max_cycles: 0x3b0a9be803b0a9, max_idle_ns: 1805497147909793 ns
[ 0.269712] Console: colour dummy device 80x25
[ 0.658102] printk: console [ttyS0] enabled
[ 0.823432] Calibrating delay loop (skipped)... 21881.00 BogoMIPS preset
[ 0.823432] pid_max: default: 348160 minimum: 2720
[ 0.823585] LSM: Security Framework initializing
[ 0.823616] SELinux: Initializing.
[ 0.823854] Mount-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[ 0.824000] Mountpoint-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[ 0.825084] rcu: Hierarchical SRCU implementation.
[ 0.827868] smp: Bringing up secondary CPUs ...
[ 0.842401] smp: Brought up 1 node, 64 CPUs
[ 1.744807] node 0 initialised, 32136731 pages in 900ms
[ 1.772554] devtmpfs: initialized
[ 1.773439] random: get_random_u32 called from bucket_table_alloc.isra.0+0x82/0x120 with crng_init=0
[ 1.774015] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 1.774659] futex hash table entries: 131072 (order: 13, 33554432 bytes, vmalloc)
[ 1.779230] xor: automatically using best checksumming function xc
[ 1.779412] NET: Registered protocol family 16
[ 1.779449] audit: initializing netlink subsys (disabled)
[ 1.779522] audit: type=2000 audit(1583350198.232:1): state=initialized audit_enabled=0 res=1
[ 1.779663] Spectre V2 mitigation: etokens
[ 1.780392] random: fast init done
[ 1.799643] HugeTLB registered 1.00 MiB page size, pre-allocated 0 pages
[ 2.049545] raid6: vx128x8 gen() 21586 MB/s
[ 2.219544] raid6: vx128x8 xor() 13355 MB/s
[ 2.219546] raid6: using algorithm vx128x8 gen() 21586 MB/s
[ 2.219547] raid6: .... xor() 13355 MB/s, rmw enabled
[ 2.219548] raid6: using s390xc recovery algorithm
[ 2.219866] iommu: Default domain type: Translated
[ 2.219980] SCSI subsystem initialized
[ 2.232745] PCI host bridge to bus 0000:00
[ 2.232750] pci_bus 0000:00: root bus resource [mem 0x8000000000000000-0x8000000007ffffff 64bit pref]
[ 2.232752] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
[ 2.232817] pci 0000:00:00.0: [1014:044b] type 00 class 0x120000
[ 2.232872] pci 0000:00:00.0: reg 0x10: [mem 0xffffd80008000000-0xffffd8000fffffff 64bit pref]
[ 2.233159] pci 0000:00:00.0: 0.000 Gb/s available PCIe bandwidth, limited by Unknown speed x0 link at 0000:00:00.0 (capable of 32.000 Gb/s with 5 GT/s x8 link)
[ 2.233199] pci 0000:00:00.0: Adding to iommu group 0
[ 2.233210] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 00
[ 2.235224] PCI host bridge to bus 0001:00
[ 2.235226] pci_bus 0001:00: root bus resource [mem 0x8001000000000000-0x80010000000fffff 64bit pref]
[ 2.235228] pci_bus 0001:00: No busn resource found for root bus, will use [bus 00-ff]
[ 2.235318] pci 0001:00:00.0: [15b3:1016] type 00 class 0x020000
[ 2.235415] pci 0001:00:00.0: reg 0x10: [mem 0xffffd40002000000-0xffffd400020fffff 64bit pref]
[ 2.235565] pci 0001:00:00.0: enabling Extended Tags
[ 2.236059] pci 0001:00:00.0: 0.000 Gb/s available PCIe bandwidth, limited by Unknown speed x0 link at 0001:00:00.0 (capable of 63.008 Gb/s with 8 GT/s x8 link)
[ 2.236106] pci 0001:00:00.0: Adding to iommu group 1
[ 2.236114] pci_bus 0001:00: busn_res: [bus 00-ff] end is updated to 00
[ 2.238133] PCI host bridge to bus 0002:00
[ 2.238135] pci_bus 0002:00: root bus resource [mem 0x8002000000000000-0x80020000000fffff 64bit pref]
[ 2.238137] pci_bus 0002:00: No busn resource found for root bus, will use [bus 00-ff]
[ 2.238226] pci 0002:00:00.0: [15b3:1016] type 00 class 0x020000
[ 2.238326] pci 0002:00:00.0: reg 0x10: [mem 0xffffd40008000000-0xffffd400080fffff 64bit pref]
[ 2.238483] pci 0002:00:00.0: enabling Extended Tags
[ 2.238988] pci 0002:00:00.0: 0.000 Gb/s available PCIe bandwidth, limited by Unknown speed x0 link at 0002:00:00.0 (capable of 63.008 Gb/s with 8 GT/s x8 link)
[ 2.239022] pci 0002:00:00.0: Adding to iommu group 2
[ 2.239028] pci_bus 0002:00: busn_res: [bus 00-ff] end is updated to 00
[ 2.836711] VFS: Disk quotas dquot_6.6.0
[ 2.836765] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 2.838349] NET: Registered protocol family 2
[ 2.839186] tcp_listen_portaddr_hash hash table entries: 65536 (order: 8, 1048576 bytes, linear)
[ 2.839680] random: crng init done
[ 2.839770] TCP established hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc)
[ 2.841819] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes, linear)
[ 2.842274] TCP: Hash tables configured (established 524288 bind 65536)
[ 2.842599] UDP hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc)
[ 2.843583] UDP-Lite hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc)
[ 2.844962] NET: Registered protocol family 1
[ 2.845169] Trying to unpack rootfs image as initramfs...
[ 3.397729] Freeing initrd memory: 42272K
[ 3.398935] alg: No test for crc32be (crc32be-vx)
[ 3.403320] Initialise system trusted keyrings
[ 3.403369] workingset: timestamp_bits=45 max_order=25 bucket_order=0
[ 3.404472] fuse: init (API version 7.31)
[ 3.404541] SGI XFS with ACLs, security attributes, realtime, quota, no debug enabled
[ 3.411259] Key type asymmetric registered
[ 3.411261] Asymmetric key parser 'x509' registered
[ 3.411267] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[ 3.411477] io scheduler mq-deadline registered
[ 3.411479] io scheduler kyber registered
[ 3.411501] io scheduler bfq registered
[ 3.412309] atomic64_test: passed
[ 3.412362] hvc_iucv: The z/VM IUCV HVC device driver cannot be used without z/VM
[ 3.418786] brd: module loaded
[ 3.419143] cio: Channel measurement facility initialized using format extended (mode autodetected)
[ 3.419414] Discipline DIAG cannot be used without z/VM
[ 4.942920] sclp_sd: No data is available for the config data entity
[ 5.301505] qeth: loading core functions
[ 5.301563] qeth: register layer 2 discipline
[ 5.301564] qeth: register layer 3 discipline
[ 5.302044] NET: Registered protocol family 10
[ 5.302987] Segment Routing with IPv6
[ 5.303005] NET: Registered protocol family 17
[ 5.303014] Key type dns_resolver registered
[ 5.303107] registered taskstats version 1
[ 5.303112] Loading compiled-in X.509 certificates
[ 5.343478] Loaded X.509 cert 'Build time autogenerated kernel key: c46ba92ee388c82c5891ee836c9c20b752cdfac5'
[ 5.344136] zswap: default zpool zbud not available
[ 5.344137] zswap: pool creation failed
[ 5.344894] Key type ._fscrypt registered
[ 5.344895] Key type .fscrypt registered
[ 5.344896] Key type fscrypt-provisioning registered
[ 5.345187] Btrfs loaded, crc32c=crc32c-vx
[ 5.349875] Key type big_key registered
[ 5.349880] ima: No TPM chip found, activating TPM-bypass!
[ 5.349884] ima: Allocated hash algorithm: sha256
[ 5.349891] ima: No architecture policies found
[ 5.351364] Freeing unused kernel memory: 3932K
[ 5.409626] Write protected read-only-after-init data: 68k
[ 5.409629] Run /init as init process
[ 5.409629] with arguments:
[ 5.409630] /init
[ 5.409630] with environment:
[ 5.409630] HOME=/
[ 5.409630] TERM=linux
[ 5.409630] BOOT_IMAGE=
[ 5.409631] crashkernel=1G
[ 5.409631] dyndbg=module=vhost +plt
[ 5.424112] systemd[1]: Inserted module 'autofs4'
[ 5.425256] systemd[1]: systemd v243.7-1.fc31 running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified)
[ 5.425663] systemd[1]: Detected architecture s390x.
[ 5.425665] systemd[1]: Running in initial RAM disk.
[ 5.425719] systemd[1]: Set hostname to <m83lp52.lnxne.boe>.
[ 5.465976] systemd[1]: Reached target Local File Systems.
[ 5.466033] systemd[1]: Reached target Slices.
[ 5.466055] systemd[1]: Reached target Swap.
[ 5.466075] systemd[1]: Reached target Timers.
[ 5.466165] systemd[1]: Listening on Journal Audit Socket.
[ 5.466216] systemd[1]: Listening on Journal Socket (/dev/log).
[ 5.753422] audit: type=1130 audit(1583350202.212:2): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-journald comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 5.760976] audit: type=1130 audit(1583350202.222:3): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-tmpfiles-setup comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 6.730719] audit: type=1130 audit(1583350203.192:4): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-cmdline comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 6.746217] audit: type=1130 audit(1583350203.202:5): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-pre-udev comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 6.746614] audit: type=1334 audit(1583350203.202:6): prog-id=6 op=LOAD
[ 6.746638] audit: type=1334 audit(1583350203.202:7): prog-id=7 op=LOAD
[ 6.972690] audit: type=1130 audit(1583350203.432:8): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-udevd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 6.976683] qeth 0.0.bd00: Priority Queueing not supported
[ 6.977305] qeth 0.0.bd00: portname is deprecated and is ignored
[ 6.978774] dasd-eckd 0.0.3318: A channel path to the device has become operational
[ 6.979092] dasd-eckd 0.0.331a: A channel path to the device has become operational
[ 6.979379] dasd-eckd 0.0.3319: A channel path to the device has become operational
[ 6.979432] dasd-eckd 0.0.331b: A channel path to the device has become operational
[ 6.982509] qdio: 0.0.bd02 OSA on SC 159b using AI:1 QEBSM:0 PRI:1 TDD:1 SIGA: W AP
[ 6.988753] dasd-eckd 0.0.331a: New DASD 3390/0C (CU 3990/01) with 30051 cylinders, 15 heads, 224 sectors
[ 6.991372] dasd-eckd 0.0.331a: DASD with 4 KB/block, 21636720 KB total size, 48 KB/track, compatible disk layout
[ 6.992179] dasdb:VOL1/ 0X331A:
[ 6.993148] dasd-eckd 0.0.3318: New DASD 3390/0E (CU 3990/01) with 262668 cylinders, 15 heads, 224 sectors
[ 6.995792] dasd-eckd 0.0.3318: DASD with 4 KB/block, 189120960 KB total size, 48 KB/track, compatible disk layout
[ 6.996773] dasda:VOL1/ 0X3318: dasda1
[ 6.997591] dasd-eckd 0.0.3319: New DASD 3390/0E (CU 3990/01) with 262668 cylinders, 15 heads, 224 sectors
[ 7.000216] dasd-eckd 0.0.3319: DASD with 4 KB/block, 189120960 KB total size, 48 KB/track, compatible disk layout
[ 7.001240] dasdc:VOL1/ 0X3319: dasdc1
[ 7.002064] dasd-eckd 0.0.331b: New DASD 3390/0C (CU 3990/01) with 30051 cylinders, 15 heads, 224 sectors
[ 7.005812] dasd-eckd 0.0.331b: DASD with 4 KB/block, 21636720 KB total size, 48 KB/track, compatible disk layout
[ 7.006506] dasdd:VOL1/ 0X331B:
[ 7.015493] audit: type=1130 audit(1583350203.472:9): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-udev-trigger comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 7.022792] qeth 0.0.bd00: QDIO data connection isolation is deactivated
[ 7.023272] qeth 0.0.bd00: The device represents a Bridge Capable Port
[ 7.026647] qeth 0.0.bd00: MAC address ea:98:1f:2a:e3:e9 successfully registered
[ 7.027175] qeth 0.0.bd00: Device is a OSD Express card (level: 0199)
with link type OSD_10GIG.
[ 7.030971] audit: type=1130 audit(1583350203.492:10): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=plymouth-start comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 7.055532] qeth 0.0.bd00: MAC address de:45:d7:61:c4:13 successfully registered
[ 7.057769] qeth 0.0.bd00 encbd00: renamed from eth0
[ 7.246654] mlx5_core 0001:00:00.0: enabling device (0000 -> 0002)
[ 7.246743] mlx5_core 0001:00:00.0: firmware version: 14.23.1020
[ 7.405839] dasdconf.sh Warning: 0.0.331a is already online, not configuring
[ 7.550030] dasdconf.sh Warning: 0.0.3319 is already online, not configuring
[ 7.665404] dasdconf.sh Warning: 0.0.331b is already online, not configuring
[ 7.684688] dasdconf.sh Warning: 0.0.3318 is already online, not configuring
[ 7.688844] mlx5_core 0002:00:00.0: enabling device (0000 -> 0002)
[ 7.688928] mlx5_core 0002:00:00.0: firmware version: 14.23.1020
[ 8.137519] mlx5_core 0001:00:00.0: MLX5E: StrdRq(0) RqSz(1024) StrdSz(256) RxCqeCmprss(0)
[ 8.268721] mlx5_core 0002:00:00.0: MLX5E: StrdRq(0) RqSz(1024) StrdSz(256) RxCqeCmprss(0)
[ 8.421011] mlx5_core 0002:00:00.0 enP2s564: renamed from eth1
[ 8.680291] mlx5_core 0001:00:00.0 enP1s519: renamed from eth0
[ 8.911022] audit: type=1130 audit(1583350205.372:11): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dracut-initqueue comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 8.927993] audit: type=1130 audit(1583350205.382:12): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-fsck-root comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 8.937455] EXT4-fs (dasda1): mounted filesystem with ordered data mode. Opts: (null)
[ 8.960316] audit: type=1334 audit(1583350205.422:13): prog-id=5 op=UNLOAD
[ 8.960319] audit: type=1334 audit(1583350205.422:14): prog-id=4 op=UNLOAD
[ 8.960321] audit: type=1334 audit(1583350205.422:15): prog-id=3 op=UNLOAD
[ 8.960346] audit: type=1334 audit(1583350205.422:16): prog-id=7 op=UNLOAD
[ 8.965353] audit: type=1334 audit(1583350205.422:17): prog-id=6 op=UNLOAD
[ 9.253873] systemd-journald[543]: Received SIGTERM from PID 1 (systemd).
[ 9.272389] printk: systemd: 19 output lines suppressed due to ratelimiting
[ 9.674803] SELinux: Permission watch in class filesystem not defined in policy.
[ 9.674808] SELinux: Permission watch in class file not defined in policy.
[ 9.674809] SELinux: Permission watch_mount in class file not defined in policy.
[ 9.674810] SELinux: Permission watch_sb in class file not defined in policy.
[ 9.674811] SELinux: Permission watch_with_perm in class file not defined in policy.
[ 9.674812] SELinux: Permission watch_reads in class file not defined in policy.
[ 9.674815] SELinux: Permission watch in class dir not defined in policy.
[ 9.674816] SELinux: Permission watch_mount in class dir not defined in policy.
[ 9.674817] SELinux: Permission watch_sb in class dir not defined in policy.
[ 9.674818] SELinux: Permission watch_with_perm in class dir not defined in policy.
[ 9.674819] SELinux: Permission watch_reads in class dir not defined in policy.
[ 9.674822] SELinux: Permission watch in class lnk_file not defined in policy.
[ 9.674823] SELinux: Permission watch_mount in class lnk_file not defined in policy.
[ 9.674824] SELinux: Permission watch_sb in class lnk_file not defined in policy.
[ 9.674825] SELinux: Permission watch_with_perm in class lnk_file not defined in policy.
[ 9.674826] SELinux: Permission watch_reads in class lnk_file not defined in policy.
[ 9.674828] SELinux: Permission watch in class chr_file not defined in policy.
[ 9.674844] SELinux: Permission watch_mount in class chr_file not defined in policy.
[ 9.674845] SELinux: Permission watch_sb in class chr_file not defined in policy.
[ 9.674846] SELinux: Permission watch_with_perm in class chr_file not defined in policy.
[ 9.674848] SELinux: Permission watch_reads in class chr_file not defined in policy.
[ 9.674850] SELinux: Permission watch in class blk_file not defined in policy.
[ 9.674851] SELinux: Permission watch_mount in class blk_file not defined in policy.
[ 9.674852] SELinux: Permission watch_sb in class blk_file not defined in policy.
[ 9.674853] SELinux: Permission watch_with_perm in class blk_file not defined in policy.
[ 9.674854] SELinux: Permission watch_reads in class blk_file not defined in policy.
[ 9.674856] SELinux: Permission watch in class sock_file not defined in policy.
[ 9.674857] SELinux: Permission watch_mount in class sock_file not defined in policy.
[ 9.674858] SELinux: Permission watch_sb in class sock_file not defined in policy.
[ 9.674859] SELinux: Permission watch_with_perm in class sock_file not defined in policy.
[ 9.674860] SELinux: Permission watch_reads in class sock_file not defined in policy.
[ 9.674863] SELinux: Permission watch in class fifo_file not defined in policy.
[ 9.674864] SELinux: Permission watch_mount in class fifo_file not defined in policy.
[ 9.674865] SELinux: Permission watch_sb in class fifo_file not defined in policy.
[ 9.674866] SELinux: Permission watch_with_perm in class fifo_file not defined in policy.
[ 9.674867] SELinux: Permission watch_reads in class fifo_file not defined in policy.
[ 9.674946] SELinux: Class perf_event not defined in policy.
[ 9.674947] SELinux: Class lockdown not defined in policy.
[ 9.674948] SELinux: the above unknown classes and permissions will be allowed
[ 9.674961] SELinux: policy capability network_peer_controls=1
[ 9.674962] SELinux: policy capability open_perms=1
[ 9.674963] SELinux: policy capability extended_socket_class=1
[ 9.674963] SELinux: policy capability always_check_network=0
[ 9.674964] SELinux: policy capability cgroup_seclabel=1
[ 9.674965] SELinux: policy capability nnp_nosuid_transition=1
[ 9.753985] systemd[1]: Successfully loaded SELinux policy in 312.676ms.
[ 9.812306] systemd[1]: Relabelled /dev, /dev/shm, /run, /sys/fs/cgroup in 12.846ms.
[ 9.814514] systemd[1]: systemd v243.7-1.fc31 running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified)
[ 9.814956] systemd[1]: Detected architecture s390x.
[ 9.816221] systemd[1]: Set hostname to <m83lp52.lnxne.boe>.
[ 9.951828] systemd[1]: /usr/lib/systemd/system/sssd.service:12: PIDFile= references a path below legacy directory /var/run/, updating /var/run/sssd.pid â /run/sssd.pid; please update the unit file accordingly.
[ 9.955870] systemd[1]: /usr/lib/systemd/system/iscsid.service:11: PIDFile= references a path below legacy directory /var/run/, updating /var/run/iscsid.pid â /run/iscsid.pid; please update the unit file accordingly.
[ 9.956083] systemd[1]: /usr/lib/systemd/system/iscsiuio.service:13: PIDFile= references a path below legacy directory /var/run/, updating /var/run/iscsiuio.pid â /run/iscsiuio.pid; please update the unit file accordingly.
[ 9.983719] systemd[1]: /usr/lib/systemd/system/sssd-kcm.socket:7: ListenStream= references a path below legacy directory /var/run/, updating /var/run/.heim_org.h5l.kcm-socket â /run/.heim_org.h5l.kcm-socket; please update the unit file accordingly.
[ 10.011461] systemd[1]: initrd-switch-root.service: Succeeded.
[ 10.011556] systemd[1]: Stopped Switch Root.
[ 10.011787] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.
[ 10.042867] EXT4-fs (dasda1): re-mounted. Opts: (null)
[ 10.360085] systemd-journald[1087]: Received client request to flush runtime journal.
[ 10.550102] VFIO - User Level meta-driver version: 0.3
[ 10.608696] genwqe 0000:00:00.0: enabling device (0000 -> 0002)
[ 10.609633] dasdconf.sh Warning: 0.0.3319 is already online, not configuring
[ 10.609924] dasdconf.sh Warning: 0.0.331a is already online, not configuring
[ 10.610250] dasdconf.sh Warning: 0.0.331b is already online, not configuring
[ 10.613015] dasdconf.sh Warning: 0.0.3318 is already online, not configuring
[ 10.951430] mlx5_ib: Mellanox Connect-IB Infiniband driver v5.0-0
[ 11.102829] XFS (dasdc1): Mounting V5 Filesystem
[ 11.113111] RPC: Registered named UNIX socket transport module.
[ 11.113114] RPC: Registered udp transport module.
[ 11.113115] RPC: Registered tcp transport module.
[ 11.113116] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 11.128347] XFS (dasdc1): Ending clean mount
[ 11.130744] xfs filesystem being mounted at /home supports timestamps until 2038 (0x7fffffff)
[ 11.159172] RPC: Registered rdma transport module.
[ 11.159175] RPC: Registered rdma backchannel transport module.
[ 12.286326] mlx5_core 0001:00:00.0 enP1s519: Link up
[ 12.289162] IPv6: ADDRCONF(NETDEV_CHANGE): enP1s519: link becomes ready
[ 12.406381] mlx5_core 0002:00:00.0 enP2s564: Link up
[ 12.511281] tun: Universal TUN/TAP device driver, 1.6
[ 12.511994] virbr0: port 1(virbr0-nic) entered blocking state
[ 12.511996] virbr0: port 1(virbr0-nic) entered disabled state
[ 12.512065] device virbr0-nic entered promiscuous mode
[ 12.806783] virbr0: port 1(virbr0-nic) entered blocking state
[ 12.806787] virbr0: port 1(virbr0-nic) entered listening state
[ 12.831055] virbr0: port 1(virbr0-nic) entered disabled state
[ 13.309576] IPv6: ADDRCONF(NETDEV_CHANGE): enP2s564: link becomes ready
[ 33.511826] hrtimer: interrupt took 650 ns
[ 111.139686] CPU34 path=/machine.slice/machine-test.slice/machine-qemu\x2d4\x2dtest11.s on_list=1 nr_running=1 p=[CPU 2/KVM 2445]
[ 111.139692] ------------[ cut here ]------------
[ 111.139693] rq->tmp_alone_branch != &rq->leaf_cfs_rq_list
[ 111.139702] WARNING: CPU: 34 PID: 5615 at kernel/sched/fair.c:380 enqueue_task_fair+0x3f6/0x4a8
[ 111.139704] Modules linked in: kvm xt_CHECKSUM xt_MASQUERADE nf_nat_tftp nf_conntrack_tftp xt_CT tun bridge stp llc xt_tcpudp ip6t_REJECT nf_reject_ipv6 ip6t_rpfilter ipt_REJECT nf_reject_ipv4 xt_conntrack ip6table_nat ip6table_mangle ip6table_raw ip6table_security iptable_nat nf_nat iptable_mangle iptable_raw iptable_security nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 ip_set nfnetlink ip6table_filter ip6_tables iptable_filter rpcrdma sunrpc rdma_ucm rdma_cm iw_cm ib_cm configfs mlx5_ib ib_uverbs s390_trng ghash_s390 prng ib_core aes_s390 des_s390 libdes sha3_512_s390 sha3_256_s390 sha512_s390 sha1_s390 genwqe_card vfio_ccw crc_itu_t vfio_mdev mdev vfio_iommu_type1 eadm_sch vfio zcrypt_cex4 sch_fq_codel ip_tables x_tables mlx5_core sha256_s390 sha_common pkey zcrypt rng_core autofs4
[ 111.139743] CPU: 34 PID: 5615 Comm: genksyms Not tainted 5.6.0-rc4+ #157
[ 111.139744] Hardware name: IBM 3906 M04 704 (LPAR)
[ 111.139746] Krnl PSW : 0404c00180000000 00000012a3f3ea32 (enqueue_task_fair+0x3fa/0x4a8)
[ 111.139748] R:0 T:1 IO:0 EX:0 Key:0 M:1 W:0 P:0 AS:3 CC:0 PM:0 RI:0 EA:3
[ 111.139750] Krnl GPRS: 00000000000003e0 0000001eb0d35400 000000000000002d 00000012a51f07c2
[ 111.139751] 000000000000002c 00000012a45aa3f8 0000000000000001 0400000000000000
[ 111.139753] 0000001f695ba000 000003e00116bb58 0000001eb0d35400 0000001fbd4a4928
[ 111.139780] 0000001a1a092000 0000001fbd4a3d00 00000012a3f3ea2e 000003e00116baa0
[ 111.139787] Krnl Code: 00000012a3f3ea22: c020005d49be larl %r2,00000012a4ae7d9e
00000012a3f3ea28: c0e5fffdcc48 brasl %r14,00000012a3ef82b8
#00000012a3f3ea2e: af000000 mc 0,0
>00000012a3f3ea32: a7f4febe brc 15,00000012a3f3e7ae
00000012a3f3ea36: ec2cfe68017f clij %r2,1,12,00000012a3f3e706
00000012a3f3ea3c: e310dd200004 lg %r1,3360(%r13)
00000012a3f3ea42: 58201098 l %r2,152(%r1)
00000012a3f3ea46: ec26fe63007e cij %r2,0,6,00000012a3f3e70c
[ 111.139802] Call Trace:
[ 111.139805] [<00000012a3f3ea32>] enqueue_task_fair+0x3fa/0x4a8
[ 111.139806] ([<00000012a3f3ea2e>] enqueue_task_fair+0x3f6/0x4a8)
[ 111.139809] [<00000012a3f2ebb8>] activate_task+0x88/0xf0
[ 111.139811] [<00000012a3f2f128>] ttwu_do_activate+0x58/0x78
[ 111.139813] [<00000012a3f30136>] try_to_wake_up+0x256/0x650
[ 111.139815] [<00000012a3f4eb3e>] swake_up_locked.part.0+0x2e/0x70
[ 111.139817] [<00000012a3f4ee5c>] swake_up_one+0x54/0x88
[ 111.139858] [<000003ff8046c07a>] kvm_vcpu_wake_up+0x52/0x78 [kvm]
[ 111.139881] [<000003ff804893a2>] kvm_s390_vcpu_wakeup+0x2a/0x40 [kvm]
[ 111.139911] [<000003ff80489b0e>] kvm_s390_idle_wakeup+0x6e/0xa0 [kvm]
[ 111.139918] [<00000012a3f99ebc>] __hrtimer_run_queues+0x114/0x2f0
[ 111.139929] [<00000012a3f9ac14>] hrtimer_interrupt+0x12c/0x2a8
[ 111.139934] [<00000012a3ebcc0c>] do_IRQ+0xac/0xb0
[ 111.139938] [<00000012a48e34c8>] ext_int_handler+0x128/0x12c
[ 111.139940] Last Breaking-Event-Address:
[ 111.139942] [<00000012a3ef8318>] __warn_printk+0x60/0x68
[ 111.139943] ---[ end trace 63b8303def5e99c8 ]---
[ 111.140565] CPU34 path=/user.slice on_list=1 nr_running=2 p=[make 5624]
[ 111.140573] CPU34 path=/user.slice on_list=1 nr_running=3 p=[make 4545]
[ 111.140576] CPU34 path=/user.slice on_list=1 nr_running=4 p=[make 4014]
[ 111.140579] CPU34 path=/user.slice on_list=1 nr_running=5 p=[make 4330]
[ 111.140583] CPU34 path=/user.slice on_list=1 nr_running=6 p=[make 4543]
[ 111.140587] CPU34 path=/user.slice on_list=1 nr_running=7 p=[make 4191]
[ 111.140589] CPU34 path=/user.slice on_list=1 nr_running=8 p=[make 4026]
[ 111.140593] CPU34 path=/user.slice on_list=1 nr_running=9 p=[make 4013]
[ 111.140595] CPU34 path=/user.slice on_list=1 nr_running=10 p=[make 4393]
[ 111.140599] CPU34 path=/user.slice on_list=1 nr_running=11 p=[make 4463]
[ 111.140602] CPU34 path=/user.slice on_list=1 nr_running=12 p=[make 4353]
[ 111.140604] CPU34 path=/user.slice on_list=1 nr_running=13 p=[make 4012]
[ 111.140607] CPU34 path=/user.slice on_list=1 nr_running=14 p=[make 4332]
[ 111.140746] CPU34 path=/user.slice on_list=1 nr_running=2 p=[make 5624]
[ 111.140756] CPU34 path=/user.slice on_list=1 nr_running=3 p=[make 4330]
[ 111.140760] CPU34 path=/user.slice on_list=1 nr_running=4 p=[make 4014]
[ 111.140763] CPU34 path=/user.slice on_list=1 nr_running=5 p=[make 4545]
[ 111.140766] CPU34 path=/user.slice on_list=1 nr_running=6 p=[make 4393]
[ 111.140773] CPU34 path=/user.slice on_list=1 nr_running=7 p=[make 4026]
[ 111.140777] CPU34 path=/user.slice on_list=1 nr_running=8 p=[make 4191]
[ 111.140784] CPU34 path=/user.slice on_list=1 nr_running=9 p=[make 4012]
[ 111.140792] CPU34 path=/user.slice on_list=1 nr_running=10 p=[make 4463]
[ 111.140799] CPU34 path=/user.slice on_list=1 nr_running=11 p=[make 4332]
[ 111.142850] CPU34 path=/user.slice on_list=1 nr_running=2 p=[make 5624]
[ 111.142862] CPU34 path=/user.slice on_list=1 nr_running=3 p=[make 4330]
[ 111.142867] CPU34 path=/user.slice on_list=1 nr_running=4 p=[make 4014]
[ 111.142870] CPU34 path=/user.slice on_list=1 nr_running=5 p=[make 4545]
[ 111.142872] CPU34 path=/user.slice on_list=1 nr_running=6 p=[make 4393]
[ 111.142881] CPU34 path=/user.slice on_list=1 nr_running=7 p=[make 4026]
[ 111.142886] CPU34 path=/user.slice on_list=1 nr_running=8 p=[make 4191]
[ 111.142893] CPU34 path=/user.slice on_list=1 nr_running=9 p=[make 4012]
[ 111.142921] CPU34 path=/user.slice on_list=1 nr_running=10 p=[make 4463]
[ 111.142930] CPU34 path=/user.slice on_list=1 nr_running=11 p=[make 4332]
[ 111.143545] CPU34 path=/user.slice on_list=1 nr_running=1 p=[genksyms 5615]
[ 111.144283] CPU34 path=/user.slice on_list=1 nr_running=1 p=[genksyms 5615]
[ 111.145172] CPU34 path=/user.slice on_list=1 nr_running=1 p=[genksyms 5615]
[ 111.145853] CPU34 path=/user.slice on_list=1 nr_running=1 p=[genksyms 5615]
[ 114.145675] CPU41 path=/machine.slice/machine-test.slice/machine-qemu\x2d7\x2dtest10.s on_list=1 nr_running=1 p=[CPU 1/KVM 2440]
[ 114.146949] CPU41 path=/user.slice on_list=1 nr_running=3 p=[gcc 10663]
[ 114.147034] CPU41 path=/user.slice on_list=1 nr_running=3 p=[make 4072]
[ 114.147250] CPU41 path=/user.slice on_list=1 nr_running=3 p=[make 4357]
[ 114.147262] CPU41 path=/user.slice on_list=1 nr_running=4 p=[make 8067]
[ 114.147264] CPU41 path=/user.slice on_list=1 nr_running=5 p=[make 4543]
[ 114.148178] CPU41 path=/user.slice on_list=1 nr_running=2 p=[sh 10659]
[ 114.148282] CPU41 path=/user.slice on_list=1 nr_running=2 p=[gcc 10658]
[ 114.148305] CPU41 path=/user.slice on_list=1 nr_running=3 p=[gcc 10668]
[ 114.150175] CPU41 path=/user.slice on_list=1 nr_running=2 p=[gcc 10658]
[ 114.150232] CPU41 path=/user.slice on_list=1 nr_running=2 p=[cc1 10663]
[ 114.169192] CPU41 path=/ on_list=1 nr_running=2 p=[ksoftirqd/41 216]
[ 114.193276] CPU41 path=/user.slice on_list=1 nr_running=2 p=[make 4357]
[ 114.193318] CPU41 path=/user.slice on_list=1 nr_running=3 p=[make 4543]
[ 114.193325] CPU41 path=/user.slice on_list=1 nr_running=4 p=[make 8067]
[ 114.649686] CPU43 path=/machine.slice/machine-test.slice/machine-qemu\x2d4\x2dtest11.s on_list=1 nr_running=1 p=[CPU 0/KVM 2437]
[ 114.655304] CPU43 path=/machine.slice/machine-production.slice/machine-qemu\x2d17\x2dt on_list=1 nr_running=1 p=[CPU 0/KVM 2587]
[ 114.665302] CPU43 path=/machine.slice/machine-production.slice/machine-qemu\x2d17\x2dt on_list=1 nr_running=1 p=[CPU 0/KVM 2587]
[ 114.670538] CPU43 path=/user.slice on_list=1 nr_running=2 p=[as 10614]
[ 114.670582] CPU43 path=/user.slice on_list=1 nr_running=2 p=[as 10614]
[ 114.675302] CPU43 path=/machine.slice/machine-production.slice/machine-qemu\x2d17\x2dt on_list=1 nr_running=1 p=[CPU 0/KVM 2587]
[ 114.676725] CPU43 path=/user.slice on_list=1 nr_running=2 p=[as 10614]
[ 114.939686] CPU42 path=/machine.slice/machine-test.slice/machine-qemu\x2d4\x2dtest11.s on_list=1 nr_running=1 p=[CPU 0/KVM 2437]
[ 120.639685] CPU33 path=/machine.slice/machine-test.slice/machine-qemu\x2d4\x2dtest11.s on_list=1 nr_running=1 p=[CPU 0/KVM 2437]
[ 122.145676] CPU54 path=/machine.slice/machine-test.slice/machine-qemu\x2d7\x2dtest10.s on_list=1 nr_running=1 p=[CPU 1/KVM 2440]
[ 122.148917] CPU54 path=/user.slice on_list=1 nr_running=4 p=[as 19656]
[ 122.149188] CPU54 path=/ on_list=1 nr_running=2 p=[kworker/54:1 453]
[ 122.179197] CPU54 path=/ on_list=1 nr_running=2 p=[ksoftirqd/54 281]
[ 122.193424] CPU54 path=/user.slice on_list=1 nr_running=4 p=[as 19656]
[ 127.049685] CPU35 path=/machine.slice/machine-test.slice/machine-qemu\x2d4\x2dtest11.s on_list=1 nr_running=1 p=[CPU 2/KVM 2445]
[ 132.228297] CPU6 path=/machine.slice/machine-test.slice/machine-qemu\x2d10\x2dtest14. on_list=1 nr_running=1 p=[CPU 2/KVM 2579]
[ 134.345678] CPU34 path=/machine.slice/machine-test.slice/machine-qemu\x2d7\x2dtest10.s on_list=1 nr_running=1 p=[CPU 2/KVM 2444]
[ 134.348906] CPU34 path=/user.slice on_list=1 nr_running=2 p=[as 32056]
[ 134.349078] CPU34 path=/user.slice on_list=1 nr_running=2 p=[as 32056]
[ 134.353372] CPU34 path=/user.slice on_list=1 nr_running=2 p=[as 32056]
[ 134.357981] CPU34 path=/user.slice on_list=1 nr_running=2 p=[as 32056]
[ 135.149687] CPU58 path=/machine.slice/machine-test.slice/machine-qemu\x2d4\x2dtest11.s on_list=1 nr_running=1 p=[CPU 2/KVM 2445]
[ 135.150236] CPU58 path=/user.slice on_list=1 nr_running=1 p=[genksyms 35088]
[ 135.152212] CPU58 path=/user.slice on_list=1 nr_running=1 p=[genksyms 35113]
[ 135.152940] CPU58 path=/user.slice on_list=1 nr_running=1 p=[genksyms 35113]
[ 135.165833] CPU58 path=/machine.slice/machine-production.slice/machine-qemu\x2d5\x2dte on_list=1 nr_running=1 p=[qemu-system-s39 2330]
[ 135.169227] CPU58 path=/machine.slice/machine-production.slice/machine-qemu\x2d5\x2dte on_list=1 nr_running=1 p=[qemu-system-s39 2330]
[ 135.194516] CPU58 path=/user.slice on_list=1 nr_running=2 p=[cc1 35115]
[ 135.198656] CPU58 path=/user.slice on_list=1 nr_running=3 p=[sh 34629]
[ 135.199181] CPU58 path=/system.slice on_list=1 nr_running=1 p=[systemd-journal 1087]
[ 135.199205] CPU58 path=/ on_list=1 nr_running=3 p=[ksoftirqd/58 301]
[ 146.075678] CPU32 path=/machine.slice/machine-test.slice/machine-qemu\x2d7\x2dtest10.s on_list=1 nr_running=1 p=[CPU 1/KVM 2440]
[ 146.097410] CPU32 path=/user.slice on_list=1 nr_running=3 p=[as 46220]
[ 146.097522] CPU32 path=/user.slice on_list=1 nr_running=3 p=[as 46220]
[ 148.449694] CPU5 path=/machine.slice/machine-test.slice/machine-qemu\x2d4\x2dtest11.s on_list=1 nr_running=1 p=[CPU 2/KVM 2445]
[ 152.649687] CPU3 path=/machine.slice/machine-test.slice/machine-qemu\x2d4\x2dtest11.s on_list=1 nr_running=1 p=[CPU 0/KVM 2437]
[ 152.659181] CPU3 path=/ on_list=1 nr_running=2 p=[rcu_sched 11]
[ 152.689179] CPU3 path=/ on_list=1 nr_running=2 p=[rcu_sched 11]
[ 154.579686] CPU3 path=/machine.slice/machine-test.slice/machine-qemu\x2d4\x2dtest11.s on_list=1 nr_running=1 p=[CPU 1/KVM 2441]
[ 154.580233] CPU3 path=/ on_list=1 nr_running=2 p=[kworker/u680:0 8]
[ 154.580242] CPU3 path=/user.slice on_list=1 nr_running=2 p=[sshd 1821]
[ 154.585388] CPU3 path=/ on_list=1 nr_running=2 p=[kworker/u680:0 8]
[ 154.585396] CPU3 path=/user.slice on_list=1 nr_running=2 p=[sshd 1821]
[ 154.585447] CPU3 path=/ on_list=1 nr_running=2 p=[kworker/u680:0 8]
[ 154.585452] CPU3 path=/user.slice on_list=1 nr_running=2 p=[sshd 1821]
[ 154.592783] CPU3 path=/user.slice on_list=1 nr_running=1 p=[cc1 57925]
[ 154.593378] CPU3 path=/user.slice on_list=1 nr_running=1 p=[make 58331]
[ 154.593413] CPU3 path=/user.slice on_list=1 nr_running=1 p=[cc1 57128]
[ 154.593733] CPU3 path=/user.slice on_list=1 nr_running=2 p=[gcc 57228]
[ 154.593997] CPU3 path=/user.slice on_list=1 nr_running=2 p=[gcc 57228]
[ 154.594007] CPU3 path=/user.slice on_list=1 nr_running=3 p=[sh 57226]
[ 154.594365] CPU3 path=/user.slice on_list=1 nr_running=3 p=[sh 58345]
[ 154.595243] CPU3 path=/ on_list=1 nr_running=2 p=[kworker/u680:0 8]
[ 154.595249] CPU3 path=/user.slice on_list=1 nr_running=2 p=[sshd 1821]
[ 154.598249] CPU3 path=/ on_list=1 nr_running=2 p=[kworker/u680:0 8]
[ 154.598257] CPU3 path=/user.slice on_list=1 nr_running=2 p=[sshd 1821]
[ 155.169688] CPU10 path=/machine.slice/machine-test.slice/machine-qemu\x2d4\x2dtest11.s on_list=1 nr_running=1 p=[CPU 1/KVM 2441]
[ 155.171423] CPU10 path=/user.slice on_list=1 nr_running=1 p=[gcc 57436]
[ 155.171761] CPU10 path=/user.slice on_list=1 nr_running=1 p=[gcc 57436]
[ 155.171789] CPU10 path=/ on_list=1 nr_running=1 p=[kworker/10:1 439]
[ 155.172119] CPU10 path=/user.slice on_list=1 nr_running=1 p=[sh 58915]
[ 155.176862] CPU10 path=/ on_list=1 nr_running=2 p=[kworker/10:1H 855]
[ 155.176871] CPU10 path=/ on_list=1 nr_running=3 p=[ksoftirqd/10 61]
[ 155.176880] CPU10 path=/user.slice on_list=1 nr_running=1 p=[fixdep 58915]
[ 155.176904] CPU10 path=/ on_list=1 nr_running=1 p=[kworker/10:1 439]
[ 155.177016] CPU10 path=/user.slice on_list=1 nr_running=1 p=[sh 58939]
[ 155.229683] CPU10 path=/machine.slice/machine-test.slice/machine-qemu\x2d4\x2dtest11.s on_list=1 nr_running=1 p=[CPU 1/KVM 2441]
[ 155.229843] CPU10 path=/user.slice on_list=1 nr_running=1 p=[as 58433]
[ 155.229886] CPU10 path=/user.slice on_list=1 nr_running=1 p=[as 58433]
[ 155.229926] CPU10 path=/user.slice on_list=1 nr_running=1 p=[as 58433]
[ 155.229932] CPU10 path=/machine.slice/machine-production.slice/machine-qemu\x2d17\x2dt on_list=1 nr_running=1 p=[CPU 0/KVM 2587]
[ 155.229960] CPU10 path=/machine.slice/machine-production.slice/machine-qemu\x2d17\x2dt on_list=1 nr_running=1 p=[CPU 0/KVM 2587]
[ 155.230074] CPU10 path=/machine.slice/machine-production.slice/machine-qemu\x2d17\x2dt on_list=1 nr_running=1 p=[CPU 0/KVM 2587]
[ 155.230564] CPU10 path=/user.slice on_list=1 nr_running=1 p=[cc1 58432]
[ 155.231238] CPU10 path=/user.slice on_list=1 nr_running=1 p=[make 16571]
[ 155.231563] CPU10 path=/user.slice on_list=1 nr_running=2 p=[make 59029]
[ 155.231706] CPU10 path=/user.slice on_list=1 nr_running=2 p=[make 16571]
[ 155.232025] CPU10 path=/user.slice on_list=1 nr_running=3 p=[make 59030]
[ 155.233386] CPU10 path=/ on_list=1 nr_running=2 p=[kworker/10:1 439]
[ 155.233401] CPU10 path=/user.slice on_list=1 nr_running=2 p=[sh 59029]
[ 155.233500] CPU10 path=/user.slice on_list=1 nr_running=2 p=[make 16571]
[ 155.233504] CPU10 path=/ on_list=1 nr_running=2 p=[kworker/10:1 439]
[ 155.233707] CPU10 path=/user.slice on_list=1 nr_running=3 p=[make 59032]
[ 155.234966] CPU10 path=/user.slice on_list=1 nr_running=2 p=[sh 59030]
[ 155.234976] CPU10 path=/ on_list=1 nr_running=2 p=[kworker/10:1 439]
[ 155.235158] CPU10 path=/user.slice on_list=1 nr_running=1 p=[make 16571]
[ 155.235303] CPU10 path=/machine.slice/machine-production.slice/machine-qemu\x2d17\x2dt on_list=1 nr_running=1 p=[CPU 0/KVM 2587]
[ 155.235376] CPU10 path=/user.slice on_list=1 nr_running=2 p=[make 59034]
[ 155.235466] CPU10 path=/user.slice on_list=1 nr_running=2 p=[make 16571]
[ 155.235630] CPU10 path=/user.slice on_list=1 nr_running=3 p=[make 59036]
[ 155.236974] CPU10 path=/user.slice on_list=1 nr_running=2 p=[sh 59034]
[ 155.237072] CPU10 path=/ on_list=1 nr_running=1 p=[kworker/10:1 439]
[ 155.237173] CPU10 path=/user.slice on_list=1 nr_running=1 p=[make 16571]
[ 155.237374] CPU10 path=/user.slice on_list=1 nr_running=2 p=[make 59038]
[ 155.237469] CPU10 path=/user.slice on_list=1 nr_running=2 p=[make 16571]
[ 155.237634] CPU10 path=/user.slice on_list=1 nr_running=3 p=[make 59040]
[ 155.845677] CPU46 path=/machine.slice/machine-test.slice/machine-qemu\x2d7\x2dtest10.s on_list=1 nr_running=1 p=[CPU 0/KVM 2435]
[ 156.219684] CPU20 path=/machine.slice/machine-test.slice/machine-qemu\x2d4\x2dtest11.s on_list=1 nr_running=1 p=[CPU 0/KVM 2437]
[ 156.222028] CPU20 path=/machine.slice/machine-production.slice/machine-qemu\x2d5\x2dte on_list=1 nr_running=1 p=[CPU 1/KVM 2451]
[ 156.222035] CPU20 path=/machine.slice/machine-production.slice/machine-qemu\x2d5\x2dte on_list=1 nr_running=1 p=[CPU 0/KVM 2449]
[ 156.222273] CPU20 path=/machine.slice/machine-production.slice/machine-qemu\x2d5\x2dte on_list=1 nr_running=1 p=[CPU 1/KVM 2451]
[ 156.222362] CPU20 path=/machine.slice/machine-production.slice/machine-qemu\x2d5\x2dte on_list=1 nr_running=1 p=[CPU 1/KVM 2451]
[ 156.223501] CPU20 path=/user.slice on_list=1 nr_running=1 p=[as 59244]
[ 156.223618] CPU20 path=/user.slice on_list=1 nr_running=1 p=[as 59244]
[ 156.223736] CPU20 path=/user.slice on_list=1 nr_running=1 p=[as 59244]
[ 156.223975] CPU20 path=/machine.slice/machine-production.slice/machine-qemu\x2d5\x2dte on_list=1 nr_running=1 p=[CPU 1/KVM 2451]
[ 156.224332] CPU20 path=/machine.slice/machine-production.slice/machine-qemu\x2d5\x2dte on_list=1 nr_running=1 p=[CPU 1/KVM 2451]
[ 156.224367] CPU20 path=/machine.slice/machine-production.slice/machine-qemu\x2d5\x2dte on_list=1 nr_running=1 p=[CPU 1/KVM 2451]
[ 156.224392] CPU20 path=/machine.slice/machine-production.slice/machine-qemu\x2d5\x2dte on_list=1 nr_running=1 p=[CPU 1/KVM 2451]
[ 156.224545] CPU20 path=/machine.slice/machine-production.slice/machine-qemu\x2d5\x2dte on_list=1 nr_running=1 p=[CPU 1/KVM 2451]
[ 156.227839] CPU20 path=/machine.slice/machine-production.slice/machine-qemu\x2d3\x2dte on_list=1 nr_running=1 p=[CPU 1/KVM 2442]
[ 175.939686] CPU52 path=/machine.slice/machine-test.slice/machine-qemu\x2d4\x2dtest11.s on_list=1 nr_running=1 p=[CPU 0/KVM 2437]
[ 175.939947] CPU52 path=/user.slice on_list=1 nr_running=2 p=[cc1 60934]
[ 175.943973] CPU52 path=/user.slice on_list=1 nr_running=1 p=[as 60936]
[ 175.943979] CPU52 path=/user.slice on_list=1 nr_running=2 p=[gcc 60930]
[ 175.943988] CPU52 path=/ on_list=1 nr_running=2 p=[kworker/52:2 1635]
[ 175.944207] CPU52 path=/user.slice on_list=1 nr_running=1 p=[gcc 60930]
[ 175.944217] CPU52 path=/ on_list=1 nr_running=1 p=[kworker/52:2 1635]
[ 200.985573] ctcm: CTCM driver initialized
[ 201.016223] lcs: Loading LCS driver
[ 224.672306] CPU22 path=/machine.slice/machine-test.slice/machine-qemu\x2d14\x2dtest2.s on_list=1 nr_running=1 p=[IO mon_iothread 2543]
[ 224.672461] CPU22 path=/ on_list=1 nr_running=1 p=[kworker/u680:1 344]
[ 224.672543] CPU22 path=/user.slice on_list=1 nr_running=1 p=[virsh 80195]
[ 224.672563] CPU22 path=/user.slice on_list=1 nr_running=1 p=[virsh 80195]
[ 224.672642] CPU22 path=/system.slice on_list=1 nr_running=1 p=[sssd_nss 1535]
[ 224.673148] CPU22 path=/system.slice on_list=1 nr_running=1 p=[sssd_nss 1535]
[ 224.673208] CPU22 path=/system.slice on_list=1 nr_running=1 p=[sssd_nss 1535]
[ 224.673318] CPU22 path=/user.slice on_list=1 nr_running=1 p=[virsh 80195]
[ 224.673342] CPU22 path=/user.slice on_list=1 nr_running=1 p=[virsh 80195]
[ 224.673363] CPU22 path=/user.slice on_list=1 nr_running=1 p=[virsh 80195]
[ 224.673378] CPU22 path=/user.slice on_list=1 nr_running=1 p=[virsh 80195]
[ 224.673408] CPU22 path=/system.slice on_list=1 nr_running=1 p=[libvirtd 1597]
[ 224.673414] CPU22 path=/user.slice on_list=1 nr_running=1 p=[virsh 80186]
[ 224.674737] CPU22 path=/user.slice on_list=1 nr_running=1 p=[virsh 80186]
[ 224.674749] CPU22 path=/ on_list=1 nr_running=1 p=[kworker/22:1 436]