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:59:58 EST
On 04.03.20 20:38, Christian Borntraeger wrote:
>
>
> 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.
New occurence (with just one extra debug line)
[ 0.229052] Linux version 5.6.0-rc3+ (cborntra@xxxxxxxxxxxxxxxxx) (gcc version 9.2.1 20190827 (Red Hat 9.2.1-1) (GCC)) #159 SMP Wed Mar 4 20:36:45 CET 2020
[ 0.229055] setup: Linux is running natively in 64-bit mode
[ 0.229106] setup: The maximum memory size is 131072MB
[ 0.229113] setup: Reserving 1024MB of memory at 130048MB for crashkernel (System RAM: 130048MB)
[ 0.229202] cpu: 64 configured CPUs, 0 standby CPUs
[ 0.229271] cpu: The CPU configuration topology of the machine is: 0 0 4 2 3 10 / 4
[ 0.230115] Write protected kernel read-only data: 13524k
[ 0.230852] Zone ranges:
[ 0.230853] DMA [mem 0x0000000000000000-0x000000007fffffff]
[ 0.230854] Normal [mem 0x0000000080000000-0x0000001fffffffff]
[ 0.230855] Movable zone start for each node
[ 0.230856] Early memory node ranges
[ 0.230857] node 0: [mem 0x0000000000000000-0x0000001fffffffff]
[ 0.230865] Initmem setup node 0 [mem 0x0000000000000000-0x0000001fffffffff]
[ 0.230866] On node 0 totalpages: 33554432
[ 0.230867] DMA zone: 8192 pages used for memmap
[ 0.230867] DMA zone: 0 pages reserved
[ 0.230868] DMA zone: 524288 pages, LIFO batch:63
[ 0.244964] Normal zone: 516096 pages used for memmap
[ 0.244965] Normal zone: 33030144 pages, LIFO batch:63
[ 0.264910] percpu: Embedded 33 pages/cpu s97280 r8192 d29696 u135168
[ 0.264919] pcpu-alloc: s97280 r8192 d29696 u135168 alloc=33*4096
[ 0.264919] pcpu-alloc: [0] 000 [0] 001 [0] 002 [0] 003
[ 0.264921] pcpu-alloc: [0] 004 [0] 005 [0] 006 [0] 007
[ 0.264922] pcpu-alloc: [0] 008 [0] 009 [0] 010 [0] 011
[ 0.264924] pcpu-alloc: [0] 012 [0] 013 [0] 014 [0] 015
[ 0.264925] pcpu-alloc: [0] 016 [0] 017 [0] 018 [0] 019
[ 0.264926] pcpu-alloc: [0] 020 [0] 021 [0] 022 [0] 023
[ 0.264927] pcpu-alloc: [0] 024 [0] 025 [0] 026 [0] 027
[ 0.264929] pcpu-alloc: [0] 028 [0] 029 [0] 030 [0] 031
[ 0.264930] pcpu-alloc: [0] 032 [0] 033 [0] 034 [0] 035
[ 0.264931] pcpu-alloc: [0] 036 [0] 037 [0] 038 [0] 039
[ 0.264932] pcpu-alloc: [0] 040 [0] 041 [0] 042 [0] 043
[ 0.264933] pcpu-alloc: [0] 044 [0] 045 [0] 046 [0] 047
[ 0.264935] pcpu-alloc: [0] 048 [0] 049 [0] 050 [0] 051
[ 0.264936] pcpu-alloc: [0] 052 [0] 053 [0] 054 [0] 055
[ 0.264937] pcpu-alloc: [0] 056 [0] 057 [0] 058 [0] 059
[ 0.264938] pcpu-alloc: [0] 060 [0] 061 [0] 062 [0] 063
[ 0.264939] pcpu-alloc: [0] 064 [0] 065 [0] 066 [0] 067
[ 0.264941] pcpu-alloc: [0] 068 [0] 069 [0] 070 [0] 071
[ 0.264942] pcpu-alloc: [0] 072 [0] 073 [0] 074 [0] 075
[ 0.264943] pcpu-alloc: [0] 076 [0] 077 [0] 078 [0] 079
[ 0.264944] pcpu-alloc: [0] 080 [0] 081 [0] 082 [0] 083
[ 0.264946] pcpu-alloc: [0] 084 [0] 085 [0] 086 [0] 087
[ 0.264947] pcpu-alloc: [0] 088 [0] 089 [0] 090 [0] 091
[ 0.264948] pcpu-alloc: [0] 092 [0] 093 [0] 094 [0] 095
[ 0.264949] pcpu-alloc: [0] 096 [0] 097 [0] 098 [0] 099
[ 0.264951] pcpu-alloc: [0] 100 [0] 101 [0] 102 [0] 103
[ 0.264952] pcpu-alloc: [0] 104 [0] 105 [0] 106 [0] 107
[ 0.264953] pcpu-alloc: [0] 108 [0] 109 [0] 110 [0] 111
[ 0.264954] pcpu-alloc: [0] 112 [0] 113 [0] 114 [0] 115
[ 0.264956] pcpu-alloc: [0] 116 [0] 117 [0] 118 [0] 119
[ 0.264957] pcpu-alloc: [0] 120 [0] 121 [0] 122 [0] 123
[ 0.264958] pcpu-alloc: [0] 124 [0] 125 [0] 126 [0] 127
[ 0.264959] pcpu-alloc: [0] 128 [0] 129 [0] 130 [0] 131
[ 0.264961] pcpu-alloc: [0] 132 [0] 133 [0] 134 [0] 135
[ 0.264962] pcpu-alloc: [0] 136 [0] 137 [0] 138 [0] 139
[ 0.264963] pcpu-alloc: [0] 140 [0] 141 [0] 142 [0] 143
[ 0.264964] pcpu-alloc: [0] 144 [0] 145 [0] 146 [0] 147
[ 0.264966] pcpu-alloc: [0] 148 [0] 149 [0] 150 [0] 151
[ 0.264967] pcpu-alloc: [0] 152 [0] 153 [0] 154 [0] 155
[ 0.264968] pcpu-alloc: [0] 156 [0] 157 [0] 158 [0] 159
[ 0.264969] pcpu-alloc: [0] 160 [0] 161 [0] 162 [0] 163
[ 0.264971] pcpu-alloc: [0] 164 [0] 165 [0] 166 [0] 167
[ 0.264972] pcpu-alloc: [0] 168 [0] 169 [0] 170 [0] 171
[ 0.264973] pcpu-alloc: [0] 172 [0] 173 [0] 174 [0] 175
[ 0.264974] pcpu-alloc: [0] 176 [0] 177 [0] 178 [0] 179
[ 0.264976] pcpu-alloc: [0] 180 [0] 181 [0] 182 [0] 183
[ 0.264977] pcpu-alloc: [0] 184 [0] 185 [0] 186 [0] 187
[ 0.264978] pcpu-alloc: [0] 188 [0] 189 [0] 190 [0] 191
[ 0.264979] pcpu-alloc: [0] 192 [0] 193 [0] 194 [0] 195
[ 0.264981] pcpu-alloc: [0] 196 [0] 197 [0] 198 [0] 199
[ 0.264982] pcpu-alloc: [0] 200 [0] 201 [0] 202 [0] 203
[ 0.264983] pcpu-alloc: [0] 204 [0] 205 [0] 206 [0] 207
[ 0.264984] pcpu-alloc: [0] 208 [0] 209 [0] 210 [0] 211
[ 0.264985] pcpu-alloc: [0] 212 [0] 213 [0] 214 [0] 215
[ 0.264987] pcpu-alloc: [0] 216 [0] 217 [0] 218 [0] 219
[ 0.264988] pcpu-alloc: [0] 220 [0] 221 [0] 222 [0] 223
[ 0.264989] pcpu-alloc: [0] 224 [0] 225 [0] 226 [0] 227
[ 0.264990] pcpu-alloc: [0] 228 [0] 229 [0] 230 [0] 231
[ 0.264991] pcpu-alloc: [0] 232 [0] 233 [0] 234 [0] 235
[ 0.264993] pcpu-alloc: [0] 236 [0] 237 [0] 238 [0] 239
[ 0.264994] pcpu-alloc: [0] 240 [0] 241 [0] 242 [0] 243
[ 0.264995] pcpu-alloc: [0] 244 [0] 245 [0] 246 [0] 247
[ 0.264996] pcpu-alloc: [0] 248 [0] 249 [0] 250 [0] 251
[ 0.264998] pcpu-alloc: [0] 252 [0] 253 [0] 254 [0] 255
[ 0.264999] pcpu-alloc: [0] 256 [0] 257 [0] 258 [0] 259
[ 0.265000] pcpu-alloc: [0] 260 [0] 261 [0] 262 [0] 263
[ 0.265001] pcpu-alloc: [0] 264 [0] 265 [0] 266 [0] 267
[ 0.265002] pcpu-alloc: [0] 268 [0] 269 [0] 270 [0] 271
[ 0.265004] pcpu-alloc: [0] 272 [0] 273 [0] 274 [0] 275
[ 0.265005] pcpu-alloc: [0] 276 [0] 277 [0] 278 [0] 279
[ 0.265006] pcpu-alloc: [0] 280 [0] 281 [0] 282 [0] 283
[ 0.265007] pcpu-alloc: [0] 284 [0] 285 [0] 286 [0] 287
[ 0.265009] pcpu-alloc: [0] 288 [0] 289 [0] 290 [0] 291
[ 0.265010] pcpu-alloc: [0] 292 [0] 293 [0] 294 [0] 295
[ 0.265011] pcpu-alloc: [0] 296 [0] 297 [0] 298 [0] 299
[ 0.265012] pcpu-alloc: [0] 300 [0] 301 [0] 302 [0] 303
[ 0.265013] pcpu-alloc: [0] 304 [0] 305 [0] 306 [0] 307
[ 0.265015] pcpu-alloc: [0] 308 [0] 309 [0] 310 [0] 311
[ 0.265016] pcpu-alloc: [0] 312 [0] 313 [0] 314 [0] 315
[ 0.265017] pcpu-alloc: [0] 316 [0] 317 [0] 318 [0] 319
[ 0.265018] pcpu-alloc: [0] 320 [0] 321 [0] 322 [0] 323
[ 0.265019] pcpu-alloc: [0] 324 [0] 325 [0] 326 [0] 327
[ 0.265021] pcpu-alloc: [0] 328 [0] 329 [0] 330 [0] 331
[ 0.265022] pcpu-alloc: [0] 332 [0] 333 [0] 334 [0] 335
[ 0.265023] pcpu-alloc: [0] 336 [0] 337 [0] 338 [0] 339
[ 0.265049] Built 1 zonelists, mobility grouping on. Total pages: 33030144
[ 0.265050] Policy zone: Normal
[ 0.265051] 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.266109] printk: log_buf_len individual max cpu contribution: 4096 bytes
[ 0.266110] printk: log_buf_len total cpu_extra contributions: 1388544 bytes
[ 0.266111] printk: log_buf_len min size: 131072 bytes
[ 0.266445] printk: log_buf_len: 2097152 bytes
[ 0.266446] printk: early log buf free: 123876(94%)
[ 0.276285] Dentry cache hash table entries: 8388608 (order: 14, 67108864 bytes, linear)
[ 0.280904] Inode-cache hash table entries: 4194304 (order: 13, 33554432 bytes, linear)
[ 0.280941] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.317267] Memory: 2315096K/134217728K available (10452K kernel code, 2024K rwdata, 3072K rodata, 3932K init, 852K bss, 3355708K reserved, 0K cma-reserved)
[ 0.317724] SLUB: HWalign=256, Order=0-3, MinObjects=0, CPUs=340, Nodes=1
[ 0.317774] ftrace: allocating 31563 entries in 124 pages
[ 0.322372] ftrace: allocated 124 pages with 5 groups
[ 0.323313] rcu: Hierarchical RCU implementation.
[ 0.323313] rcu: RCU event tracing is enabled.
[ 0.323314] rcu: RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=340.
[ 0.323315] Tasks RCU enabled.
[ 0.323316] rcu: RCU calculated value of scheduler-enlistment delay is 11 jiffies.
[ 0.323317] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=340
[ 0.326356] NR_IRQS: 3, nr_irqs: 3, preallocated irqs: 3
[ 0.326494] clocksource: tod: mask: 0xffffffffffffffff max_cycles: 0x3b0a9be803b0a9, max_idle_ns: 1805497147909793 ns
[ 0.326764] Console: colour dummy device 80x25
[ 0.431448] printk: console [ttyS0] enabled
[ 0.526088] Calibrating delay loop (skipped)... 21881.00 BogoMIPS preset
[ 0.526089] pid_max: default: 348160 minimum: 2720
[ 0.526240] LSM: Security Framework initializing
[ 0.526272] SELinux: Initializing.
[ 0.526529] Mount-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[ 0.526675] Mountpoint-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[ 0.527718] rcu: Hierarchical SRCU implementation.
[ 0.530478] smp: Bringing up secondary CPUs ...
[ 0.544916] smp: Brought up 1 node, 64 CPUs
[ 1.570355] node 0 initialised, 32136731 pages in 1020ms
[ 1.597908] devtmpfs: initialized
[ 1.598796] random: get_random_u32 called from bucket_table_alloc.isra.0+0x82/0x120 with crng_init=0
[ 1.599376] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 1.600153] futex hash table entries: 131072 (order: 13, 33554432 bytes, vmalloc)
[ 1.604749] xor: automatically using best checksumming function xc
[ 1.604926] NET: Registered protocol family 16
[ 1.604962] audit: initializing netlink subsys (disabled)
[ 1.605034] audit: type=2000 audit(1583350720.705:1): state=initialized audit_enabled=0 res=1
[ 1.605170] Spectre V2 mitigation: etokens
[ 1.605877] random: fast init done
[ 1.612650] HugeTLB registered 1.00 MiB page size, pre-allocated 0 pages
[ 1.866553] raid6: vx128x8 gen() 21598 MB/s
[ 2.036503] raid6: vx128x8 xor() 13323 MB/s
[ 2.036505] raid6: using algorithm vx128x8 gen() 21598 MB/s
[ 2.036505] raid6: .... xor() 13323 MB/s, rmw enabled
[ 2.036506] raid6: using s390xc recovery algorithm
[ 2.036881] iommu: Default domain type: Translated
[ 2.037025] SCSI subsystem initialized
[ 2.100086] PCI host bridge to bus 0000:00
[ 2.100093] pci_bus 0000:00: root bus resource [mem 0x8000000000000000-0x8000000007ffffff 64bit pref]
[ 2.100096] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
[ 2.100170] pci 0000:00:00.0: [1014:044b] type 00 class 0x120000
[ 2.100231] pci 0000:00:00.0: reg 0x10: [mem 0xffffd80008000000-0xffffd8000fffffff 64bit pref]
[ 2.100547] 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.100590] pci 0000:00:00.0: Adding to iommu group 0
[ 2.100601] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 00
[ 2.102924] PCI host bridge to bus 0001:00
[ 2.102926] pci_bus 0001:00: root bus resource [mem 0x8001000000000000-0x80010000000fffff 64bit pref]
[ 2.102929] pci_bus 0001:00: No busn resource found for root bus, will use [bus 00-ff]
[ 2.103023] pci 0001:00:00.0: [15b3:1016] type 00 class 0x020000
[ 2.103129] pci 0001:00:00.0: reg 0x10: [mem 0xffffd40002000000-0xffffd400020fffff 64bit pref]
[ 2.103289] pci 0001:00:00.0: enabling Extended Tags
[ 2.103793] 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.103831] pci 0001:00:00.0: Adding to iommu group 1
[ 2.103840] pci_bus 0001:00: busn_res: [bus 00-ff] end is updated to 00
[ 2.106095] PCI host bridge to bus 0002:00
[ 2.106097] pci_bus 0002:00: root bus resource [mem 0x8002000000000000-0x80020000000fffff 64bit pref]
[ 2.106099] pci_bus 0002:00: No busn resource found for root bus, will use [bus 00-ff]
[ 2.106184] pci 0002:00:00.0: [15b3:1016] type 00 class 0x020000
[ 2.106284] pci 0002:00:00.0: reg 0x10: [mem 0xffffd40008000000-0xffffd400080fffff 64bit pref]
[ 2.106439] pci 0002:00:00.0: enabling Extended Tags
[ 2.107033] 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.107068] pci 0002:00:00.0: Adding to iommu group 2
[ 2.107074] pci_bus 0002:00: busn_res: [bus 00-ff] end is updated to 00
[ 2.669299] VFS: Disk quotas dquot_6.6.0
[ 2.669354] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 2.670694] random: crng init done
[ 2.671085] NET: Registered protocol family 2
[ 2.671733] tcp_listen_portaddr_hash hash table entries: 65536 (order: 8, 1048576 bytes, linear)
[ 2.672293] TCP established hash table entries: 524288 (order: 10, 4194304 bytes, vmalloc)
[ 2.674302] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes, linear)
[ 2.674808] TCP: Hash tables configured (established 524288 bind 65536)
[ 2.675133] UDP hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc)
[ 2.676140] UDP-Lite hash table entries: 65536 (order: 9, 2097152 bytes, vmalloc)
[ 2.677625] NET: Registered protocol family 1
[ 2.677828] Trying to unpack rootfs image as initramfs...
[ 3.248308] Freeing initrd memory: 43596K
[ 3.249509] alg: No test for crc32be (crc32be-vx)
[ 3.253769] Initialise system trusted keyrings
[ 3.253823] workingset: timestamp_bits=45 max_order=25 bucket_order=0
[ 3.254971] fuse: init (API version 7.31)
[ 3.255041] SGI XFS with ACLs, security attributes, realtime, quota, no debug enabled
[ 3.261726] Key type asymmetric registered
[ 3.261728] Asymmetric key parser 'x509' registered
[ 3.261733] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[ 3.261934] io scheduler mq-deadline registered
[ 3.261936] io scheduler kyber registered
[ 3.261957] io scheduler bfq registered
[ 3.262765] atomic64_test: passed
[ 3.262816] hvc_iucv: The z/VM IUCV HVC device driver cannot be used without z/VM
[ 3.269334] brd: module loaded
[ 3.269693] cio: Channel measurement facility initialized using format extended (mode autodetected)
[ 3.269968] Discipline DIAG cannot be used without z/VM
[ 5.124916] sclp_sd: No data is available for the config data entity
[ 5.341297] qeth: loading core functions
[ 5.341358] qeth: register layer 2 discipline
[ 5.341360] qeth: register layer 3 discipline
[ 5.341883] NET: Registered protocol family 10
[ 5.342820] Segment Routing with IPv6
[ 5.342835] NET: Registered protocol family 17
[ 5.342845] Key type dns_resolver registered
[ 5.342935] registered taskstats version 1
[ 5.342940] Loading compiled-in X.509 certificates
[ 5.382486] Loaded X.509 cert 'Build time autogenerated kernel key: c46ba92ee388c82c5891ee836c9c20b752cdfac5'
[ 5.383144] zswap: default zpool zbud not available
[ 5.383145] zswap: pool creation failed
[ 5.383866] Key type ._fscrypt registered
[ 5.383867] Key type .fscrypt registered
[ 5.383868] Key type fscrypt-provisioning registered
[ 5.384137] Btrfs loaded, crc32c=crc32c-vx
[ 5.388723] Key type big_key registered
[ 5.388729] ima: No TPM chip found, activating TPM-bypass!
[ 5.388732] ima: Allocated hash algorithm: sha256
[ 5.388740] ima: No architecture policies found
[ 5.389834] Freeing unused kernel memory: 3932K
[ 5.446574] Write protected read-only-after-init data: 68k
[ 5.446577] Run /init as init process
[ 5.446577] with arguments:
[ 5.446578] /init
[ 5.446578] with environment:
[ 5.446578] HOME=/
[ 5.446578] TERM=linux
[ 5.446578] BOOT_IMAGE=
[ 5.446579] crashkernel=1G
[ 5.446579] dyndbg=module=vhost +plt
[ 5.461019] systemd[1]: Inserted module 'autofs4'
[ 5.462181] 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.462869] systemd[1]: Detected architecture s390x.
[ 5.462871] systemd[1]: Running in initial RAM disk.
[ 5.462923] systemd[1]: Set hostname to <m83lp52.lnxne.boe>.
[ 5.503062] systemd[1]: Reached target Local File Systems.
[ 5.503120] systemd[1]: Reached target Slices.
[ 5.503143] systemd[1]: Reached target Swap.
[ 5.503160] systemd[1]: Reached target Timers.
[ 5.503254] systemd[1]: Listening on Journal Audit Socket.
[ 5.503305] systemd[1]: Listening on Journal Socket (/dev/log).
[ 5.782907] audit: type=1130 audit(1583350724.885: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.792394] audit: type=1130 audit(1583350724.895: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.869558] audit: type=1130 audit(1583350725.975: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.885592] audit: type=1130 audit(1583350725.985: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.886066] audit: type=1334 audit(1583350725.985:6): prog-id=6 op=LOAD
[ 6.886093] audit: type=1334 audit(1583350725.985:7): prog-id=7 op=LOAD
[ 7.106613] audit: type=1130 audit(1583350726.215: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'
[ 7.110846] qeth 0.0.bd00: Priority Queueing not supported
[ 7.111597] qeth 0.0.bd00: portname is deprecated and is ignored
[ 7.112828] dasd-eckd 0.0.3318: A channel path to the device has become operational
[ 7.112971] dasd-eckd 0.0.3319: A channel path to the device has become operational
[ 7.113686] dasd-eckd 0.0.331a: A channel path to the device has become operational
[ 7.113910] dasd-eckd 0.0.331b: A channel path to the device has become operational
[ 7.117112] qdio: 0.0.bd02 OSA on SC 159b using AI:1 QEBSM:0 PRI:1 TDD:1 SIGA: W AP
[ 7.123509] dasd-eckd 0.0.3319: New DASD 3390/0E (CU 3990/01) with 262668 cylinders, 15 heads, 224 sectors
[ 7.126422] dasd-eckd 0.0.3319: DASD with 4 KB/block, 189120960 KB total size, 48 KB/track, compatible disk layout
[ 7.127590] dasdb:VOL1/ 0X3319: dasdb1
[ 7.128367] dasd-eckd 0.0.3318: New DASD 3390/0E (CU 3990/01) with 262668 cylinders, 15 heads, 224 sectors
[ 7.130987] dasd-eckd 0.0.3318: DASD with 4 KB/block, 189120960 KB total size, 48 KB/track, compatible disk layout
[ 7.132054] dasda:VOL1/ 0X3318: dasda1
[ 7.133315] dasd-eckd 0.0.331a: New DASD 3390/0C (CU 3990/01) with 30051 cylinders, 15 heads, 224 sectors
[ 7.136326] dasd-eckd 0.0.331a: DASD with 4 KB/block, 21636720 KB total size, 48 KB/track, compatible disk layout
[ 7.137145] dasdc:VOL1/ 0X331A:
[ 7.138060] dasd-eckd 0.0.331b: New DASD 3390/0C (CU 3990/01) with 30051 cylinders, 15 heads, 224 sectors
[ 7.140842] dasd-eckd 0.0.331b: DASD with 4 KB/block, 21636720 KB total size, 48 KB/track, compatible disk layout
[ 7.141538] dasdd:VOL1/ 0X331B:
[ 7.147527] audit: type=1130 audit(1583350726.255: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.149679] qeth 0.0.bd00: QDIO data connection isolation is deactivated
[ 7.150155] qeth 0.0.bd00: The device represents a Bridge Capable Port
[ 7.153543] qeth 0.0.bd00: MAC address 8e:dc:f9:1b:1d:48 successfully registered
[ 7.154070] qeth 0.0.bd00: Device is a OSD Express card (level: 0199)
with link type OSD_10GIG.
[ 7.163550] audit: type=1130 audit(1583350726.265: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.189372] qeth 0.0.bd00: MAC address de:45:d7:61:c4:13 successfully registered
[ 7.191686] qeth 0.0.bd00 encbd00: renamed from eth0
[ 7.380543] mlx5_core 0001:00:00.0: enabling device (0000 -> 0002)
[ 7.380634] mlx5_core 0001:00:00.0: firmware version: 14.23.1020
[ 7.464556] dasdconf.sh Warning: 0.0.3318 is already online, not configuring
[ 7.513188] dasdconf.sh Warning: 0.0.331b is already online, not configuring
[ 7.513319] dasdconf.sh Warning: 0.0.331a is already online, not configuring
[ 7.524280] dasdconf.sh Warning: 0.0.3319 is already online, not configuring
[ 7.822902] mlx5_core 0002:00:00.0: enabling device (0000 -> 0002)
[ 7.822988] mlx5_core 0002:00:00.0: firmware version: 14.23.1020
[ 8.272590] mlx5_core 0001:00:00.0: MLX5E: StrdRq(0) RqSz(1024) StrdSz(256) RxCqeCmprss(0)
[ 8.411681] mlx5_core 0002:00:00.0: MLX5E: StrdRq(0) RqSz(1024) StrdSz(256) RxCqeCmprss(0)
[ 8.573287] mlx5_core 0001:00:00.0 enP1s519: renamed from eth0
[ 8.827283] mlx5_core 0002:00:00.0 enP2s564: renamed from eth1
[ 9.027834] audit: type=1130 audit(1583350728.135: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'
[ 9.045379] audit: type=1130 audit(1583350728.145: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'
[ 9.054299] EXT4-fs (dasda1): mounted filesystem with ordered data mode. Opts: (null)
[ 9.063290] audit: type=1334 audit(1583350728.165:13): prog-id=7 op=UNLOAD
[ 9.380815] systemd-journald[543]: Received SIGTERM from PID 1 (systemd).
[ 9.395001] printk: systemd: 19 output lines suppressed due to ratelimiting
[ 9.661651] SELinux: Permission watch in class filesystem not defined in policy.
[ 9.661656] SELinux: Permission watch in class file not defined in policy.
[ 9.661657] SELinux: Permission watch_mount in class file not defined in policy.
[ 9.661658] SELinux: Permission watch_sb in class file not defined in policy.
[ 9.661659] SELinux: Permission watch_with_perm in class file not defined in policy.
[ 9.661660] SELinux: Permission watch_reads in class file not defined in policy.
[ 9.661662] SELinux: Permission watch in class dir not defined in policy.
[ 9.661663] SELinux: Permission watch_mount in class dir not defined in policy.
[ 9.661664] SELinux: Permission watch_sb in class dir not defined in policy.
[ 9.661665] SELinux: Permission watch_with_perm in class dir not defined in policy.
[ 9.661666] SELinux: Permission watch_reads in class dir not defined in policy.
[ 9.661670] SELinux: Permission watch in class lnk_file not defined in policy.
[ 9.661670] SELinux: Permission watch_mount in class lnk_file not defined in policy.
[ 9.661672] SELinux: Permission watch_sb in class lnk_file not defined in policy.
[ 9.661673] SELinux: Permission watch_with_perm in class lnk_file not defined in policy.
[ 9.661674] SELinux: Permission watch_reads in class lnk_file not defined in policy.
[ 9.661676] SELinux: Permission watch in class chr_file not defined in policy.
[ 9.661690] SELinux: Permission watch_mount in class chr_file not defined in policy.
[ 9.661691] SELinux: Permission watch_sb in class chr_file not defined in policy.
[ 9.661692] SELinux: Permission watch_with_perm in class chr_file not defined in policy.
[ 9.661693] SELinux: Permission watch_reads in class chr_file not defined in policy.
[ 9.661695] SELinux: Permission watch in class blk_file not defined in policy.
[ 9.661696] SELinux: Permission watch_mount in class blk_file not defined in policy.
[ 9.661697] SELinux: Permission watch_sb in class blk_file not defined in policy.
[ 9.661698] SELinux: Permission watch_with_perm in class blk_file not defined in policy.
[ 9.661699] SELinux: Permission watch_reads in class blk_file not defined in policy.
[ 9.661702] SELinux: Permission watch in class sock_file not defined in policy.
[ 9.661702] SELinux: Permission watch_mount in class sock_file not defined in policy.
[ 9.661704] SELinux: Permission watch_sb in class sock_file not defined in policy.
[ 9.661705] SELinux: Permission watch_with_perm in class sock_file not defined in policy.
[ 9.661706] SELinux: Permission watch_reads in class sock_file not defined in policy.
[ 9.661708] SELinux: Permission watch in class fifo_file not defined in policy.
[ 9.661710] SELinux: Permission watch_mount in class fifo_file not defined in policy.
[ 9.661710] SELinux: Permission watch_sb in class fifo_file not defined in policy.
[ 9.661711] SELinux: Permission watch_with_perm in class fifo_file not defined in policy.
[ 9.661712] SELinux: Permission watch_reads in class fifo_file not defined in policy.
[ 9.661793] SELinux: Class perf_event not defined in policy.
[ 9.661794] SELinux: Class lockdown not defined in policy.
[ 9.661795] SELinux: the above unknown classes and permissions will be allowed
[ 9.661808] SELinux: policy capability network_peer_controls=1
[ 9.661809] SELinux: policy capability open_perms=1
[ 9.661810] SELinux: policy capability extended_socket_class=1
[ 9.661811] SELinux: policy capability always_check_network=0
[ 9.661811] SELinux: policy capability cgroup_seclabel=1
[ 9.661812] SELinux: policy capability nnp_nosuid_transition=1
[ 9.741220] systemd[1]: Successfully loaded SELinux policy in 291.310ms.
[ 9.789736] systemd[1]: Relabelled /dev, /dev/shm, /run, /sys/fs/cgroup in 12.825ms.
[ 9.791767] 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.792457] systemd[1]: Detected architecture s390x.
[ 9.793656] systemd[1]: Set hostname to <m83lp52.lnxne.boe>.
[ 9.902467] 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.906424] 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.906622] 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.934051] 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.
[ 9.961533] systemd[1]: initrd-switch-root.service: Succeeded.
[ 9.961634] systemd[1]: Stopped Switch Root.
[ 9.961890] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.
[ 9.989554] EXT4-fs (dasda1): re-mounted. Opts: (null)
[ 10.299160] systemd-journald[1085]: Received client request to flush runtime journal.
[ 10.499707] VFIO - User Level meta-driver version: 0.3
[ 10.530145] genwqe 0000:00:00.0: enabling device (0000 -> 0002)
[ 10.532037] dasdconf.sh Warning: 0.0.331a is already online, not configuring
[ 10.534362] dasdconf.sh Warning: 0.0.331b is already online, not configuring
[ 10.534490] dasdconf.sh Warning: 0.0.3319 is already online, not configuring
[ 10.534516] dasdconf.sh Warning: 0.0.3318 is already online, not configuring
[ 10.768265] mlx5_ib: Mellanox Connect-IB Infiniband driver v5.0-0
[ 10.954777] XFS (dasdb1): Mounting V5 Filesystem
[ 10.967218] RPC: Registered named UNIX socket transport module.
[ 10.967221] RPC: Registered udp transport module.
[ 10.967223] RPC: Registered tcp transport module.
[ 10.967224] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 10.985393] XFS (dasdb1): Ending clean mount
[ 10.987810] xfs filesystem being mounted at /home supports timestamps until 2038 (0x7fffffff)
[ 11.002317] RPC: Registered rdma transport module.
[ 11.002319] RPC: Registered rdma backchannel transport module.
[ 11.943320] mlx5_core 0001:00:00.0 enP1s519: Link up
[ 11.945973] IPv6: ADDRCONF(NETDEV_CHANGE): enP1s519: link becomes ready
[ 12.063453] mlx5_core 0002:00:00.0 enP2s564: Link up
[ 12.136089] tun: Universal TUN/TAP device driver, 1.6
[ 12.137058] virbr0: port 1(virbr0-nic) entered blocking state
[ 12.137060] virbr0: port 1(virbr0-nic) entered disabled state
[ 12.137150] device virbr0-nic entered promiscuous mode
[ 12.536173] virbr0: port 1(virbr0-nic) entered blocking state
[ 12.536176] virbr0: port 1(virbr0-nic) entered listening state
[ 12.560143] virbr0: port 1(virbr0-nic) entered disabled state
[ 12.976588] IPv6: ADDRCONF(NETDEV_CHANGE): enP2s564: link becomes ready
[ 25.680326] CPU62 path=/machine.slice/machine-test.slice/machine-qemu\x2d16\x2dtest14. on_list=1 nr_running=1 p=[CPU 1/KVM 2543]
[ 25.680334] ------------[ cut here ]------------
[ 25.680335] rq->tmp_alone_branch != &rq->leaf_cfs_rq_list
[ 25.680351] WARNING: CPU: 61 PID: 2535 at kernel/sched/fair.c:380 enqueue_task_fair+0x3f6/0x4a8
[ 25.680353] 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 s390_trng ghash_s390 prng aes_s390 ib_uverbs des_s390 libdes sha3_512_s390 ib_core sha3_256_s390 sha512_s390 sha1_s390 genwqe_card vfio_ccw crc_itu_t vfio_mdev mdev vfio_iommu_type1 vfio eadm_sch zcrypt_cex4 sch_fq_codel ip_tables x_tables mlx5_core sha256_s390 sha_common pkey zcrypt rng_core autofs4
[ 25.680397] CPU: 61 PID: 2535 Comm: CPU 0/KVM Not tainted 5.6.0-rc3+ #159
[ 25.680398] Hardware name: IBM 3906 M04 704 (LPAR)
[ 25.680399] Krnl PSW : 0404c00180000000 0000001b0ed9ef0a (enqueue_task_fair+0x3fa/0x4a8)
[ 25.680402] 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
[ 25.680404] Krnl GPRS: 00000000000003e0 0000001e40060400 000000000000002d 0000001b100507c2
[ 25.680405] 000000000000002c 0000001b0f4089d0 0000000000000001 0400001b00000000
[ 25.680407] 0000001eb757e000 000003e00167bb58 0000001e40060400 0000001fbd840928
[ 25.680454] 0000001ebfc0a000 0000001fbd83fd00 0000001b0ed9ef06 000003e00167baa0
[ 25.680461] Krnl Code: 0000001b0ed9eefa: c020005d398a larl %r2,0000001b0f94620e
0000001b0ed9ef00: c0e5fffdcbd8 brasl %r14,0000001b0ed586b0
#0000001b0ed9ef06: af000000 mc 0,0
>0000001b0ed9ef0a: a7f4febe brc 15,0000001b0ed9ec86
0000001b0ed9ef0e: ec2cfe68017f clij %r2,1,12,0000001b0ed9ebde
0000001b0ed9ef14: e310dd200004 lg %r1,3360(%r13)
0000001b0ed9ef1a: 58201098 l %r2,152(%r1)
0000001b0ed9ef1e: ec26fe63007e cij %r2,0,6,0000001b0ed9ebe4
[ 25.680475] Call Trace:
[ 25.680477] [<0000001b0ed9ef0a>] enqueue_task_fair+0x3fa/0x4a8
[ 25.680479] ([<0000001b0ed9ef06>] enqueue_task_fair+0x3f6/0x4a8)
[ 25.680482] [<0000001b0ed8ed78>] activate_task+0x88/0xf0
[ 25.680483] [<0000001b0ed8f2e8>] ttwu_do_activate+0x58/0x78
[ 25.680485] [<0000001b0ed902ce>] try_to_wake_up+0x256/0x650
[ 25.680489] [<0000001b0edae50e>] swake_up_locked.part.0+0x2e/0x70
[ 25.680490] [<0000001b0edae82c>] swake_up_one+0x54/0x88
[ 25.680536] [<000003ff8042315a>] kvm_vcpu_wake_up+0x52/0x78 [kvm]
[ 25.680545] [<000003ff80441f0a>] kvm_s390_vcpu_wakeup+0x2a/0x40 [kvm]
[ 25.680554] [<000003ff80442696>] kvm_s390_idle_wakeup+0x6e/0xa0 [kvm]
[ 25.680559] [<0000001b0edf90dc>] __hrtimer_run_queues+0x114/0x2f0
[ 25.680562] [<0000001b0edf9e34>] hrtimer_interrupt+0x12c/0x2a8
[ 25.680564] [<0000001b0ed1cd3c>] do_IRQ+0xac/0xb0
[ 25.680570] [<0000001b0f741704>] ext_int_handler+0x130/0x134
[ 25.680572] [<0000001b0f740dc6>] sie_exit+0x0/0x46
[ 25.680580] ([<000003ff8043a452>] __vcpu_run+0x3a2/0xcb0 [kvm])
[ 25.680589] [<000003ff8043b7c0>] kvm_arch_vcpu_ioctl_run+0x248/0x880 [kvm]
[ 25.680597] [<000003ff804261d4>] kvm_vcpu_ioctl+0x284/0x7b0 [kvm]
[ 25.680602] [<0000001b0efdac0e>] ksys_ioctl+0xae/0xe8
[ 25.680604] [<0000001b0efdacb2>] __s390x_sys_ioctl+0x2a/0x38
[ 25.680605] [<0000001b0f7410b2>] system_call+0x2a6/0x2c8
[ 25.680606] Last Breaking-Event-Address:
[ 25.680609] [<0000001b0ed58710>] __warn_printk+0x60/0x68
[ 25.680610] ---[ end trace 1298e6d8f1f0ce77 ]---
Attachment:
sysfs.tar.lz4
Description: application/lz4