From: Guenter Roeck <linux@roeck-us.net>
To: Christoph Hellwig <hch@lst.de>
Cc: Jens Axboe <axboe@kernel.dk>, Mike Snitzer <snitzer@redhat.com>,
linux-block@vger.kernel.org, dm-devel@redhat.com
Subject: Re: [dm-devel] [PATCH 4/8] block: support delayed holder registration
Date: Tue, 17 Aug 2021 19:51:53 -0700 [thread overview]
Message-ID: <20210818025153.GA1053733@roeck-us.net> (raw)
In-Reply-To: <20210816072158.GA27147@lst.de>
On Mon, Aug 16, 2021 at 09:21:58AM +0200, Christoph Hellwig wrote:
> On Sun, Aug 15, 2021 at 07:27:37AM -0700, Guenter Roeck wrote:
> > [ 14.467748][ T1] Possible unsafe locking scenario:
> > [ 14.467748][ T1]
> > [ 14.467928][ T1] CPU0 CPU1
> > [ 14.468058][ T1] ---- ----
> > [ 14.468187][ T1] lock(&disk->open_mutex);
> > [ 14.468317][ T1] lock(mtd_table_mutex);
> > [ 14.468493][ T1] lock(&disk->open_mutex);
> > [ 14.468671][ T1] lock(mtd_table_mutex);
>
> Oh, that ooks like a really old one, fixed by
> b7abb0516822 ("mtd: fix lock hierarchy in deregister_mtd_blktrans")
> in linux-next.
I tested again with next-20210817. The problem is still there, and
reverting commit d62633873590 ("block: support delayed holder
registration") still fixes it. A complete boot log is attached
for reference.
Guenter
---
Build reference: next-20210817
qemu log:
[ 0.010915815,5] OPAL v6.4 starting...
[ 0.011392739,7] initial console log level: memory 7, driver 5
[ 0.011422553,6] CPU: P9 generation processor (max 4 threads/core)
[ 0.011437437,7] CPU: Boot CPU PIR is 0x0000 PVR is 0x004e1200
[ 0.011524734,7] OPAL table: 0x30101830 .. 0x30101da0, branch table: 0x30002000
[ 0.011667083,7] Assigning physical memory map table for nimbus
[ 0.011914730,7] FDT: Parsing fdt @0x1000000
[ 0.013589817,5] CHIP: Detected Qemu simulator
[ 0.013713155,6] CHIP: Initialised chip 0 from xscom@603fc00000000
[ 0.013992710,6] P9 DD2.00 detected
[ 0.014006187,5] CHIP: Chip ID 0000 type: P9N DD2.00
[ 0.014012448,7] XSCOM: Base address: 0x603fc00000000
[ 0.014031889,7] XSTOP: ibm,sw-checkstop-fir prop not found
[ 0.014094328,6] MFSI 0:0: Initialized
[ 0.014102372,6] MFSI 0:2: Initialized
[ 0.014109468,6] MFSI 0:1: Initialized
[ 0.014477509,6] LPC: LPC[000]: Initialized
[ 0.014483986,7] LPC: access via MMIO @0x6030000000000
[ 0.014513616,7] LPC: Default bus on chip 0x0
[ 0.014579301,7] CPU: New max PIR set to 0x3
[ 0.014944450,7] MEM: parsing reserved memory from reserved-names/-ranges properties
[ 0.015013478,7] CPU: decrementer bits 56
[ 0.015059057,6] CPU: CPU from DT PIR=0x0000 Server#=0x0 State=3
[ 0.015116735,6] CPU: 1 secondary threads
[ 0.016079682,5] PLAT: Using SuperIO UART
[ 0.016285800,7] UART: Using LPC IRQ 4
[ 0.017744314,5] PLAT: Detected QEMU POWER9 platform
[ 0.017803645,5] PLAT: Detected BMC platform ast2500:openbmc
[ 0.033090750,5] CPU: All 1 processors called in...
[ 0.033389379,3] SBE: Master chip ID not found.
[ 0.033807105,7] LPC: Routing irq 10, policy: 0 (r=1)
[ 0.033866006,7] LPC: SerIRQ 10 using route 0 targetted at OPAL
[ 0.055456502,5] HIOMAP: Negotiated hiomap protocol v2
[ 0.055559088,5] HIOMAP: Block size is 4KiB
[ 0.055635761,5] HIOMAP: BMC suggested flash timeout of 0s
[ 0.055732832,5] HIOMAP: Flash size is 32MiB
[ 0.055809489,5] HIOMAP: Erase granule size is 4KiB
[ 0.072601777,4] FLASH: No ffs info; using raw device only
[ 0.078031760,3] FLASH: Can't open ffs handle
[ 0.083329630,3] FLASH: Can't open ffs handle
[ 0.088614080,3] FLASH: Can't open ffs handle
[ 0.093896205,3] FLASH: Can't open ffs handle
[ 0.099174034,3] FLASH: Can't open ffs handle
[ 0.104454746,3] FLASH: Can't open ffs handle
[ 0.115977110,2] NVRAM: Failed to load
[ 0.116068253,2] NVRAM: Failed to load
[ 0.116173219,5] STB: secure boot not supported
[ 0.116283085,5] STB: trusted boot not supported
[ 0.116683004,4] FLASH: Can't load resource id:4. No system flash found
[ 0.117069713,4] FLASH: Can't load resource id:3. No system flash found
[ 0.117269585,2] NVRAM: Failed to load
[ 0.117490209,7] LPC: Routing irq 4, policy: 0 (r=1)
[ 0.117514888,7] LPC: SerIRQ 4 using route 1 targetted at OPAL
[ 0.117933346,3] SLW: HOMER base not set 0
[ 0.118081064,5] Unable to log error
[ 0.118227237,2] NVRAM: Failed to load
[ 0.118442741,3] OCC: No HOMER detected, assuming no pstates
[ 0.118501222,5] Unable to log error
[ 0.118555649,2] NVRAM: Failed to load
[ 0.118604663,2] NVRAM: Failed to load
[ 0.118720628,4] FLASH: Can't load resource id:2. No system flash found
[ 0.118912385,4] FLASH: Can't load resource id:0. No system flash found
[ 0.118983574,4] FLASH: Can't load resource id:1. No system flash found
[ 0.119116640,3] IMC: IMC Catalog load failed
[ 0.119364768,2] NVRAM: Failed to load
[ 0.119406236,2] NVRAM: Failed to load
[ 0.119444636,2] NVRAM: Failed to load
[ 0.119482315,2] NVRAM: Failed to load
[ 0.131102078,3] CAPP: Error loading ucode lid. index=200d1
[ 0.150206406,2] NVRAM: Failed to load
[ 0.160574726,5] PCI: Resetting PHBs and training links...
[ 6.170966934,5] PCI: Probing slots...
[ 6.175681253,5] PCI Summary:
[ 6.176039126,5] PHB#0000:00:00.0 [ROOT] 1014 04c1 R:00 C:060400 B:01..01
[ 6.176342301,5] PHB#0000:01:00.0 [PCID] 10ec 8139 R:20 C:020000 ( ethernet)
[ 6.176532516,5] PHB#0001:00:00.0 [ROOT] 1014 04c1 R:00 C:060400 B:00..00
[ 6.176658081,5] PHB#0002:00:00.0 [ROOT] 1014 04c1 R:00 C:060400 B:00..00
[ 6.176779913,5] PHB#0003:00:00.0 [ROOT] 1014 04c1 R:00 C:060400 B:00..00
[ 6.176904577,5] PHB#0004:00:00.0 [ROOT] 1014 04c1 R:00 C:060400 B:00..00
[ 6.177035788,5] PHB#0005:00:00.0 [ROOT] 1014 04c1 R:00 C:060400 B:00..00
[ 6.177260815,4] FLASH: Failed to load VERSION data
[ 6.312317126,5] INIT: Waiting for kernel...
[ 6.312368972,5] INIT: platform wait for kernel load failed
[ 6.312433234,5] INIT: Assuming kernel at 0x20000000
[ 6.312515708,5] INIT: 64-bit LE kernel discovered
[ 6.312673483,3] OCC: Unassigned OCC Common Area. No sensors found
[ 6.312827720,2] NVRAM: Failed to load
[ 6.370807692,5] INIT: Starting kernel at 0x20010000, fdt at 0x306c9818 24120 bytes
zImage starting: loaded at 0x0000000020010000 (sp: 0x00000000209e7ed8)
Allocating 0x2647d20 bytes for kernel...
Decompressing (0x0000000000000000 <- 0x0000000020021000:0x00000000209e6ea9)...
Done! Decompressed 0x1a7ebf4 bytes
Linux/PowerPC load: panic=-1 slub_debug=FZPUA root=/dev/mtdblock0 console=tty console=hvc0
Finalizing device tree... flat tree at 0x209e8ca0
[ 0.000000][ T0] dt-cpu-ftrs: setup for ISA 3000
[ 0.000000][ T0] dt-cpu-ftrs: final cpu/mmu features = 0x0003c06b8f5fb187 0x3c007041
[ 0.000000][ T0] Activating Kernel Userspace Execution Prevention
[ 0.000000][ T0] Activating Kernel Userspace Access Prevention
[ 0.000000][ T0] radix-mmu: Mapped 0x0000000000000000-0x0000000001740000 with 64.0 KiB pages (exec)
[ 0.000000][ T0] radix-mmu: Mapped 0x0000000001740000-0x0000000080000000 with 64.0 KiB pages
[ 0.000000][ T0] radix-mmu: Initializing Radix MMU
[ 0.000000][ T0] Linux version 5.14.0-rc6-next-20210817 (groeck@server.roeck-us.net) (powerpc64-linux-gcc.br_real (Buildroot 2019.02-git-00353-g4f20f23) 7.4.0, GNU ld (GNU Binutils) 2.31.1) #1 SMP Tue Aug 17 19:13:07 PDT 2021
[ 0.000000][ T0] Using PowerNV machine description
[ 0.000000][ T0] printk: bootconsole [udbg0] enabled
[ 0.000000][ T0] CPU maps initialized for 1 thread per core
[ 0.000000][ T0] -----------------------------------------------------
[ 0.000000][ T0] phys_mem_size = 0x80000000
[ 0.000000][ T0] dcache_bsize = 0x80
[ 0.000000][ T0] icache_bsize = 0x80
[ 0.000000][ T0] cpu_features = 0x0003c06b8f4fb187
[ 0.000000][ T0] possible = 0x000ffbfbcf5fb187
[ 0.000000][ T0] always = 0x0000000380008181
[ 0.000000][ T0] cpu_user_features = 0xdc0065c2 0xaef00000
[ 0.000000][ T0] mmu_features = 0x3c007641
[ 0.000000][ T0] firmware_features = 0x0000000010000000
[ 0.000000][ T0] vmalloc start = 0xc008000000000000
[ 0.000000][ T0] IO start = 0xc00a000000000000
[ 0.000000][ T0] vmemmap start = 0xc00c000000000000
[ 0.000000][ T0] -----------------------------------------------------
[ 0.000000][ T0] kvm_cma_reserve: reserving 102 MiB for global area
[ 0.000000][ T0] cma: Reserved 112 MiB at 0x0000000073000000
[ 0.000000][ T0] numa: NODE_DATA [mem 0x7bf7ae00-0x7bf7ffff]
[ 0.000000][ T0] rfi-flush: fallback displacement flush available
[ 0.000000][ T0] count-cache-flush: flush disabled.
[ 0.000000][ T0] link-stack-flush: flush disabled.
[ 0.000000][ T0] stf-barrier: eieio barrier available
[ 0.000000][ T0] barrier-nospec: using ORI speculation barrier
[ 0.000000][ T0] Zone ranges:
[ 0.000000][ T0] Normal [mem 0x0000000000000000-0x000000007fffffff]
[ 0.000000][ T0] Movable zone start for each node
[ 0.000000][ T0] Early memory node ranges
[ 0.000000][ T0] node 0: [mem 0x0000000000000000-0x000000007fffffff]
[ 0.000000][ T0] Initmem setup node 0 [mem 0x0000000000000000-0x000000007fffffff]
[ 0.000000][ T0] percpu: Embedded 11 pages/cpu s645968 r0 d74928 u720896
[ 0.000000][ T0] Built 1 zonelists, mobility grouping on. Total pages: 32736
[ 0.000000][ T0] Policy zone: Normal
[ 0.000000][ T0] Kernel command line: panic=-1 slub_debug=FZPUA root=/dev/mtdblock0 console=tty console=hvc0
[ 0.000000][ T0] Dentry cache hash table entries: 262144 (order: 5, 2097152 bytes, linear)
[ 0.000000][ T0] Inode-cache hash table entries: 131072 (order: 4, 1048576 bytes, linear)
[ 0.000000][ T0] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000][ T0] Memory: 0K/2097152K available (17152K kernel code, 3328K rwdata, 4608K rodata, 1984K init, 12063K bss, 173440K reserved, 114688K cma-reserved)
[ 0.000000][ T0] **********************************************************
[ 0.000000][ T0] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE **
[ 0.000000][ T0] ** **
[ 0.000000][ T0] ** This system shows unhashed kernel memory addresses **
[ 0.000000][ T0] ** via the console, logs, and other interfaces. This **
[ 0.000000][ T0] ** might reduce the security of your system. **
[ 0.000000][ T0] ** **
[ 0.000000][ T0] ** If you see this message and you are not debugging **
[ 0.000000][ T0] ** the kernel, report this immediately to your system **
[ 0.000000][ T0] ** administrator! **
[ 0.000000][ T0] ** **
[ 0.000000][ T0] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE **
[ 0.000000][ T0] **********************************************************
[ 0.000000][ T0] SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000][ T0] ftrace: allocating 36425 entries in 14 pages
[ 0.000000][ T0] ftrace: allocated 14 pages with 3 groups
[ 0.000000][ T0] trace event string verifier disabled
[ 0.000000][ T0] Running RCU self tests
[ 0.000000][ T0] rcu: Hierarchical RCU implementation.
[ 0.000000][ T0] rcu: RCU event tracing is enabled.
[ 0.000000][ T0] rcu: RCU lockdep checking is enabled.
[ 0.000000][ T0] rcu: RCU restricting CPUs from NR_CPUS=2048 to nr_cpu_ids=1.
[ 0.000000][ T0] rcu: RCU debug extended QS entry/exit.
[ 0.000000][ T0] Rude variant of Tasks RCU enabled.
[ 0.000000][ T0] Tracing variant of Tasks RCU enabled.
[ 0.000000][ T0] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[ 0.000000][ T0] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
[ 0.000000][ T0] NR_IRQS: 512, nr_irqs: 512, preallocated irqs: 16
[ 0.000000][ T0] xive: Interrupt handling initialized with native backend
[ 0.000000][ T0] xive: Using priority 7 for all interrupts
[ 0.000000][ T0] xive: Using 64kB queues
[ 0.000000][ T0] random: get_random_u64 called from start_kernel+0x680/0x8e8 with crng_init=0
[ 0.000090][ T0] time_init: 56 bit decrementer (max: 7fffffffffffff)
[ 0.001865][ T0] clocksource: timebase: mask: 0xffffffffffffffff max_cycles: 0x761537d007, max_idle_ns: 440795202126 ns
[ 0.004659][ T0] clocksource: timebase mult[1f40000] shift[24] registered
[ 0.012714][ T0] Console: colour dummy device 80x25
[ 0.026090][ T0] printk: console [tty0] enabled
[ 0.026571][ T0] printk: console [hvc0] enabled
[ 0.026571][ T0] printk: console [hvc0] enabled
[ 0.027221][ T0] printk: bootconsole [udbg0] disabled
[ 0.027221][ T0] printk: bootconsole [udbg0] disabled
[ 0.028092][ T0] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[ 0.028424][ T0] ... MAX_LOCKDEP_SUBCLASSES: 8
[ 0.028613][ T0] ... MAX_LOCK_DEPTH: 48
[ 0.028800][ T0] ... MAX_LOCKDEP_KEYS: 8192
[ 0.028989][ T0] ... CLASSHASH_SIZE: 4096
[ 0.029185][ T0] ... MAX_LOCKDEP_ENTRIES: 32768
[ 0.029381][ T0] ... MAX_LOCKDEP_CHAINS: 65536
[ 0.029574][ T0] ... CHAINHASH_SIZE: 32768
[ 0.029768][ T0] memory used by lock dependency info: 6365 kB
[ 0.029997][ T0] memory used for stack traces: 4224 kB
[ 0.030204][ T0] per task-struct memory footprint: 1920 bytes
[ 0.030467][ T0] ------------------------
[ 0.030645][ T0] | Locking API testsuite:
[ 0.030819][ T0] ----------------------------------------------------------------------------
[ 0.035275][ T0] | spin |wlock |rlock |mutex | wsem | rsem |
[ 0.035616][ T0] --------------------------------------------------------------------------
[ 0.036183][ T0] A-A deadlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.049825][ T0] A-B-B-A deadlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.064240][ T0] A-B-B-C-C-A deadlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.086497][ T0] A-B-C-A-B-C deadlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.103109][ T0] A-B-B-C-C-D-D-A deadlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.122436][ T0] A-B-C-D-B-D-D-A deadlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.141864][ T0] A-B-C-D-B-C-D-A deadlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.161418][ T0] double unlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.173155][ T0] initialize held: ok | ok | ok | ok | ok | ok | ok |
[ 0.183712][ T0] --------------------------------------------------------------------------
[ 0.184041][ T0] recursive read-lock: | ok | | ok |
[ 0.187988][ T0] recursive read-lock #2: | ok | | ok |
[ 0.191588][ T0] mixed read-write-lock: | ok | | ok |
[ 0.195301][ T0] mixed write-read-lock: | ok | | ok |
[ 0.198850][ T0] mixed read-lock/lock-write ABBA: | ok | | ok |
[ 0.202797][ T0] mixed read-lock/lock-read ABBA: | ok | | ok |
[ 0.207250][ T0] mixed write-lock/lock-write ABBA: | ok | | ok |
[ 0.211513][ T0] chain cached mixed R-L/L-W ABBA: | ok |
[ 0.213847][ T0] rlock W1R2/W2R3/W3R1/123: | ok |
[ 0.216917][ T0] rlock W1R2/W2R3/W3R1/132: | ok |
[ 0.219589][ T0] rlock W1R2/W2R3/W3R1/213: | ok |
[ 0.222209][ T0] rlock W1R2/W2R3/W3R1/231: | ok |
[ 0.224828][ T0] rlock W1R2/W2R3/W3R1/312: | ok |
[ 0.227578][ T0] rlock W1R2/W2R3/W3R1/321: | ok |
[ 0.230260][ T0] rlock W1W2/R2R3/W3R1/123: | ok |
[ 0.232933][ T0] rlock W1W2/R2R3/W3R1/132: | ok |
[ 0.235588][ T0] rlock W1W2/R2R3/W3R1/213: | ok |
[ 0.238346][ T0] rlock W1W2/R2R3/W3R1/231: | ok |
[ 0.241010][ T0] rlock W1W2/R2R3/W3R1/312: | ok |
[ 0.243660][ T0] rlock W1W2/R2R3/W3R1/321: | ok |
[ 0.246311][ T0] rlock W1W2/R2R3/R3W1/123: | ok |
[ 0.249064][ T0] rlock W1W2/R2R3/R3W1/132: | ok |
[ 0.251699][ T0] rlock W1W2/R2R3/R3W1/213: | ok |
[ 0.254318][ T0] rlock W1W2/R2R3/R3W1/231: | ok |
[ 0.256931][ T0] rlock W1W2/R2R3/R3W1/312: | ok |
[ 0.259677][ T0] rlock W1W2/R2R3/R3W1/321: | ok |
[ 0.262346][ T0] rlock W1R2/R2R3/W3W1/123: | ok |
[ 0.264978][ T0] rlock W1R2/R2R3/W3W1/132: | ok |
[ 0.267613][ T0] rlock W1R2/R2R3/W3W1/213: | ok |
[ 0.270324][ T0] rlock W1R2/R2R3/W3W1/231: | ok |
[ 0.272953][ T0] rlock W1R2/R2R3/W3W1/312: | ok |
[ 0.275577][ T0] rlock W1R2/R2R3/W3W1/321: | ok |
[ 0.278228][ T0] --------------------------------------------------------------------------
[ 0.278553][ T0] hard-irqs-on + irq-safe-A/12: ok | ok | ok |
[ 0.283971][ T0] soft-irqs-on + irq-safe-A/12: ok | ok | ok |
[ 0.289507][ T0] hard-irqs-on + irq-safe-A/21: ok | ok | ok |
[ 0.294903][ T0] soft-irqs-on + irq-safe-A/21: ok | ok | ok |
[ 0.300069][ T0] sirq-safe-A => hirqs-on/12: ok | ok | ok |
[ 0.305415][ T0] sirq-safe-A => hirqs-on/21: ok | ok | ok |
[ 0.310652][ T0] hard-safe-A + irqs-on/12: ok | ok | ok |
[ 0.316082][ T0] soft-safe-A + irqs-on/12: ok | ok | ok |
[ 0.321303][ T0] hard-safe-A + irqs-on/21: ok | ok | ok |
[ 0.326734][ T0] soft-safe-A + irqs-on/21: ok | ok | ok |
[ 0.331984][ T0] hard-safe-A + unsafe-B #1/123: ok | ok | ok |
[ 0.338422][ T0] soft-safe-A + unsafe-B #1/123: ok | ok | ok |
[ 0.345541][ T0] hard-safe-A + unsafe-B #1/132: ok | ok | ok |
[ 0.356619][ T0] soft-safe-A + unsafe-B #1/132: ok | ok | ok |
[ 0.362796][ T0] hard-safe-A + unsafe-B #1/213: ok | ok | ok |
[ 0.369123][ T0] soft-safe-A + unsafe-B #1/213: ok | ok | ok |
[ 0.375299][ T0] hard-safe-A + unsafe-B #1/231: ok | ok | ok |
[ 0.381629][ T0] soft-safe-A + unsafe-B #1/231: ok | ok | ok |
[ 0.387777][ T0] hard-safe-A + unsafe-B #1/312: ok | ok | ok |
[ 0.393484][ T0] soft-safe-A + unsafe-B #1/312: ok | ok | ok |
[ 0.399117][ T0] hard-safe-A + unsafe-B #1/321: ok | ok | ok |
[ 0.405361][ T0] soft-safe-A + unsafe-B #1/321: ok | ok | ok |
[ 0.411995][ T0] hard-safe-A + unsafe-B #2/123: ok | ok | ok |
[ 0.418450][ T0] soft-safe-A + unsafe-B #2/123: ok | ok | ok |
[ 0.424913][ T0] hard-safe-A + unsafe-B #2/132: ok | ok | ok |
[ 0.431446][ T0] soft-safe-A + unsafe-B #2/132: ok | ok | ok |
[ 0.437784][ T0] hard-safe-A + unsafe-B #2/213: ok | ok | ok |
[ 0.447485][ T0] soft-safe-A + unsafe-B #2/213: ok | ok | ok |
[ 0.455678][ T0] hard-safe-A + unsafe-B #2/231: ok | ok | ok |
[ 0.462876][ T0] soft-safe-A + unsafe-B #2/231: ok | ok | ok |
[ 0.469234][ T0] hard-safe-A + unsafe-B #2/312: ok | ok | ok |
[ 0.475729][ T0] soft-safe-A + unsafe-B #2/312: ok | ok | ok |
[ 0.481936][ T0] hard-safe-A + unsafe-B #2/321: ok | ok | ok |
[ 0.488372][ T0] soft-safe-A + unsafe-B #2/321: ok | ok | ok |
[ 0.494631][ T0] hard-irq lock-inversion/123: ok | ok | ok |
[ 0.501236][ T0] soft-irq lock-inversion/123: ok | ok | ok |
[ 0.507923][ T0] hard-irq lock-inversion/132: ok | ok | ok |
[ 0.514774][ T0] soft-irq lock-inversion/132: ok | ok | ok |
[ 0.521709][ T0] hard-irq lock-inversion/213: ok | ok | ok |
[ 0.528010][ T0] soft-irq lock-inversion/213: ok | ok | ok |
[ 0.535301][ T0] hard-irq lock-inversion/231: ok | ok | ok |
[ 0.541693][ T0] soft-irq lock-inversion/231: ok | ok | ok |
[ 0.548029][ T0] hard-irq lock-inversion/312: ok | ok | ok |
[ 0.554493][ T0] soft-irq lock-inversion/312: ok | ok | ok |
[ 0.561569][ T0] hard-irq lock-inversion/321: ok | ok | ok |
[ 0.568094][ T0] soft-irq lock-inversion/321: ok | ok | ok |
[ 0.574559][ T0] hard-irq read-recursion/123: | ok | ok |
[ 0.578977][ T0] soft-irq read-recursion/123: | ok | ok |
[ 0.583251][ T0] hard-irq read-recursion/132: | ok | ok |
[ 0.587936][ T0] soft-irq read-recursion/132: | ok | ok |
[ 0.592573][ T0] hard-irq read-recursion/213: | ok | ok |
[ 0.596938][ T0] soft-irq read-recursion/213: | ok | ok |
[ 0.600913][ T0] hard-irq read-recursion/231: | ok | ok |
[ 0.604965][ T0] soft-irq read-recursion/231: | ok | ok |
[ 0.609102][ T0] hard-irq read-recursion/312: | ok | ok |
[ 0.613560][ T0] soft-irq read-recursion/312: | ok | ok |
[ 0.618017][ T0] hard-irq read-recursion/321: | ok | ok |
[ 0.622508][ T0] soft-irq read-recursion/321: | ok | ok |
[ 0.626868][ T0] hard-irq read-recursion #2/123: | ok | ok |
[ 0.631391][ T0] soft-irq read-recursion #2/123: | ok | ok |
[ 0.635753][ T0] hard-irq read-recursion #2/132: | ok | ok |
[ 0.640608][ T0] soft-irq read-recursion #2/132: | ok | ok |
[ 0.644958][ T0] hard-irq read-recursion #2/213: | ok | ok |
[ 0.649470][ T0] soft-irq read-recursion #2/213: | ok | ok |
[ 0.653954][ T0] hard-irq read-recursion #2/231: | ok | ok |
[ 0.658352][ T0] soft-irq read-recursion #2/231: | ok | ok |
[ 0.663008][ T0] hard-irq read-recursion #2/312: | ok | ok |
[ 0.667407][ T0] soft-irq read-recursion #2/312: | ok | ok |
[ 0.671847][ T0] hard-irq read-recursion #2/321: | ok | ok |
[ 0.676744][ T0] soft-irq read-recursion #2/321: | ok | ok |
[ 0.681763][ T0] hard-irq read-recursion #3/123: | ok | ok |
[ 0.686669][ T0] soft-irq read-recursion #3/123: | ok | ok |
[ 0.691021][ T0] hard-irq read-recursion #3/132: | ok | ok |
[ 0.695718][ T0] soft-irq read-recursion #3/132: | ok | ok |
[ 0.700074][ T0] hard-irq read-recursion #3/213: | ok | ok |
[ 0.704752][ T0] soft-irq read-recursion #3/213: | ok | ok |
[ 0.713237][ T0] hard-irq read-recursion #3/231: | ok | ok |
[ 0.718254][ T0] soft-irq read-recursion #3/231: | ok | ok |
[ 0.722683][ T0] hard-irq read-recursion #3/312: | ok | ok |
[ 0.727007][ T0] soft-irq read-recursion #3/312: | ok | ok |
[ 0.731373][ T0] hard-irq read-recursion #3/321: | ok | ok |
[ 0.735706][ T0] soft-irq read-recursion #3/321: | ok | ok |
[ 0.739976][ T0] --------------------------------------------------------------------------
[ 0.740294][ T0] | Wound/wait tests |
[ 0.740456][ T0] ---------------------
[ 0.740616][ T0] ww api failures: ok | ok | ok |
[ 0.747943][ T0] ww contexts mixing: ok | ok |
[ 0.751839][ T0] finishing ww context: ok | ok | ok | ok |
[ 0.759807][ T0] locking mismatches: ok | ok | ok |
[ 0.765794][ T0] EDEADLK handling: ok | ok | ok | ok | ok | ok | ok | ok | ok | ok |
[ 0.786926][ T0] spinlock nest unlocked: ok |
[ 0.788813][ T0] spinlock nest test: ok |
[ 0.791472][ T0] -----------------------------------------------------
[ 0.791735][ T0] |block | try |context|
[ 0.792000][ T0] -----------------------------------------------------
[ 0.792252][ T0] context: ok | ok | ok |
[ 0.798615][ T0] try: ok | ok | ok |
[ 0.804046][ T0] block: ok | ok | ok |
[ 0.810770][ T0] spinlock: ok | ok | ok |
[ 0.821347][ T0] --------------------------------------------------------------------------
[ 0.821673][ T0] | queued read lock tests |
[ 0.821856][ T0] ---------------------------
[ 0.822041][ T0] hardirq read-lock/lock-read: ok |
[ 0.824356][ T0] hardirq lock-read/read-lock: ok |
[ 0.826567][ T0] hardirq inversion: ok |
[ 0.828774][ T0] --------------------
[ 0.828939][ T0] | fs_reclaim tests |
[ 0.829097][ T0] --------------------
[ 0.829252][ T0] correct nesting: ok |
[ 0.830836][ T0] wrong nesting: ok |
[ 0.832385][ T0] protected nesting: ok |
[ 0.833899][ T0] --------------------------------------------------------------------------
[ 0.834216][ T0] | local_lock tests |
[ 0.834373][ T0] ---------------------
[ 0.834531][ T0] local_lock inversion 2: ok |
[ 0.836820][ T0] local_lock inversion 3A: ok |
[ 0.839520][ T0] local_lock inversion 3B: ok |
[ 0.842690][ T0] hardirq_unsafe_softirq_safe: ok |
[ 0.846193][ T0] -------------------------------------------------------
[ 0.846452][ T0] Good, all 358 testcases passed! |
[ 0.846645][ T0] ---------------------------------
[ 0.848247][ T0] pid_max: default: 32768 minimum: 301
[ 0.850462][ T0] Mount-cache hash table entries: 8192 (order: 0, 65536 bytes, linear)
[ 0.850823][ T0] Mountpoint-cache hash table entries: 8192 (order: 0, 65536 bytes, linear)
[ 0.902548][ T1] Running RCU-tasks wait API self tests
[ 0.909691][ T1] POWER9 performance monitor hardware support registered
[ 0.911844][ T1] rcu: Hierarchical SRCU implementation.
[ 0.929941][ T10] Callback from call_rcu_tasks_trace() invoked.
[ 0.932539][ T1] smp: Bringing up secondary CPUs ...
[ 0.932888][ T1] smp: Brought up 1 node, 1 CPU
[ 0.933249][ T1] numa: Node 0 CPUs: 0
[ 0.943941][ T16] node 0 deferred pages initialised in 0ms
[ 0.948649][ T16] pgdatinit0 (16) used greatest stack depth: 12528 bytes left
[ 0.960416][ T1] devtmpfs: initialized
[ 1.045777][ T9] Callback from call_rcu_tasks_rude() invoked.
[ 1.051318][ T1] Initializing IODA2 PHB (/pciex@600c3c0000000)
[ 1.052702][ T1] PCI host bridge /pciex@600c3c0000000 (primary) ranges:
[ 1.053465][ T1] MEM 0x000600c000000000..0x000600c07ffeffff -> 0x0000000080000000
[ 1.054400][ T1] MEM 0x0006000000000000..0x0006003fffffffff -> 0x0006000000000000 (M64 #1..31)
[ 1.054813][ T1] Using M64 #31 as default window
[ 1.056081][ T1] 512 (511) PE's M32: 0x80000000 [segment=0x400000]
[ 1.056408][ T1] M64: 0x4000000000 [segment=0x20000000]
[ 1.056858][ T1] Allocated bitmap for 4088 MSIs (base IRQ 0xfe000)
[ 1.061975][ T1] Initializing IODA2 PHB (/pciex@600c3c0100000)
[ 1.062583][ T1] PCI host bridge /pciex@600c3c0100000 ranges:
[ 1.062929][ T1] MEM 0x000600c080000000..0x000600c0fffeffff -> 0x0000000080000000
[ 1.063511][ T1] MEM 0x0006004000000000..0x0006007fffffffff -> 0x0006004000000000 (M64 #1..15)
[ 1.063907][ T1] Using M64 #15 as default window
[ 1.064324][ T1] 256 (255) PE's M32: 0x80000000 [segment=0x800000]
[ 1.064617][ T1] M64: 0x4000000000 [segment=0x40000000]
[ 1.064944][ T1] Allocated bitmap for 2040 MSIs (base IRQ 0xfd800)
[ 1.066901][ T1] Initializing IODA2 PHB (/pciex@600c3c0200000)
[ 1.067465][ T1] PCI host bridge /pciex@600c3c0200000 ranges:
[ 1.067794][ T1] MEM 0x000600c100000000..0x000600c17ffeffff -> 0x0000000080000000
[ 1.068359][ T1] MEM 0x0006008000000000..0x000600bfffffffff -> 0x0006008000000000 (M64 #1..15)
[ 1.068745][ T1] Using M64 #15 as default window
[ 1.069417][ T1] 256 (255) PE's M32: 0x80000000 [segment=0x800000]
[ 1.069708][ T1] M64: 0x4000000000 [segment=0x40000000]
[ 1.070032][ T1] Allocated bitmap for 2040 MSIs (base IRQ 0xfd000)
[ 1.072066][ T1] Initializing IODA2 PHB (/pciex@600c3c0300000)
[ 1.072637][ T1] PCI host bridge /pciex@600c3c0300000 ranges:
[ 1.072969][ T1] MEM 0x000600c180000000..0x000600c1fffeffff -> 0x0000000080000000
[ 1.073537][ T1] MEM 0x0006020000000000..0x0006023fffffffff -> 0x0006020000000000 (M64 #1..31)
[ 1.073922][ T1] Using M64 #31 as default window
[ 1.074531][ T1] 512 (511) PE's M32: 0x80000000 [segment=0x400000]
[ 1.074818][ T1] M64: 0x4000000000 [segment=0x20000000]
[ 1.075132][ T1] Allocated bitmap for 4088 MSIs (base IRQ 0xfc000)
[ 1.077220][ T1] Initializing IODA2 PHB (/pciex@600c3c0400000)
[ 1.077782][ T1] PCI host bridge /pciex@600c3c0400000 ranges:
[ 1.078120][ T1] MEM 0x000600c200000000..0x000600c27ffeffff -> 0x0000000080000000
[ 1.078682][ T1] MEM 0x0006024000000000..0x0006027fffffffff -> 0x0006024000000000 (M64 #1..15)
[ 1.079077][ T1] Using M64 #15 as default window
[ 1.079742][ T1] 256 (255) PE's M32: 0x80000000 [segment=0x800000]
[ 1.080035][ T1] M64: 0x4000000000 [segment=0x40000000]
[ 1.080352][ T1] Allocated bitmap for 2040 MSIs (base IRQ 0xfb800)
[ 1.082665][ T1] Initializing IODA2 PHB (/pciex@600c3c0500000)
[ 1.083238][ T1] PCI host bridge /pciex@600c3c0500000 ranges:
[ 1.083563][ T1] MEM 0x000600c280000000..0x000600c2fffeffff -> 0x0000000080000000
[ 1.084123][ T1] MEM 0x0006028000000000..0x000602bfffffffff -> 0x0006028000000000 (M64 #1..15)
[ 1.084504][ T1] Using M64 #15 as default window
[ 1.084916][ T1] 256 (255) PE's M32: 0x80000000 [segment=0x800000]
[ 1.085203][ T1] M64: 0x4000000000 [segment=0x40000000]
[ 1.085519][ T1] Allocated bitmap for 2040 MSIs (base IRQ 0xfb000)
[ 1.088892][ T1] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 1.089557][ T1] futex hash table entries: 256 (order: -1, 32768 bytes, linear)
[ 1.101390][ T1] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[ 1.109073][ T1] audit: initializing netlink subsys (disabled)
[ 1.118056][ T1] cpuidle: using governor menu
[ 1.119320][ T1] Failed to initialize. Disabling HugeTLB
[ 1.119642][ T1] nvram: No room to create lnx,oops-log partition, deleting any obsolete OS partitions...
[ 1.120368][ T1] nvram: Failed to find or create lnx,oops-log partition, err -28
[ 1.120723][ T1] nvram: Failed to initialize oops partition!
[ 1.134049][ T20] audit: type=2000 audit(1629254531.000:1): state=initialized audit_enabled=0 res=1
[ 1.137609][ T1] EEH: PowerNV platform initialized
[ 1.145237][ T1] PCI: Probing PCI hardware
[ 1.149106][ T1] PCI host bridge to bus 0000:00
[ 1.149625][ T1] pci_bus 0000:00: root bus resource [mem 0x600c000000000-0x600c07ffeffff] (bus address [0x80000000-0xfffeffff])
[ 1.150397][ T1] pci_bus 0000:00: root bus resource [mem 0x6000000000000-0x6003fbfffffff 64bit pref]
[ 1.151013][ T1] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 1.151524][ T1] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to ff
[ 1.154823][ T1] pci 0000:00:00.0: [1014:04c1] type 01 class 0x060400
[ 1.167476][ T1] pci 0000:01:00.0: [10ec:8139] type 00 class 0x020000
[ 1.168101][ T1] pci 0000:01:00.0: reg 0x10: [io 0x0000-0x00ff]
[ 1.168442][ T1] pci 0000:01:00.0: reg 0x14: [mem 0x00000000-0x000000ff]
[ 1.168858][ T1] pci 0000:01:00.0: reg 0x30: [mem 0x00000000-0x0003ffff pref]
[ 1.169311][ T1] pci 0000:01:00.0: BAR1 [mem size 0x00000100]: requesting alignment to 0x10000
[ 1.172922][ T1] pci 0000:00:00.0: PCI bridge to [bus 01]
[ 1.174447][ T1] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 01
[ 1.176415][ T1] PCI host bridge to bus 0001:00
[ 1.176674][ T1] pci_bus 0001:00: root bus resource [mem 0x600c080000000-0x600c0fffeffff] (bus address [0x80000000-0xfffeffff])
[ 1.177170][ T1] pci_bus 0001:00: root bus resource [mem 0x6004000000000-0x6007f7fffffff 64bit pref]
[ 1.177597][ T1] pci_bus 0001:00: root bus resource [bus 00-ff]
[ 1.177871][ T1] pci_bus 0001:00: busn_res: [bus 00-ff] end is updated to ff
[ 1.178330][ T1] pci 0001:00:00.0: [1014:04c1] type 01 class 0x060400
[ 1.184174][ T1] pci 0001:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 1.187991][ T1] pci 0001:00:00.0: PCI bridge to [bus 01-ff]
[ 1.188371][ T1] pci_bus 0001:01: busn_res: [bus 01-ff] end is updated to 01
[ 1.189153][ T1] pci_bus 0001:00: busn_res: [bus 00-ff] end is updated to 01
[ 1.190752][ T1] PCI host bridge to bus 0002:00
[ 1.191002][ T1] pci_bus 0002:00: root bus resource [mem 0x600c100000000-0x600c17ffeffff] (bus address [0x80000000-0xfffeffff])
[ 1.191493][ T1] pci_bus 0002:00: root bus resource [mem 0x6008000000000-0x600bf7fffffff 64bit pref]
[ 1.191911][ T1] pci_bus 0002:00: root bus resource [bus 00-ff]
[ 1.192184][ T1] pci_bus 0002:00: busn_res: [bus 00-ff] end is updated to ff
[ 1.192636][ T1] pci 0002:00:00.0: [1014:04c1] type 01 class 0x060400
[ 1.199010][ T1] pci 0002:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 1.202319][ T1] pci 0002:00:00.0: PCI bridge to [bus 01-ff]
[ 1.202673][ T1] pci_bus 0002:01: busn_res: [bus 01-ff] end is updated to 01
[ 1.203269][ T1] pci_bus 0002:00: busn_res: [bus 00-ff] end is updated to 01
[ 1.204899][ T1] PCI host bridge to bus 0003:00
[ 1.205148][ T1] pci_bus 0003:00: root bus resource [mem 0x600c180000000-0x600c1fffeffff] (bus address [0x80000000-0xfffeffff])
[ 1.205642][ T1] pci_bus 0003:00: root bus resource [mem 0x6020000000000-0x6023fbfffffff 64bit pref]
[ 1.206748][ T1] pci_bus 0003:00: root bus resource [bus 00-ff]
[ 1.207045][ T1] pci_bus 0003:00: busn_res: [bus 00-ff] end is updated to ff
[ 1.207505][ T1] pci 0003:00:00.0: [1014:04c1] type 01 class 0x060400
[ 1.213117][ T1] pci 0003:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 1.216451][ T1] pci 0003:00:00.0: PCI bridge to [bus 01-ff]
[ 1.217503][ T1] pci_bus 0003:01: busn_res: [bus 01-ff] end is updated to 01
[ 1.218181][ T1] pci_bus 0003:00: busn_res: [bus 00-ff] end is updated to 01
[ 1.219717][ T1] PCI host bridge to bus 0004:00
[ 1.219968][ T1] pci_bus 0004:00: root bus resource [mem 0x600c200000000-0x600c27ffeffff] (bus address [0x80000000-0xfffeffff])
[ 1.220454][ T1] pci_bus 0004:00: root bus resource [mem 0x6024000000000-0x6027f7fffffff 64bit pref]
[ 1.220863][ T1] pci_bus 0004:00: root bus resource [bus 00-ff]
[ 1.221132][ T1] pci_bus 0004:00: busn_res: [bus 00-ff] end is updated to ff
[ 1.221585][ T1] pci 0004:00:00.0: [1014:04c1] type 01 class 0x060400
[ 1.227067][ T1] pci 0004:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 1.231059][ T1] pci 0004:00:00.0: PCI bridge to [bus 01-ff]
[ 1.231411][ T1] pci_bus 0004:01: busn_res: [bus 01-ff] end is updated to 01
[ 1.231984][ T1] pci_bus 0004:00: busn_res: [bus 00-ff] end is updated to 01
[ 1.233643][ T1] PCI host bridge to bus 0005:00
[ 1.233894][ T1] pci_bus 0005:00: root bus resource [mem 0x600c280000000-0x600c2fffeffff] (bus address [0x80000000-0xfffeffff])
[ 1.234393][ T1] pci_bus 0005:00: root bus resource [mem 0x6028000000000-0x602bf7fffffff 64bit pref]
[ 1.234799][ T1] pci_bus 0005:00: root bus resource [bus 00-ff]
[ 1.235079][ T1] pci_bus 0005:00: busn_res: [bus 00-ff] end is updated to ff
[ 1.235538][ T1] pci 0005:00:00.0: [1014:04c1] type 01 class 0x060400
[ 1.241752][ T1] pci 0005:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 1.245089][ T1] pci 0005:00:00.0: PCI bridge to [bus 01-ff]
[ 1.245444][ T1] pci_bus 0005:01: busn_res: [bus 01-ff] end is updated to 01
[ 1.246021][ T1] pci_bus 0005:00: busn_res: [bus 00-ff] end is updated to 01
[ 1.247644][ T1] pci 0000:00:00.0: bridge window [mem 0x20000000-0x1fffffff 64bit pref] to [bus 01] add_size 20000000 add_align 20000000
[ 1.249777][ T1] pci 0000:00:00.0: BAR 9: assigned [mem 0x6000000000000-0x600001fffffff 64bit pref]
[ 1.250256][ T1] pci 0000:00:00.0: BAR 8: assigned [mem 0x600c000000000-0x600c0003fffff]
[ 1.250664][ T1] pci 0000:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.250986][ T1] pci 0000:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.251724][ T1] pci 0000:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.252029][ T1] pci 0000:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.252488][ T1] pci 0000:01:00.0: BAR 6: assigned [mem 0x600c000000000-0x600c00003ffff pref]
[ 1.252966][ T1] pci 0000:01:00.0: BAR 1: assigned [mem 0x600c000040000-0x600c0000400ff]
[ 1.253406][ T1] pci 0000:01:00.0: BAR 0: no space for [io size 0x0100]
[ 1.253698][ T1] pci 0000:01:00.0: BAR 0: failed to assign [io size 0x0100]
[ 1.254222][ T1] pci 0000:00:00.0: PCI bridge to [bus 01]
[ 1.254868][ T1] pci 0000:00:00.0: bridge window [mem 0x600c000000000-0x600c07fefffff]
[ 1.255351][ T1] pci 0000:00:00.0: bridge window [mem 0x6000000000000-0x6003fbff0ffff 64bit pref]
[ 1.256063][ T1] pci_bus 0000:00: Some PCI device resources are unassigned, try booting with pci=realloc
[ 1.256580][ T1] pci_bus 0000:00: resource 4 [mem 0x600c000000000-0x600c07ffeffff]
[ 1.256922][ T1] pci_bus 0000:00: resource 5 [mem 0x6000000000000-0x6003fbfffffff 64bit pref]
[ 1.257298][ T1] pci_bus 0000:01: resource 1 [mem 0x600c000000000-0x600c07fefffff]
[ 1.257623][ T1] pci_bus 0000:01: resource 2 [mem 0x6000000000000-0x6003fbff0ffff 64bit pref]
[ 1.258108][ T1] pci 0001:00:00.0: bridge window [io 0x1000-0x0fff] to [bus 01] add_size 1000
[ 1.258537][ T1] pci 0001:00:00.0: bridge window [mem 0x40000000-0x3fffffff 64bit pref] to [bus 01] add_size 40000000 add_align 40000000
[ 1.259065][ T1] pci 0001:00:00.0: bridge window [mem 0x00800000-0x007fffff] to [bus 01] add_size 800000 add_align 800000
[ 1.259617][ T1] pci 0001:00:00.0: BAR 9: assigned [mem 0x6004000000000-0x600403fffffff 64bit pref]
[ 1.260009][ T1] pci 0001:00:00.0: BAR 8: assigned [mem 0x600c080000000-0x600c0807fffff]
[ 1.260501][ T1] pci 0001:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.260808][ T1] pci 0001:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.261239][ T1] pci 0001:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.261539][ T1] pci 0001:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.261933][ T1] pci 0001:00:00.0: PCI bridge to [bus 01]
[ 1.262441][ T1] pci 0001:00:00.0: bridge window [mem 0x600c080000000-0x600c0ffefffff]
[ 1.262836][ T1] pci 0001:00:00.0: bridge window [mem 0x6004000000000-0x6007f7ff0ffff 64bit pref]
[ 1.263456][ T1] pci_bus 0001:00: resource 4 [mem 0x600c080000000-0x600c0fffeffff]
[ 1.263827][ T1] pci_bus 0001:00: resource 5 [mem 0x6004000000000-0x6007f7fffffff 64bit pref]
[ 1.264186][ T1] pci_bus 0001:01: resource 1 [mem 0x600c080000000-0x600c0ffefffff]
[ 1.264507][ T1] pci_bus 0001:01: resource 2 [mem 0x6004000000000-0x6007f7ff0ffff 64bit pref]
[ 1.264910][ T1] pci 0002:00:00.0: bridge window [io 0x1000-0x0fff] to [bus 01] add_size 1000
[ 1.265291][ T1] pci 0002:00:00.0: bridge window [mem 0x40000000-0x3fffffff 64bit pref] to [bus 01] add_size 40000000 add_align 40000000
[ 1.265802][ T1] pci 0002:00:00.0: bridge window [mem 0x00800000-0x007fffff] to [bus 01] add_size 800000 add_align 800000
[ 1.266339][ T1] pci 0002:00:00.0: BAR 9: assigned [mem 0x6008000000000-0x600803fffffff 64bit pref]
[ 1.266722][ T1] pci 0002:00:00.0: BAR 8: assigned [mem 0x600c100000000-0x600c1007fffff]
[ 1.267067][ T1] pci 0002:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.267352][ T1] pci 0002:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.267712][ T1] pci 0002:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.268002][ T1] pci 0002:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.268316][ T1] pci 0002:00:00.0: PCI bridge to [bus 01]
[ 1.268818][ T1] pci 0002:00:00.0: bridge window [mem 0x600c100000000-0x600c17fefffff]
[ 1.269207][ T1] pci 0002:00:00.0: bridge window [mem 0x6008000000000-0x600bf7ff0ffff 64bit pref]
[ 1.269834][ T1] pci_bus 0002:00: resource 4 [mem 0x600c100000000-0x600c17ffeffff]
[ 1.270205][ T1] pci_bus 0002:00: resource 5 [mem 0x6008000000000-0x600bf7fffffff 64bit pref]
[ 1.270564][ T1] pci_bus 0002:01: resource 1 [mem 0x600c100000000-0x600c17fefffff]
[ 1.271232][ T1] pci_bus 0002:01: resource 2 [mem 0x6008000000000-0x600bf7ff0ffff 64bit pref]
[ 1.271649][ T1] pci 0003:00:00.0: bridge window [io 0x1000-0x0fff] to [bus 01] add_size 1000
[ 1.272043][ T1] pci 0003:00:00.0: bridge window [mem 0x20000000-0x1fffffff 64bit pref] to [bus 01] add_size 20000000 add_align 20000000
[ 1.272563][ T1] pci 0003:00:00.0: bridge window [mem 0x00400000-0x003fffff] to [bus 01] add_size 400000 add_align 400000
[ 1.273100][ T1] pci 0003:00:00.0: BAR 9: assigned [mem 0x6020000000000-0x602001fffffff 64bit pref]
[ 1.273487][ T1] pci 0003:00:00.0: BAR 8: assigned [mem 0x600c180000000-0x600c1803fffff]
[ 1.273832][ T1] pci 0003:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.274119][ T1] pci 0003:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.274478][ T1] pci 0003:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.274763][ T1] pci 0003:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.275085][ T1] pci 0003:00:00.0: PCI bridge to [bus 01]
[ 1.275632][ T1] pci 0003:00:00.0: bridge window [mem 0x600c180000000-0x600c1ffefffff]
[ 1.276022][ T1] pci 0003:00:00.0: bridge window [mem 0x6020000000000-0x6023fbff0ffff 64bit pref]
[ 1.276634][ T1] pci_bus 0003:00: resource 4 [mem 0x600c180000000-0x600c1fffeffff]
[ 1.276999][ T1] pci_bus 0003:00: resource 5 [mem 0x6020000000000-0x6023fbfffffff 64bit pref]
[ 1.277359][ T1] pci_bus 0003:01: resource 1 [mem 0x600c180000000-0x600c1ffefffff]
[ 1.277679][ T1] pci_bus 0003:01: resource 2 [mem 0x6020000000000-0x6023fbff0ffff 64bit pref]
[ 1.278082][ T1] pci 0004:00:00.0: bridge window [io 0x1000-0x0fff] to [bus 01] add_size 1000
[ 1.278464][ T1] pci 0004:00:00.0: bridge window [mem 0x40000000-0x3fffffff 64bit pref] to [bus 01] add_size 40000000 add_align 40000000
[ 1.278987][ T1] pci 0004:00:00.0: bridge window [mem 0x00800000-0x007fffff] to [bus 01] add_size 800000 add_align 800000
[ 1.279526][ T1] pci 0004:00:00.0: BAR 9: assigned [mem 0x6024000000000-0x602403fffffff 64bit pref]
[ 1.279925][ T1] pci 0004:00:00.0: BAR 8: assigned [mem 0x600c200000000-0x600c2007fffff]
[ 1.280273][ T1] pci 0004:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.280564][ T1] pci 0004:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.280932][ T1] pci 0004:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.281223][ T1] pci 0004:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.281688][ T1] pci 0004:00:00.0: PCI bridge to [bus 01]
[ 1.282222][ T1] pci 0004:00:00.0: bridge window [mem 0x600c200000000-0x600c27fefffff]
[ 1.282623][ T1] pci 0004:00:00.0: bridge window [mem 0x6024000000000-0x6027f7ff0ffff 64bit pref]
[ 1.283258][ T1] pci_bus 0004:00: resource 4 [mem 0x600c200000000-0x600c27ffeffff]
[ 1.283633][ T1] pci_bus 0004:00: resource 5 [mem 0x6024000000000-0x6027f7fffffff 64bit pref]
[ 1.284000][ T1] pci_bus 0004:01: resource 1 [mem 0x600c200000000-0x600c27fefffff]
[ 1.284324][ T1] pci_bus 0004:01: resource 2 [mem 0x6024000000000-0x6027f7ff0ffff 64bit pref]
[ 1.284724][ T1] pci 0005:00:00.0: bridge window [io 0x1000-0x0fff] to [bus 01] add_size 1000
[ 1.285109][ T1] pci 0005:00:00.0: bridge window [mem 0x40000000-0x3fffffff 64bit pref] to [bus 01] add_size 40000000 add_align 40000000
[ 1.285624][ T1] pci 0005:00:00.0: bridge window [mem 0x00800000-0x007fffff] to [bus 01] add_size 800000 add_align 800000
[ 1.286157][ T1] pci 0005:00:00.0: BAR 9: assigned [mem 0x6028000000000-0x602803fffffff 64bit pref]
[ 1.286544][ T1] pci 0005:00:00.0: BAR 8: assigned [mem 0x600c280000000-0x600c2807fffff]
[ 1.286895][ T1] pci 0005:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.287182][ T1] pci 0005:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.287543][ T1] pci 0005:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.287833][ T1] pci 0005:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.288149][ T1] pci 0005:00:00.0: PCI bridge to [bus 01]
[ 1.288640][ T1] pci 0005:00:00.0: bridge window [mem 0x600c280000000-0x600c2ffefffff]
[ 1.289031][ T1] pci 0005:00:00.0: bridge window [mem 0x6028000000000-0x602bf7ff0ffff 64bit pref]
[ 1.289663][ T1] pci_bus 0005:00: resource 4 [mem 0x600c280000000-0x600c2fffeffff]
[ 1.290038][ T1] pci_bus 0005:00: resource 5 [mem 0x6028000000000-0x602bf7fffffff 64bit pref]
[ 1.290415][ T1] pci_bus 0005:01: resource 1 [mem 0x600c280000000-0x600c2ffefffff]
[ 1.290744][ T1] pci_bus 0005:01: resource 2 [mem 0x6028000000000-0x602bf7ff0ffff 64bit pref]
[ 1.291302][ T1] pci_bus 0000:00: Configuring PE for bus
[ 1.292035][ T1] pci 0000:00 : [PE# 1fe] Secondary bus 0x0000000000000000 associated with PE#1fe
[ 1.293202][ T1] pci 0000:00:00.0: Configured PE#1fe
[ 1.295876][ T1] pci_bus 0000:01: Configuring PE for bus
[ 1.296332][ T1] pci 0000:01 : [PE# 1fd] Secondary bus 0x0000000000000001 associated with PE#1fd
[ 1.297103][ T1] pci 0000:01:00.0: Configured PE#1fd
[ 1.297363][ T1] pci 0000:01 : [PE# 1fd] Setting up 32-bit TCE table at 0..80000000
[ 1.298764][ T1] IOMMU table initialized, virtual merging enabled
[ 1.299106][ T1] pci 0000:01 : [PE# 1fd] Setting up window#0 0..7fffffff pg=10000
[ 1.299875][ T1] pci 0000:01 : [PE# 1fd] Enabling 64-bit DMA bypass
[ 1.301127][ T1] pci 0000:01:00.0: Adding to iommu group 0
[ 1.303551][ T1] pci_bus 0001:00: Configuring PE for bus
[ 1.303821][ T1] pci 0001:00 : [PE# fe] Secondary bus 0x0000000000000000 associated with PE#fe
[ 1.304336][ T1] pci 0001:00:00.0: Configured PE#fe
[ 1.305333][ T1] pci_bus 0002:00: Configuring PE for bus
[ 1.305584][ T1] pci 0002:00 : [PE# fe] Secondary bus 0x0000000000000000 associated with PE#fe
[ 1.306093][ T1] pci 0002:00:00.0: Configured PE#fe
[ 1.307058][ T1] pci_bus 0003:00: Configuring PE for bus
[ 1.307309][ T1] pci 0003:00 : [PE# 1fe] Secondary bus 0x0000000000000000 associated with PE#1fe
[ 1.307823][ T1] pci 0003:00:00.0: Configured PE#1fe
[ 1.308719][ T1] pci_bus 0004:00: Configuring PE for bus
[ 1.308969][ T1] pci 0004:00 : [PE# fe] Secondary bus 0x0000000000000000 associated with PE#fe
[ 1.309469][ T1] pci 0004:00:00.0: Configured PE#fe
[ 1.310396][ T1] pci_bus 0005:00: Configuring PE for bus
[ 1.310646][ T1] pci 0005:00 : [PE# fe] Secondary bus 0x0000000000000000 associated with PE#fe
[ 1.311146][ T1] pci 0005:00:00.0: Configured PE#fe
[ 1.314106][ T1] pci 0000:00:00.0: enabling device (0105 -> 0107)
[ 1.314972][ T1] EEH: Capable adapter found: recovery enabled.
[ 1.327661][ T1] cpuidle-powernv: Default stop: psscr = 0x0000000000000330,mask=0x00000000003003ff
[ 1.328088][ T1] cpuidle-powernv: Deepest stop: psscr = 0x0000000000300331,mask=0x00000000003003ff
[ 1.328467][ T1] cpuidle-powernv: First stop level that may lose SPRs = 0x10
[ 1.328771][ T1] cpuidle-powernv: First stop level that may lose timebase = 0x10
[ 1.418096][ T1] Kprobes globally optimized
[ 1.445284][ T34] cryptomgr_test (34) used greatest stack depth: 10880 bytes left
[ 1.477721][ T43] cryptomgr_test (43) used greatest stack depth: 10528 bytes left
[ 1.649775][ T1] raid6: vpermxor8 gen() 911 MB/s
[ 1.821391][ T1] raid6: vpermxor4 gen() 892 MB/s
[ 1.992859][ T1] raid6: vpermxor2 gen() 801 MB/s
[ 2.164481][ T1] raid6: vpermxor1 gen() 670 MB/s
[ 2.336154][ T1] raid6: altivecx8 gen() 1082 MB/s
[ 2.507671][ T1] raid6: altivecx4 gen() 1221 MB/s
[ 2.679460][ T1] raid6: altivecx2 gen() 1120 MB/s
[ 2.850914][ T1] raid6: altivecx1 gen() 843 MB/s
[ 3.022625][ T1] raid6: int64x8 gen() 1612 MB/s
[ 3.195010][ T1] raid6: int64x8 xor() 1085 MB/s
[ 3.366613][ T1] raid6: int64x4 gen() 2585 MB/s
[ 3.539108][ T1] raid6: int64x4 xor() 1289 MB/s
[ 3.711797][ T1] raid6: int64x2 gen() 2250 MB/s
[ 3.884349][ T1] raid6: int64x2 xor() 1449 MB/s
[ 4.055962][ T1] raid6: int64x1 gen() 1654 MB/s
[ 4.227577][ T1] raid6: int64x1 xor() 1052 MB/s
[ 4.227844][ T1] raid6: using algorithm int64x4 gen() 2585 MB/s
[ 4.228126][ T1] raid6: .... xor() 1289 MB/s, rmw enabled
[ 4.228428][ T1] raid6: using intx1 recovery algorithm
[ 4.229638][ T1] iommu: Default domain type: Translated
[ 4.229925][ T1] iommu: DMA domain TLB invalidation policy: lazy mode
[ 4.237510][ T1] vgaarb: loaded
[ 4.246973][ T1] SCSI subsystem initialized
[ 4.250526][ T1] usbcore: registered new interface driver usbfs
[ 4.251465][ T1] usbcore: registered new interface driver hub
[ 4.252078][ T1] usbcore: registered new device driver usb
[ 4.270795][ T1] clocksource: Switched to clocksource timebase
[ 4.952052][ T1] hugetlbfs: disabling because there are no supported hugepage sizes
[ 5.048614][ T1] NET: Registered PF_INET protocol family
[ 5.050972][ T1] IP idents hash table entries: 32768 (order: 2, 262144 bytes, linear)
[ 5.058507][ T1] tcp_listen_portaddr_hash hash table entries: 1024 (order: 0, 81920 bytes, linear)
[ 5.059211][ T1] TCP established hash table entries: 16384 (order: 1, 131072 bytes, linear)
[ 5.060165][ T1] TCP bind hash table entries: 16384 (order: 4, 1179648 bytes, linear)
[ 5.063161][ T1] TCP: Hash tables configured (established 16384 bind 16384)
[ 5.064854][ T1] UDP hash table entries: 1024 (order: 1, 163840 bytes, linear)
[ 5.065745][ T1] UDP-Lite hash table entries: 1024 (order: 1, 163840 bytes, linear)
[ 5.068316][ T1] NET: Registered PF_UNIX/PF_LOCAL protocol family
[ 5.069444][ T1] PCI: CLS 0 bytes, default 128
[ 11.698074][ T1] workingset: timestamp_bits=38 max_order=15 bucket_order=0
[ 11.863823][ T1] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 11.868058][ T1] xor: measuring software checksum speed
[ 11.871448][ T1] 8regs : 3419 MB/sec
[ 11.875731][ T1] 8regs_prefetch : 2781 MB/sec
[ 11.879196][ T1] 32regs : 3140 MB/sec
[ 11.883403][ T1] 32regs_prefetch : 2606 MB/sec
[ 11.887182][ T1] altivec : 2876 MB/sec
[ 11.887443][ T1] xor: using function: 8regs (3419 MB/sec)
[ 11.888066][ T1] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
[ 11.888569][ T1] io scheduler mq-deadline registered
[ 11.888942][ T1] io scheduler kyber registered
[ 12.533563][ T1] String selftests succeeded
[ 12.536168][ T1] test_firmware: interface ready
[ 12.536606][ T1] test_bitmap: loaded.
[ 12.538982][ T1] test_bitmap: parselist: 14: input is '0-2047:128/256' OK, Time: 2500
[ 12.540499][ T1] test_bitmap: bitmap_print_to_pagebuf: input is '0-524287
[ 12.540499][ T1] ', Time: 196283
[ 12.547687][ T1] test_bitmap: all 1943 tests passed
[ 12.548124][ T1] test_uuid: all 18 tests passed
[ 12.550638][ T1] crc32: CRC_LE_BITS = 64, CRC_BE BITS = 64
[ 12.550919][ T1] crc32: self tests passed, processed 225944 bytes in 441546 nsec
[ 12.551692][ T1] crc32c: CRC_LE_BITS = 64
[ 12.551895][ T1] crc32c: self tests passed, processed 225944 bytes in 210993 nsec
[ 12.589245][ T1] crc32_combine: 8373 self tests passed
[ 12.625891][ T1] crc32c_combine: 8373 self tests passed
[ 12.626772][ T1] glob: 64 self-tests passed, 0 failed
[ 12.632624][ T1] rbtree testing
[ 12.653861][ T1] -> test 1 (latency of nnodes insert+delete): 10807 cycles
[ 12.666573][ T1] -> test 2 (latency of nnodes cached insert+delete): 6252 cycles
[ 12.669009][ T1] -> test 3 (latency of inorder traversal): 1046 cycles
[ 12.669361][ T1] -> test 4 (latency to fetch first node)
[ 12.669608][ T1] non-cached: 27 cycles
[ 12.669823][ T1] cached: 0 cycles
[ 12.769434][ T1] augmented rbtree testing
[ 12.812243][ T1] -> test 1 (latency of nnodes insert+delete): 21897 cycles
[ 12.860505][ T1] -> test 2 (latency of nnodes cached insert+delete): 24428 cycles
[ 12.994713][ T1] interval tree insert/remove
[ 13.018177][ T1] -> 11958 cycles
[ 13.018560][ T1] interval tree search
[ 13.112939][ T1] -> 48288 cycles (2692 results)
[ 13.114012][ T1] IPMI message handler: version 39.2
[ 13.114781][ T1] ipmi device interface
[ 13.345730][ T1] ipmi-powernv ibm,opal:ipmi: IPMI message handler: Found new BMC (man_id: 0x000000, prod_id: 0x0000, dev_id: 0x20)
[ 13.569872][ T1] hvc0: raw protocol on /ibm,opal/consoles/serial@0 (boot console)
[ 13.571124][ T1] hvc0: No interrupts property, using OPAL event
[ 13.579830][ T1] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[ 13.647596][ T1] loop: module loaded
[ 13.650217][ T1] Adaptec aacraid driver 1.2.1[50983]-custom
[ 13.652349][ T1] megasas: 07.717.02.00-rc1
[ 13.653397][ T1] ipr: IBM Power RAID SCSI Device Driver version: 2.6.4 (March 14, 2017)
[ 13.679028][ T1] 1 fixed-partitions partitions found on MTD device flash@0
[ 13.679453][ T1] Creating 1 MTD partitions on "flash@0":
[ 13.679876][ T1] 0x000000000000-0x000002000000 : "PNOR"
[ 13.711952][ T1] libphy: Fixed MDIO Bus: probed
[ 13.715189][ T1] e100: Intel(R) PRO/100 Network Driver
[ 13.715437][ T1] e100: Copyright(c) 1999-2006 Intel Corporation
[ 13.715979][ T1] e1000: Intel(R) PRO/1000 Network Driver
[ 13.716232][ T1] e1000: Copyright (c) 1999-2006 Intel Corporation.
[ 13.716928][ T1] e1000e: Intel(R) PRO/1000 Network Driver
[ 13.717181][ T1] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
[ 13.718728][ T11] 8139cp: 8139cp: 10/100 PCI Ethernet driver v1.3 (Mar 22, 2004)
[ 13.719630][ T11] 8139cp 0000:01:00.0: enabling device (0100 -> 0102)
[ 13.726664][ T11] 8139cp 0000:01:00.0 eth0: RTL-8139C+ at 0xc00a000080630000, 52:54:00:12:34:56, IRQ 32
[ 13.728905][ T1] usbcore: registered new interface driver asix
[ 13.729476][ T1] usbcore: registered new interface driver ax88179_178a
[ 13.730006][ T1] usbcore: registered new interface driver cdc_ether
[ 13.730746][ T1] usbcore: registered new interface driver net1080
[ 13.731272][ T1] usbcore: registered new interface driver cdc_subset
[ 13.731791][ T1] usbcore: registered new interface driver zaurus
[ 13.732528][ T1] usbcore: registered new interface driver cdc_ncm
[ 13.732828][ T1] Fusion MPT base driver 3.04.20
[ 13.733047][ T1] Copyright (c) 1999-2008 LSI Corporation
[ 13.733504][ T1] Fusion MPT SAS Host driver 3.04.20
[ 13.735177][ T1] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 13.735547][ T1] ehci-pci: EHCI PCI platform driver
[ 13.736156][ T1] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 13.738233][ T1] usbcore: registered new interface driver uas
[ 13.738956][ T1] usbcore: registered new interface driver usb-storage
[ 13.739614][ T1] usbcore: registered new interface driver usbtest
[ 13.740123][ T1] usbcore: registered new interface driver usb_ehset_test
[ 13.740829][ T1] usbcore: registered new interface driver lvs
[ 13.984603][ T1] rtc-opal opal-rtc: registered as rtc0
[ 14.191792][ T1] rtc-opal opal-rtc: setting system clock to 2021-08-18T02:42:24 UTC (1629254544)
[ 14.193896][ T1] i2c /dev entries driver
[ 14.202822][ T1] device-mapper: uevent: version 1.0.3
[ 14.209077][ T1] device-mapper: ioctl: 4.45.0-ioctl (2021-03-22) initialised: dm-devel@redhat.com
[ 14.209551][ T1] powernv-cpufreq: ibm,pstate-min node not found
[ 14.209825][ T1] powernv-cpufreq: Platform driver disabled. System does not support PState control
[ 14.213922][ T1] sdhci: Secure Digital Host Controller Interface driver
[ 14.214246][ T1] sdhci: Copyright(c) Pierre Ossman
[ 14.216479][ T1] ipip: IPv4 and MPLS over IPv4 tunneling driver
[ 14.228886][ T1] NET: Registered PF_INET6 protocol family
[ 14.243458][ T1] Segment Routing with IPv6
[ 14.243966][ T1] In-situ OAM (IOAM) with IPv6
[ 14.244762][ T1] NET: Registered PF_PACKET protocol family
[ 14.246324][ T1] Key type dns_resolver registered
[ 14.246774][ T1] drmem: No dynamic reconfiguration memory found
[ 14.258788][ T1] registered taskstats version 1
[ 14.282301][ T1] Btrfs loaded, crc32c=crc32c-generic, zoned=no, fsverity=no
[ 14.292334][ T1] ### dt-test ### start of unittest - you will see error messages
[ 14.296627][ T1] ### dt-test ### EXPECT \ : Duplicate name in testcase-data, renamed to "duplicate-name#1"
[ 14.297957][ T1] Duplicate name in testcase-data, renamed to "duplicate-name#1"
[ 14.322891][ T1] ### dt-test ### EXPECT / : Duplicate name in testcase-data, renamed to "duplicate-name#1"
[ 14.328302][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-a: could not get #phandle-cells-missing for /testcase-data/phandle-tests/provider1
[ 14.328760][ T1] OF: /testcase-data/phandle-tests/consumer-a: could not get #phandle-cells-missing for /testcase-data/phandle-tests/provider1
[ 14.329967][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-a: could not get #phandle-cells-missing for /testcase-data/phandle-tests/provider1
[ 14.329990][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-a: could not get #phandle-cells-missing for /testcase-data/phandle-tests/provider1
[ 14.330773][ T1] OF: /testcase-data/phandle-tests/consumer-a: could not get #phandle-cells-missing for /testcase-data/phandle-tests/provider1
[ 14.331988][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-a: could not get #phandle-cells-missing for /testcase-data/phandle-tests/provider1
[ 14.332025][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-a: could not find phandle
[ 14.332660][ T1] OF: /testcase-data/phandle-tests/consumer-a: could not find phandle 12345678
[ 14.333489][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-a: could not find phandle
[ 14.333533][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-a: could not find phandle
[ 14.333966][ T1] OF: /testcase-data/phandle-tests/consumer-a: could not find phandle 12345678
[ 14.334811][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-a: could not find phandle
[ 14.334842][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-a: #phandle-cells = 3 found -1
[ 14.335284][ T1] OF: /testcase-data/phandle-tests/consumer-a: #phandle-cells = 3 found -1
[ 14.336102][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-a: #phandle-cells = 3 found -1
[ 14.336124][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-a: #phandle-cells = 3 found -1
[ 14.336574][ T1] OF: /testcase-data/phandle-tests/consumer-a: #phandle-cells = 3 found -1
[ 14.337380][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-a: #phandle-cells = 3 found -1
[ 14.338978][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-b: could not get #phandle-missing-cells for /testcase-data/phandle-tests/provider1
[ 14.339501][ T1] OF: /testcase-data/phandle-tests/consumer-b: could not get #phandle-missing-cells for /testcase-data/phandle-tests/provider1
[ 14.341394][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-b: could not get #phandle-missing-cells for /testcase-data/phandle-tests/provider1
[ 14.341466][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-b: could not find phandle
[ 14.342848][ T1] OF: /testcase-data/phandle-tests/consumer-b: could not find phandle 12345678
[ 14.344546][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-b: could not find phandle
[ 14.344606][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-b: #phandle-cells = 2 found -1
[ 14.345657][ T1] OF: /testcase-data/phandle-tests/consumer-b: #phandle-cells = 2 found -1
[ 14.347372][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-b: #phandle-cells = 2 found -1
[ 14.353289][ T1] ### dt-test ### FAIL of_unittest_dma_ranges_one():922 of_dma_get_range: wrong phys addr 0x0000000000000000 (expecting 20000000) on node /testcase-data/address-tests/device@70000000
[ 14.354511][ T1] ### dt-test ### FAIL of_unittest_dma_ranges_one():925 of_dma_get_range: wrong DMA addr 0x0000000020000000 (expecting 0) on node /testcase-data/address-tests/device@70000000
[ 14.355461][ T1] ### dt-test ### FAIL of_unittest_dma_ranges_one():922 of_dma_get_range: wrong phys addr 0x0000000100000000 (expecting 20000000) on node /testcase-data/address-tests/bus@80000000/device@1000
[ 14.356255][ T1] ### dt-test ### FAIL of_unittest_dma_ranges_one():925 of_dma_get_range: wrong DMA addr 0x0000000020000000 (expecting 100000000) on node /testcase-data/address-tests/bus@80000000/device@1000
[ 14.357459][ T1] ### dt-test ### FAIL of_unittest_dma_ranges_one():922 of_dma_get_range: wrong phys addr 0x0000000080000000 (expecting 20000000) on node /testcase-data/address-tests/pci@90000000
[ 14.358210][ T1] ### dt-test ### FAIL of_unittest_dma_ranges_one():925 of_dma_get_range: wrong DMA addr 0x0000000020000000 (expecting 80000000) on node /testcase-data/address-tests/pci@90000000
[ 14.361799][ T1] ### dt-test ### EXPECT \ : platform testcase-data:testcase-device2: IRQ index 0 not found
[ 14.361874][ T1] platform testcase-data:testcase-device2: IRQ index 0 not found
[ 14.362644][ T1] ### dt-test ### EXPECT / : platform testcase-data:testcase-device2: IRQ index 0 not found
[ 14.371513][ T1] ### dt-test ### end of unittest - 184 passed, 6 failed
[ 14.375004][ T1] TAP version 14
[ 14.375192][ T1] 1..11
[ 14.375391][ T1] # Subtest: sysctl_test
[ 14.375460][ T1] 1..10
[ 14.378464][ T1] ok 1 - sysctl_test_api_dointvec_null_tbl_data
[ 14.379651][ T1] ok 2 - sysctl_test_api_dointvec_table_maxlen_unset
[ 14.381506][ T1] ok 3 - sysctl_test_api_dointvec_table_len_is_zero
[ 14.382656][ T1] ok 4 - sysctl_test_api_dointvec_table_read_but_position_set
[ 14.384011][ T1] ok 5 - sysctl_test_dointvec_read_happy_single_positive
[ 14.385228][ T1] ok 6 - sysctl_test_dointvec_read_happy_single_negative
[ 14.386628][ T1] ok 7 - sysctl_test_dointvec_write_happy_single_positive
[ 14.387832][ T1] ok 8 - sysctl_test_dointvec_write_happy_single_negative
[ 14.389086][ T1] ok 9 - sysctl_test_api_dointvec_write_single_less_int_min
[ 14.390490][ T1] ok 10 - sysctl_test_api_dointvec_write_single_greater_int_max
[ 14.390881][ T1] # sysctl_test: pass:10 fail:0 skip:0 total:10
[ 14.391258][ T1] # Totals: pass:10 fail:0 skip:0 total:10
[ 14.391605][ T1] ok 1 - sysctl_test
[ 14.392077][ T1] # Subtest: ext4_inode_test
[ 14.392090][ T1] 1..1
[ 14.393284][ T1] # inode_test_xtimestamp_decoding: ok 1 - 1901-12-13 Lower bound of 32bit < 0 timestamp, no extra bits
[ 14.394195][ T1] # inode_test_xtimestamp_decoding: ok 2 - 1969-12-31 Upper bound of 32bit < 0 timestamp, no extra bits
[ 14.395457][ T1] # inode_test_xtimestamp_decoding: ok 3 - 1970-01-01 Lower bound of 32bit >=0 timestamp, no extra bits
[ 14.396662][ T1] # inode_test_xtimestamp_decoding: ok 4 - 2038-01-19 Upper bound of 32bit >=0 timestamp, no extra bits
[ 14.397815][ T1] # inode_test_xtimestamp_decoding: ok 5 - 2038-01-19 Lower bound of 32bit <0 timestamp, lo extra sec bit on
[ 14.398969][ T1] # inode_test_xtimestamp_decoding: ok 6 - 2106-02-07 Upper bound of 32bit <0 timestamp, lo extra sec bit on
[ 14.400124][ T1] # inode_test_xtimestamp_decoding: ok 7 - 2106-02-07 Lower bound of 32bit >=0 timestamp, lo extra sec bit on
[ 14.402278][ T1] # inode_test_xtimestamp_decoding: ok 8 - 2174-02-25 Upper bound of 32bit >=0 timestamp, lo extra sec bit on
[ 14.403526][ T1] # inode_test_xtimestamp_decoding: ok 9 - 2174-02-25 Lower bound of 32bit <0 timestamp, hi extra sec bit on
[ 14.404696][ T1] # inode_test_xtimestamp_decoding: ok 10 - 2242-03-16 Upper bound of 32bit <0 timestamp, hi extra sec bit on
[ 14.405854][ T1] # inode_test_xtimestamp_decoding: ok 11 - 2242-03-16 Lower bound of 32bit >=0 timestamp, hi extra sec bit on
[ 14.407020][ T1] # inode_test_xtimestamp_decoding: ok 12 - 2310-04-04 Upper bound of 32bit >=0 timestamp, hi extra sec bit on
[ 14.408178][ T1] # inode_test_xtimestamp_decoding: ok 13 - 2310-04-04 Upper bound of 32bit>=0 timestamp, hi extra sec bit 1. 1 ns
[ 14.409335][ T1] # inode_test_xtimestamp_decoding: ok 14 - 2378-04-22 Lower bound of 32bit>= timestamp. Extra sec bits 1. Max ns
[ 14.411220][ T1] # inode_test_xtimestamp_decoding: ok 15 - 2378-04-22 Lower bound of 32bit >=0 timestamp. All extra sec bits on
[ 14.412401][ T1] # inode_test_xtimestamp_decoding: ok 16 - 2446-05-10 Upper bound of 32bit >=0 timestamp. All extra sec bits on
[ 14.412926][ T1] # inode_test_xtimestamp_decoding: pass:16 fail:0 skip:0 total:16
[ 14.413434][ T1] ok 1 - inode_test_xtimestamp_decoding
[ 14.413780][ T1] # Totals: pass:16 fail:0 skip:0 total:16
[ 14.414032][ T1] ok 2 - ext4_inode_test
[ 14.414468][ T1] # Subtest: lib_sort
[ 14.414480][ T1] 1..1
[ 14.415945][ T1] ok 1 - test_sort
[ 14.416111][ T1] ok 3 - lib_sort
[ 14.416444][ T1] # Subtest: kunit_executor_test
[ 14.416455][ T1] 1..3
[ 14.417902][ T1] ok 1 - filter_subsuite_test
[ 14.418905][ T1] ok 2 - filter_subsuite_to_empty_test
[ 14.420261][ T1] ok 3 - filter_suites_test
[ 14.421124][ T1] # kunit_executor_test: pass:3 fail:0 skip:0 total:3
[ 14.421343][ T1] # Totals: pass:3 fail:0 skip:0 total:3
[ 14.421626][ T1] ok 4 - kunit_executor_test
[ 14.422053][ T1] # Subtest: kunit-try-catch-test
[ 14.422065][ T1] 1..2
[ 14.424075][ T1] ok 1 - kunit_test_try_catch_successful_try_no_catch
[ 14.425713][ T1] ok 2 - kunit_test_try_catch_unsuccessful_try_does_catch
[ 14.426024][ T1] # kunit-try-catch-test: pass:2 fail:0 skip:0 total:2
[ 14.426347][ T1] # Totals: pass:2 fail:0 skip:0 total:2
[ 14.426633][ T1] ok 5 - kunit-try-catch-test
[ 14.427069][ T1] # Subtest: kunit-resource-test
[ 14.427080][ T1] 1..7
[ 14.428173][ T1] ok 1 - kunit_resource_test_init_resources
[ 14.429237][ T1] ok 2 - kunit_resource_test_alloc_resource
[ 14.431621][ T1] ok 3 - kunit_resource_test_destroy_resource
[ 14.432898][ T1] ok 4 - kunit_resource_test_cleanup_resources
[ 14.434190][ T1] ok 5 - kunit_resource_test_proper_free_ordering
[ 14.435279][ T1] ok 6 - kunit_resource_test_static
[ 14.436861][ T1] ok 7 - kunit_resource_test_named
[ 14.437112][ T1] # kunit-resource-test: pass:7 fail:0 skip:0 total:7
[ 14.437346][ T1] # Totals: pass:7 fail:0 skip:0 total:7
[ 14.437627][ T1] ok 6 - kunit-resource-test
[ 14.438049][ T1] # Subtest: kunit-log-test
[ 14.438059][ T1] 1..1
[ 14.438771][ T104] put this in log.
[ 14.438939][ T104] this too.
[ 14.439116][ T104] add to suite log.
[ 14.439272][ T104] along with this.
[ 14.439707][ T1] ok 1 - kunit_log_test
[ 14.439888][ T1] ok 7 - kunit-log-test
[ 14.440257][ T1] # Subtest: kunit_status
[ 14.440268][ T1] 1..2
[ 14.441840][ T1] ok 1 - kunit_status_set_failure_test
[ 14.442860][ T1] ok 2 - kunit_status_mark_skipped_test
[ 14.443125][ T1] # kunit_status: pass:2 fail:0 skip:0 total:2
[ 14.443377][ T1] # Totals: pass:2 fail:0 skip:0 total:2
[ 14.443637][ T1] ok 8 - kunit_status
[ 14.444039][ T1] # Subtest: string-stream-test
[ 14.444050][ T1] 1..3
[ 14.445245][ T1] ok 1 - string_stream_test_empty_on_creation
[ 14.446679][ T1] ok 2 - string_stream_test_not_empty_after_add
[ 14.448202][ T1] ok 3 - string_stream_test_get_string
[ 14.448495][ T1] # string-stream-test: pass:3 fail:0 skip:0 total:3
[ 14.448746][ T1] # Totals: pass:3 fail:0 skip:0 total:3
[ 14.449023][ T1] ok 9 - string-stream-test
[ 14.449446][ T1] # Subtest: list-kunit-test
[ 14.449457][ T1] 1..36
[ 14.451451][ T1] ok 1 - list_test_list_init
[ 14.452493][ T1] ok 2 - list_test_list_add
[ 14.453552][ T1] ok 3 - list_test_list_add_tail
[ 14.454616][ T1] ok 4 - list_test_list_del
[ 14.455644][ T1] ok 5 - list_test_list_replace
[ 14.456671][ T1] ok 6 - list_test_list_replace_init
[ 14.457789][ T1] ok 7 - list_test_list_swap
[ 14.458867][ T1] ok 8 - list_test_list_del_init
[ 14.459925][ T1] ok 9 - list_test_list_move
[ 14.461559][ T1] ok 10 - list_test_list_move_tail
[ 14.462757][ T1] ok 11 - list_test_list_bulk_move_tail
[ 14.463787][ T1] ok 12 - list_test_list_is_first
[ 14.464823][ T1] ok 13 - list_test_list_is_last
[ 14.465859][ T1] ok 14 - list_test_list_empty
[ 14.466872][ T1] ok 15 - list_test_list_empty_careful
[ 14.467928][ T1] ok 16 - list_test_list_rotate_left
[ 14.469065][ T1] ok 17 - list_test_list_rotate_to_front
[ 14.470131][ T1] ok 18 - list_test_list_is_singular
[ 14.471588][ T1] ok 19 - list_test_list_cut_position
[ 14.472793][ T1] ok 20 - list_test_list_cut_before
[ 14.473933][ T1] ok 21 - list_test_list_splice
[ 14.475096][ T1] ok 22 - list_test_list_splice_tail
[ 14.476234][ T1] ok 23 - list_test_list_splice_init
[ 14.477388][ T1] ok 24 - list_test_list_splice_tail_init
[ 14.478401][ T1] ok 25 - list_test_list_entry
[ 14.479436][ T1] ok 26 - list_test_list_first_entry
[ 14.481777][ T1] ok 27 - list_test_list_last_entry
[ 14.482916][ T1] ok 28 - list_test_list_first_entry_or_null
[ 14.483933][ T1] ok 29 - list_test_list_next_entry
[ 14.484971][ T1] ok 30 - list_test_list_prev_entry
[ 14.486050][ T1] ok 31 - list_test_list_for_each
[ 14.487135][ T1] ok 32 - list_test_list_for_each_prev
[ 14.488253][ T1] ok 33 - list_test_list_for_each_safe
[ 14.489385][ T1] ok 34 - list_test_list_for_each_prev_safe
[ 14.491430][ T1] ok 35 - list_test_list_for_each_entry
[ 14.492601][ T1] ok 36 - list_test_list_for_each_entry_reverse
[ 14.492868][ T1] # list-kunit-test: pass:36 fail:0 skip:0 total:36
[ 14.493149][ T1] # Totals: pass:36 fail:0 skip:0 total:36
[ 14.493425][ T1] ok 10 - list-kunit-test
[ 14.493848][ T1] # Subtest: qos-kunit-test
[ 14.493859][ T1] 1..3
[ 14.495411][ T1] ok 1 - freq_qos_test_min
[ 14.496624][ T1] ok 2 - freq_qos_test_maxdef
[ 14.497716][ T1] ok 3 - freq_qos_test_readd
[ 14.497949][ T1] # qos-kunit-test: pass:3 fail:0 skip:0 total:3
[ 14.498176][ T1] # Totals: pass:3 fail:0 skip:0 total:3
[ 14.498441][ T1] ok 11 - qos-kunit-test
[ 14.505883][ T1] md: Waiting for all devices to be available before autodetect
[ 14.506243][ T1] md: If you don't use raid, use raid=noautodetect
[ 14.506595][ T1] md: Autodetecting RAID arrays.
[ 14.506868][ T1] md: autorun ...
[ 14.507051][ T1] md: ... autorun DONE.
[ 14.509976][ T1]
[ 14.510063][ T1] ======================================================
[ 14.510243][ T1] WARNING: possible circular locking dependency detected
[ 14.510463][ T1] 5.14.0-rc6-next-20210817 #1 Not tainted
[ 14.510664][ T1] ------------------------------------------------------
[ 14.510835][ T1] swapper/0/1 is trying to acquire lock:
[ 14.511006][ T1] c00000000192c620 (mtd_table_mutex){+.+.}-{3:3}, at: blktrans_open+0x60/0x300
[ 14.511490][ T1]
[ 14.511490][ T1] but task is already holding lock:
[ 14.511672][ T1] c000000005a7b118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev+0x20c/0x3c0
[ 14.511946][ T1]
[ 14.511946][ T1] which lock already depends on the new lock.
[ 14.511946][ T1]
[ 14.512198][ T1]
[ 14.512198][ T1] the existing dependency chain (in reverse order) is:
[ 14.512434][ T1]
[ 14.512434][ T1] -> #1 (&disk->open_mutex){+.+.}-{3:3}:
[ 14.512676][ T1] __mutex_lock+0xd8/0xaf0
[ 14.512849][ T1] bd_register_pending_holders+0x48/0x190
[ 14.513013][ T1] device_add_disk+0x27c/0x3d0
[ 14.513171][ T1] add_mtd_blktrans_dev+0x358/0x620
[ 14.513332][ T1] mtdblock_add_mtd+0x94/0x120
[ 14.513487][ T1] blktrans_notify_add+0x7c/0xb0
[ 14.513644][ T1] add_mtd_device+0x3f8/0x600
[ 14.513789][ T1] add_mtd_partitions+0xfc/0x2b0
[ 14.513944][ T1] parse_mtd_partitions+0x2b4/0x980
[ 14.514115][ T1] mtd_device_parse_register+0xc0/0x3a0
[ 14.514281][ T1] powernv_flash_probe+0x180/0x240
[ 14.514444][ T1] platform_probe+0x78/0x120
[ 14.514598][ T1] really_probe+0x1cc/0x440
[ 14.514738][ T1] __driver_probe_device+0xb0/0x160
[ 14.514892][ T1] driver_probe_device+0x60/0x130
[ 14.515043][ T1] __driver_attach+0xe8/0x160
[ 14.515188][ T1] bus_for_each_dev+0xb4/0x130
[ 14.515328][ T1] driver_attach+0x34/0x50
[ 14.515466][ T1] bus_add_driver+0x1d8/0x2b0
[ 14.515608][ T1] driver_register+0x98/0x1a0
[ 14.515753][ T1] __platform_driver_register+0x38/0x50
[ 14.515923][ T1] powernv_flash_driver_init+0x2c/0x40
[ 14.516084][ T1] do_one_initcall+0x88/0x480
[ 14.516223][ T1] kernel_init_freeable+0x3dc/0x484
[ 14.516392][ T1] kernel_init+0x3c/0x180
[ 14.516522][ T1] ret_from_kernel_thread+0x5c/0x64
[ 14.516718][ T1]
[ 14.516718][ T1] -> #0 (mtd_table_mutex){+.+.}-{3:3}:
[ 14.516917][ T1] __lock_acquire+0x1b5c/0x21d0
[ 14.517068][ T1] lock_acquire+0x2d8/0x4b0
[ 14.517208][ T1] __mutex_lock+0xd8/0xaf0
[ 14.517342][ T1] blktrans_open+0x60/0x300
[ 14.517487][ T1] blkdev_get_whole+0x50/0x110
[ 14.517632][ T1] blkdev_get_by_dev+0x1dc/0x3c0
[ 14.517782][ T1] blkdev_get_by_path+0x90/0xe0
[ 14.517931][ T1] mount_bdev+0x6c/0x2b0
[ 14.518063][ T1] ext4_mount+0x28/0x40
[ 14.518207][ T1] legacy_get_tree+0x4c/0xb0
[ 14.518358][ T1] vfs_get_tree+0x48/0x100
[ 14.518489][ T1] path_mount+0x2d8/0xd30
[ 14.518616][ T1] init_mount+0x7c/0xcc
[ 14.518759][ T1] mount_block_root+0x230/0x454
[ 14.518894][ T1] prepare_namespace+0x1b0/0x204
[ 14.519031][ T1] kernel_init_freeable+0x428/0x484
[ 14.519193][ T1] kernel_init+0x3c/0x180
[ 14.519321][ T1] ret_from_kernel_thread+0x5c/0x64
[ 14.519501][ T1]
[ 14.519501][ T1] other info that might help us debug this:
[ 14.519501][ T1]
[ 14.519756][ T1] Possible unsafe locking scenario:
[ 14.519756][ T1]
[ 14.519934][ T1] CPU0 CPU1
[ 14.520065][ T1] ---- ----
[ 14.520194][ T1] lock(&disk->open_mutex);
[ 14.520326][ T1] lock(mtd_table_mutex);
[ 14.520506][ T1] lock(&disk->open_mutex);
[ 14.520693][ T1] lock(mtd_table_mutex);
[ 14.520822][ T1]
[ 14.520822][ T1] *** DEADLOCK ***
[ 14.520822][ T1]
[ 14.521042][ T1] 1 lock held by swapper/0/1:
[ 14.521181][ T1] #0: c000000005a7b118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev+0x20c/0x3c0
[ 14.521481][ T1]
[ 14.521481][ T1] stack backtrace:
[ 14.521733][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.14.0-rc6-next-20210817 #1
[ 14.522127][ T1] Call Trace:
[ 14.522256][ T1] [c000000002d072b0] [c0000000009106c8] dump_stack_lvl+0xac/0x108 (unreliable)
[ 14.522564][ T1] [c000000002d072f0] [c0000000001aa04c] print_circular_bug.isra.44+0x37c/0x3e0
[ 14.522812][ T1] [c000000002d07390] [c0000000001aa270] check_noncircular+0x1c0/0x1f0
[ 14.523024][ T1] [c000000002d07460] [c0000000001aff3c] __lock_acquire+0x1b5c/0x21d0
[ 14.523236][ T1] [c000000002d075a0] [c0000000001ad2b8] lock_acquire+0x2d8/0x4b0
[ 14.523439][ T1] [c000000002d076a0] [c0000000010ae868] __mutex_lock+0xd8/0xaf0
[ 14.523644][ T1] [c000000002d077b0] [c000000000bad9f0] blktrans_open+0x60/0x300
[ 14.523858][ T1] [c000000002d07800] [c000000000540050] blkdev_get_whole+0x50/0x110
[ 14.524069][ T1] [c000000002d07840] [c00000000054289c] blkdev_get_by_dev+0x1dc/0x3c0
[ 14.524286][ T1] [c000000002d078a0] [c000000000542e90] blkdev_get_by_path+0x90/0xe0
[ 14.524499][ T1] [c000000002d078f0] [c0000000004d148c] mount_bdev+0x6c/0x2b0
[ 14.524694][ T1] [c000000002d07990] [c00000000064a0f8] ext4_mount+0x28/0x40
[ 14.524887][ T1] [c000000002d079b0] [c0000000005315dc] legacy_get_tree+0x4c/0xb0
[ 14.525100][ T1] [c000000002d079e0] [c0000000004cf5e8] vfs_get_tree+0x48/0x100
[ 14.525298][ T1] [c000000002d07a50] [c00000000050fbe8] path_mount+0x2d8/0xd30
[ 14.525489][ T1] [c000000002d07ae0] [c000000001587874] init_mount+0x7c/0xcc
[ 14.525694][ T1] [c000000002d07b50] [c000000001551bd8] mount_block_root+0x230/0x454
[ 14.525894][ T1] [c000000002d07c50] [c000000001552058] prepare_namespace+0x1b0/0x204
[ 14.526106][ T1] [c000000002d07cc0] [c000000001551714] kernel_init_freeable+0x428/0x484
[ 14.526335][ T1] [c000000002d07da0] [c000000000012d1c] kernel_init+0x3c/0x180
[ 14.526529][ T1] [c000000002d07e10] [c00000000000cfd4] ret_from_kernel_thread+0x5c/0x64
[ 14.567502][ T1] EXT4-fs (mtdblock0): mounted filesystem without journal. Opts: (null). Quota mode: disabled.
[ 14.568104][ T1] VFS: Mounted root (ext4 filesystem) readonly on device 31:0.
[ 14.572575][ T1] devtmpfs: mounted
[ 14.632605][ T1] Freeing unused kernel image (initmem) memory: 1984K
[ 14.632873][ T1] Kernel memory protection not selected by kernel config.
[ 14.633341][ T1] Run /sbin/init as init process
[ 14.633475][ T1] with arguments:
[ 14.633586][ T1] /sbin/init
[ 14.633692][ T1] with environment:
[ 14.633814][ T1] HOME=/
[ 14.633912][ T1] TERM=linux
[ 14.651001][ C0] random: fast init done
[ 15.671461][ T152] mount (152) used greatest stack depth: 10048 bytes left
mount: mounting devtmpfs on /dev failed: Device or resource busy
[ 15.768631][ T48] (null): opal_flash_async_op(op=0) failed (rc -1)
[ 15.773159][ T48] blk_update_request: I/O error, dev mtdblock0, sector 2 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 15.773787][ T48] blk_update_request: I/O error, dev mtdblock0, sector 2 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 15.774151][ T48] Buffer I/O error on dev mtdblock0, logical block 1, lost sync page write
[ 15.775037][ T154] EXT4-fs (mtdblock0): I/O error while writing superblock
mount: mounting /dev/root on / failed: Input/output error
Starting syslogd: OK
Starting klogd: OK
Running sysctl: [ 16.730207][ T179] logger (179) used greatest stack depth: 9920 bytes left
OK
Saving random seed: SKIP (read-only file system detected)
Starting network: [ 17.450126][ T195] 8139cp 0000:01:00.0 eth0: link up, 100Mbps, full-duplex, lpa 0x05E1
udhcpc: started, v1.33.0
udhcpc: sending discover
udhcpc: sending select for 10.0.2.15
udhcpc: lease of 10.0.2.15 obtained, lease time 86400
deleting routers
adding dns 10.0.2.3
OK
Found console hvc0
Linux version 5.14.0-rc6-next-20210817 (groeck@server.roeck-us.net) (powerpc64-linux-gcc.br_real (Buildroot 2019.02-git-00353-g4f20f23) 7.4.0, GNU ld (GNU Binutils) 2.31.1) #1 SMP Tue Aug 17 19:13:07 PDT 2021
[ 18.515763][ T227] telnet (227) used greatest stack depth: 8528 bytes left
Network interface test passed
Boot successful.
Rebooting
[ 34.724800][ T232] reboot: Restarting system
[ 48.142228983,5] OPAL: Reboot request...
[ 48.142294919,2] NVRAM: Failed to load
------------
WARNING: multiple messages have this Message-ID (diff)
From: Guenter Roeck <linux@roeck-us.net>
To: Christoph Hellwig <hch@lst.de>
Cc: Jens Axboe <axboe@kernel.dk>,
linux-block@vger.kernel.org, dm-devel@redhat.com,
Mike Snitzer <snitzer@redhat.com>
Subject: Re: [dm-devel] [PATCH 4/8] block: support delayed holder registration
Date: Tue, 17 Aug 2021 19:51:53 -0700 [thread overview]
Message-ID: <20210818025153.GA1053733@roeck-us.net> (raw)
In-Reply-To: <20210816072158.GA27147@lst.de>
On Mon, Aug 16, 2021 at 09:21:58AM +0200, Christoph Hellwig wrote:
> On Sun, Aug 15, 2021 at 07:27:37AM -0700, Guenter Roeck wrote:
> > [ 14.467748][ T1] Possible unsafe locking scenario:
> > [ 14.467748][ T1]
> > [ 14.467928][ T1] CPU0 CPU1
> > [ 14.468058][ T1] ---- ----
> > [ 14.468187][ T1] lock(&disk->open_mutex);
> > [ 14.468317][ T1] lock(mtd_table_mutex);
> > [ 14.468493][ T1] lock(&disk->open_mutex);
> > [ 14.468671][ T1] lock(mtd_table_mutex);
>
> Oh, that ooks like a really old one, fixed by
> b7abb0516822 ("mtd: fix lock hierarchy in deregister_mtd_blktrans")
> in linux-next.
I tested again with next-20210817. The problem is still there, and
reverting commit d62633873590 ("block: support delayed holder
registration") still fixes it. A complete boot log is attached
for reference.
Guenter
---
Build reference: next-20210817
qemu log:
[ 0.010915815,5] OPAL v6.4 starting...
[ 0.011392739,7] initial console log level: memory 7, driver 5
[ 0.011422553,6] CPU: P9 generation processor (max 4 threads/core)
[ 0.011437437,7] CPU: Boot CPU PIR is 0x0000 PVR is 0x004e1200
[ 0.011524734,7] OPAL table: 0x30101830 .. 0x30101da0, branch table: 0x30002000
[ 0.011667083,7] Assigning physical memory map table for nimbus
[ 0.011914730,7] FDT: Parsing fdt @0x1000000
[ 0.013589817,5] CHIP: Detected Qemu simulator
[ 0.013713155,6] CHIP: Initialised chip 0 from xscom@603fc00000000
[ 0.013992710,6] P9 DD2.00 detected
[ 0.014006187,5] CHIP: Chip ID 0000 type: P9N DD2.00
[ 0.014012448,7] XSCOM: Base address: 0x603fc00000000
[ 0.014031889,7] XSTOP: ibm,sw-checkstop-fir prop not found
[ 0.014094328,6] MFSI 0:0: Initialized
[ 0.014102372,6] MFSI 0:2: Initialized
[ 0.014109468,6] MFSI 0:1: Initialized
[ 0.014477509,6] LPC: LPC[000]: Initialized
[ 0.014483986,7] LPC: access via MMIO @0x6030000000000
[ 0.014513616,7] LPC: Default bus on chip 0x0
[ 0.014579301,7] CPU: New max PIR set to 0x3
[ 0.014944450,7] MEM: parsing reserved memory from reserved-names/-ranges properties
[ 0.015013478,7] CPU: decrementer bits 56
[ 0.015059057,6] CPU: CPU from DT PIR=0x0000 Server#=0x0 State=3
[ 0.015116735,6] CPU: 1 secondary threads
[ 0.016079682,5] PLAT: Using SuperIO UART
[ 0.016285800,7] UART: Using LPC IRQ 4
[ 0.017744314,5] PLAT: Detected QEMU POWER9 platform
[ 0.017803645,5] PLAT: Detected BMC platform ast2500:openbmc
[ 0.033090750,5] CPU: All 1 processors called in...
[ 0.033389379,3] SBE: Master chip ID not found.
[ 0.033807105,7] LPC: Routing irq 10, policy: 0 (r=1)
[ 0.033866006,7] LPC: SerIRQ 10 using route 0 targetted at OPAL
[ 0.055456502,5] HIOMAP: Negotiated hiomap protocol v2
[ 0.055559088,5] HIOMAP: Block size is 4KiB
[ 0.055635761,5] HIOMAP: BMC suggested flash timeout of 0s
[ 0.055732832,5] HIOMAP: Flash size is 32MiB
[ 0.055809489,5] HIOMAP: Erase granule size is 4KiB
[ 0.072601777,4] FLASH: No ffs info; using raw device only
[ 0.078031760,3] FLASH: Can't open ffs handle
[ 0.083329630,3] FLASH: Can't open ffs handle
[ 0.088614080,3] FLASH: Can't open ffs handle
[ 0.093896205,3] FLASH: Can't open ffs handle
[ 0.099174034,3] FLASH: Can't open ffs handle
[ 0.104454746,3] FLASH: Can't open ffs handle
[ 0.115977110,2] NVRAM: Failed to load
[ 0.116068253,2] NVRAM: Failed to load
[ 0.116173219,5] STB: secure boot not supported
[ 0.116283085,5] STB: trusted boot not supported
[ 0.116683004,4] FLASH: Can't load resource id:4. No system flash found
[ 0.117069713,4] FLASH: Can't load resource id:3. No system flash found
[ 0.117269585,2] NVRAM: Failed to load
[ 0.117490209,7] LPC: Routing irq 4, policy: 0 (r=1)
[ 0.117514888,7] LPC: SerIRQ 4 using route 1 targetted at OPAL
[ 0.117933346,3] SLW: HOMER base not set 0
[ 0.118081064,5] Unable to log error
[ 0.118227237,2] NVRAM: Failed to load
[ 0.118442741,3] OCC: No HOMER detected, assuming no pstates
[ 0.118501222,5] Unable to log error
[ 0.118555649,2] NVRAM: Failed to load
[ 0.118604663,2] NVRAM: Failed to load
[ 0.118720628,4] FLASH: Can't load resource id:2. No system flash found
[ 0.118912385,4] FLASH: Can't load resource id:0. No system flash found
[ 0.118983574,4] FLASH: Can't load resource id:1. No system flash found
[ 0.119116640,3] IMC: IMC Catalog load failed
[ 0.119364768,2] NVRAM: Failed to load
[ 0.119406236,2] NVRAM: Failed to load
[ 0.119444636,2] NVRAM: Failed to load
[ 0.119482315,2] NVRAM: Failed to load
[ 0.131102078,3] CAPP: Error loading ucode lid. index=200d1
[ 0.150206406,2] NVRAM: Failed to load
[ 0.160574726,5] PCI: Resetting PHBs and training links...
[ 6.170966934,5] PCI: Probing slots...
[ 6.175681253,5] PCI Summary:
[ 6.176039126,5] PHB#0000:00:00.0 [ROOT] 1014 04c1 R:00 C:060400 B:01..01
[ 6.176342301,5] PHB#0000:01:00.0 [PCID] 10ec 8139 R:20 C:020000 ( ethernet)
[ 6.176532516,5] PHB#0001:00:00.0 [ROOT] 1014 04c1 R:00 C:060400 B:00..00
[ 6.176658081,5] PHB#0002:00:00.0 [ROOT] 1014 04c1 R:00 C:060400 B:00..00
[ 6.176779913,5] PHB#0003:00:00.0 [ROOT] 1014 04c1 R:00 C:060400 B:00..00
[ 6.176904577,5] PHB#0004:00:00.0 [ROOT] 1014 04c1 R:00 C:060400 B:00..00
[ 6.177035788,5] PHB#0005:00:00.0 [ROOT] 1014 04c1 R:00 C:060400 B:00..00
[ 6.177260815,4] FLASH: Failed to load VERSION data
[ 6.312317126,5] INIT: Waiting for kernel...
[ 6.312368972,5] INIT: platform wait for kernel load failed
[ 6.312433234,5] INIT: Assuming kernel at 0x20000000
[ 6.312515708,5] INIT: 64-bit LE kernel discovered
[ 6.312673483,3] OCC: Unassigned OCC Common Area. No sensors found
[ 6.312827720,2] NVRAM: Failed to load
[ 6.370807692,5] INIT: Starting kernel at 0x20010000, fdt at 0x306c9818 24120 bytes
zImage starting: loaded at 0x0000000020010000 (sp: 0x00000000209e7ed8)
Allocating 0x2647d20 bytes for kernel...
Decompressing (0x0000000000000000 <- 0x0000000020021000:0x00000000209e6ea9)...
Done! Decompressed 0x1a7ebf4 bytes
Linux/PowerPC load: panic=-1 slub_debug=FZPUA root=/dev/mtdblock0 console=tty console=hvc0
Finalizing device tree... flat tree at 0x209e8ca0
[ 0.000000][ T0] dt-cpu-ftrs: setup for ISA 3000
[ 0.000000][ T0] dt-cpu-ftrs: final cpu/mmu features = 0x0003c06b8f5fb187 0x3c007041
[ 0.000000][ T0] Activating Kernel Userspace Execution Prevention
[ 0.000000][ T0] Activating Kernel Userspace Access Prevention
[ 0.000000][ T0] radix-mmu: Mapped 0x0000000000000000-0x0000000001740000 with 64.0 KiB pages (exec)
[ 0.000000][ T0] radix-mmu: Mapped 0x0000000001740000-0x0000000080000000 with 64.0 KiB pages
[ 0.000000][ T0] radix-mmu: Initializing Radix MMU
[ 0.000000][ T0] Linux version 5.14.0-rc6-next-20210817 (groeck@server.roeck-us.net) (powerpc64-linux-gcc.br_real (Buildroot 2019.02-git-00353-g4f20f23) 7.4.0, GNU ld (GNU Binutils) 2.31.1) #1 SMP Tue Aug 17 19:13:07 PDT 2021
[ 0.000000][ T0] Using PowerNV machine description
[ 0.000000][ T0] printk: bootconsole [udbg0] enabled
[ 0.000000][ T0] CPU maps initialized for 1 thread per core
[ 0.000000][ T0] -----------------------------------------------------
[ 0.000000][ T0] phys_mem_size = 0x80000000
[ 0.000000][ T0] dcache_bsize = 0x80
[ 0.000000][ T0] icache_bsize = 0x80
[ 0.000000][ T0] cpu_features = 0x0003c06b8f4fb187
[ 0.000000][ T0] possible = 0x000ffbfbcf5fb187
[ 0.000000][ T0] always = 0x0000000380008181
[ 0.000000][ T0] cpu_user_features = 0xdc0065c2 0xaef00000
[ 0.000000][ T0] mmu_features = 0x3c007641
[ 0.000000][ T0] firmware_features = 0x0000000010000000
[ 0.000000][ T0] vmalloc start = 0xc008000000000000
[ 0.000000][ T0] IO start = 0xc00a000000000000
[ 0.000000][ T0] vmemmap start = 0xc00c000000000000
[ 0.000000][ T0] -----------------------------------------------------
[ 0.000000][ T0] kvm_cma_reserve: reserving 102 MiB for global area
[ 0.000000][ T0] cma: Reserved 112 MiB at 0x0000000073000000
[ 0.000000][ T0] numa: NODE_DATA [mem 0x7bf7ae00-0x7bf7ffff]
[ 0.000000][ T0] rfi-flush: fallback displacement flush available
[ 0.000000][ T0] count-cache-flush: flush disabled.
[ 0.000000][ T0] link-stack-flush: flush disabled.
[ 0.000000][ T0] stf-barrier: eieio barrier available
[ 0.000000][ T0] barrier-nospec: using ORI speculation barrier
[ 0.000000][ T0] Zone ranges:
[ 0.000000][ T0] Normal [mem 0x0000000000000000-0x000000007fffffff]
[ 0.000000][ T0] Movable zone start for each node
[ 0.000000][ T0] Early memory node ranges
[ 0.000000][ T0] node 0: [mem 0x0000000000000000-0x000000007fffffff]
[ 0.000000][ T0] Initmem setup node 0 [mem 0x0000000000000000-0x000000007fffffff]
[ 0.000000][ T0] percpu: Embedded 11 pages/cpu s645968 r0 d74928 u720896
[ 0.000000][ T0] Built 1 zonelists, mobility grouping on. Total pages: 32736
[ 0.000000][ T0] Policy zone: Normal
[ 0.000000][ T0] Kernel command line: panic=-1 slub_debug=FZPUA root=/dev/mtdblock0 console=tty console=hvc0
[ 0.000000][ T0] Dentry cache hash table entries: 262144 (order: 5, 2097152 bytes, linear)
[ 0.000000][ T0] Inode-cache hash table entries: 131072 (order: 4, 1048576 bytes, linear)
[ 0.000000][ T0] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000][ T0] Memory: 0K/2097152K available (17152K kernel code, 3328K rwdata, 4608K rodata, 1984K init, 12063K bss, 173440K reserved, 114688K cma-reserved)
[ 0.000000][ T0] **********************************************************
[ 0.000000][ T0] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE **
[ 0.000000][ T0] ** **
[ 0.000000][ T0] ** This system shows unhashed kernel memory addresses **
[ 0.000000][ T0] ** via the console, logs, and other interfaces. This **
[ 0.000000][ T0] ** might reduce the security of your system. **
[ 0.000000][ T0] ** **
[ 0.000000][ T0] ** If you see this message and you are not debugging **
[ 0.000000][ T0] ** the kernel, report this immediately to your system **
[ 0.000000][ T0] ** administrator! **
[ 0.000000][ T0] ** **
[ 0.000000][ T0] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE **
[ 0.000000][ T0] **********************************************************
[ 0.000000][ T0] SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000][ T0] ftrace: allocating 36425 entries in 14 pages
[ 0.000000][ T0] ftrace: allocated 14 pages with 3 groups
[ 0.000000][ T0] trace event string verifier disabled
[ 0.000000][ T0] Running RCU self tests
[ 0.000000][ T0] rcu: Hierarchical RCU implementation.
[ 0.000000][ T0] rcu: RCU event tracing is enabled.
[ 0.000000][ T0] rcu: RCU lockdep checking is enabled.
[ 0.000000][ T0] rcu: RCU restricting CPUs from NR_CPUS=2048 to nr_cpu_ids=1.
[ 0.000000][ T0] rcu: RCU debug extended QS entry/exit.
[ 0.000000][ T0] Rude variant of Tasks RCU enabled.
[ 0.000000][ T0] Tracing variant of Tasks RCU enabled.
[ 0.000000][ T0] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[ 0.000000][ T0] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
[ 0.000000][ T0] NR_IRQS: 512, nr_irqs: 512, preallocated irqs: 16
[ 0.000000][ T0] xive: Interrupt handling initialized with native backend
[ 0.000000][ T0] xive: Using priority 7 for all interrupts
[ 0.000000][ T0] xive: Using 64kB queues
[ 0.000000][ T0] random: get_random_u64 called from start_kernel+0x680/0x8e8 with crng_init=0
[ 0.000090][ T0] time_init: 56 bit decrementer (max: 7fffffffffffff)
[ 0.001865][ T0] clocksource: timebase: mask: 0xffffffffffffffff max_cycles: 0x761537d007, max_idle_ns: 440795202126 ns
[ 0.004659][ T0] clocksource: timebase mult[1f40000] shift[24] registered
[ 0.012714][ T0] Console: colour dummy device 80x25
[ 0.026090][ T0] printk: console [tty0] enabled
[ 0.026571][ T0] printk: console [hvc0] enabled
[ 0.026571][ T0] printk: console [hvc0] enabled
[ 0.027221][ T0] printk: bootconsole [udbg0] disabled
[ 0.027221][ T0] printk: bootconsole [udbg0] disabled
[ 0.028092][ T0] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[ 0.028424][ T0] ... MAX_LOCKDEP_SUBCLASSES: 8
[ 0.028613][ T0] ... MAX_LOCK_DEPTH: 48
[ 0.028800][ T0] ... MAX_LOCKDEP_KEYS: 8192
[ 0.028989][ T0] ... CLASSHASH_SIZE: 4096
[ 0.029185][ T0] ... MAX_LOCKDEP_ENTRIES: 32768
[ 0.029381][ T0] ... MAX_LOCKDEP_CHAINS: 65536
[ 0.029574][ T0] ... CHAINHASH_SIZE: 32768
[ 0.029768][ T0] memory used by lock dependency info: 6365 kB
[ 0.029997][ T0] memory used for stack traces: 4224 kB
[ 0.030204][ T0] per task-struct memory footprint: 1920 bytes
[ 0.030467][ T0] ------------------------
[ 0.030645][ T0] | Locking API testsuite:
[ 0.030819][ T0] ----------------------------------------------------------------------------
[ 0.035275][ T0] | spin |wlock |rlock |mutex | wsem | rsem |
[ 0.035616][ T0] --------------------------------------------------------------------------
[ 0.036183][ T0] A-A deadlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.049825][ T0] A-B-B-A deadlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.064240][ T0] A-B-B-C-C-A deadlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.086497][ T0] A-B-C-A-B-C deadlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.103109][ T0] A-B-B-C-C-D-D-A deadlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.122436][ T0] A-B-C-D-B-D-D-A deadlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.141864][ T0] A-B-C-D-B-C-D-A deadlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.161418][ T0] double unlock: ok | ok | ok | ok | ok | ok | ok |
[ 0.173155][ T0] initialize held: ok | ok | ok | ok | ok | ok | ok |
[ 0.183712][ T0] --------------------------------------------------------------------------
[ 0.184041][ T0] recursive read-lock: | ok | | ok |
[ 0.187988][ T0] recursive read-lock #2: | ok | | ok |
[ 0.191588][ T0] mixed read-write-lock: | ok | | ok |
[ 0.195301][ T0] mixed write-read-lock: | ok | | ok |
[ 0.198850][ T0] mixed read-lock/lock-write ABBA: | ok | | ok |
[ 0.202797][ T0] mixed read-lock/lock-read ABBA: | ok | | ok |
[ 0.207250][ T0] mixed write-lock/lock-write ABBA: | ok | | ok |
[ 0.211513][ T0] chain cached mixed R-L/L-W ABBA: | ok |
[ 0.213847][ T0] rlock W1R2/W2R3/W3R1/123: | ok |
[ 0.216917][ T0] rlock W1R2/W2R3/W3R1/132: | ok |
[ 0.219589][ T0] rlock W1R2/W2R3/W3R1/213: | ok |
[ 0.222209][ T0] rlock W1R2/W2R3/W3R1/231: | ok |
[ 0.224828][ T0] rlock W1R2/W2R3/W3R1/312: | ok |
[ 0.227578][ T0] rlock W1R2/W2R3/W3R1/321: | ok |
[ 0.230260][ T0] rlock W1W2/R2R3/W3R1/123: | ok |
[ 0.232933][ T0] rlock W1W2/R2R3/W3R1/132: | ok |
[ 0.235588][ T0] rlock W1W2/R2R3/W3R1/213: | ok |
[ 0.238346][ T0] rlock W1W2/R2R3/W3R1/231: | ok |
[ 0.241010][ T0] rlock W1W2/R2R3/W3R1/312: | ok |
[ 0.243660][ T0] rlock W1W2/R2R3/W3R1/321: | ok |
[ 0.246311][ T0] rlock W1W2/R2R3/R3W1/123: | ok |
[ 0.249064][ T0] rlock W1W2/R2R3/R3W1/132: | ok |
[ 0.251699][ T0] rlock W1W2/R2R3/R3W1/213: | ok |
[ 0.254318][ T0] rlock W1W2/R2R3/R3W1/231: | ok |
[ 0.256931][ T0] rlock W1W2/R2R3/R3W1/312: | ok |
[ 0.259677][ T0] rlock W1W2/R2R3/R3W1/321: | ok |
[ 0.262346][ T0] rlock W1R2/R2R3/W3W1/123: | ok |
[ 0.264978][ T0] rlock W1R2/R2R3/W3W1/132: | ok |
[ 0.267613][ T0] rlock W1R2/R2R3/W3W1/213: | ok |
[ 0.270324][ T0] rlock W1R2/R2R3/W3W1/231: | ok |
[ 0.272953][ T0] rlock W1R2/R2R3/W3W1/312: | ok |
[ 0.275577][ T0] rlock W1R2/R2R3/W3W1/321: | ok |
[ 0.278228][ T0] --------------------------------------------------------------------------
[ 0.278553][ T0] hard-irqs-on + irq-safe-A/12: ok | ok | ok |
[ 0.283971][ T0] soft-irqs-on + irq-safe-A/12: ok | ok | ok |
[ 0.289507][ T0] hard-irqs-on + irq-safe-A/21: ok | ok | ok |
[ 0.294903][ T0] soft-irqs-on + irq-safe-A/21: ok | ok | ok |
[ 0.300069][ T0] sirq-safe-A => hirqs-on/12: ok | ok | ok |
[ 0.305415][ T0] sirq-safe-A => hirqs-on/21: ok | ok | ok |
[ 0.310652][ T0] hard-safe-A + irqs-on/12: ok | ok | ok |
[ 0.316082][ T0] soft-safe-A + irqs-on/12: ok | ok | ok |
[ 0.321303][ T0] hard-safe-A + irqs-on/21: ok | ok | ok |
[ 0.326734][ T0] soft-safe-A + irqs-on/21: ok | ok | ok |
[ 0.331984][ T0] hard-safe-A + unsafe-B #1/123: ok | ok | ok |
[ 0.338422][ T0] soft-safe-A + unsafe-B #1/123: ok | ok | ok |
[ 0.345541][ T0] hard-safe-A + unsafe-B #1/132: ok | ok | ok |
[ 0.356619][ T0] soft-safe-A + unsafe-B #1/132: ok | ok | ok |
[ 0.362796][ T0] hard-safe-A + unsafe-B #1/213: ok | ok | ok |
[ 0.369123][ T0] soft-safe-A + unsafe-B #1/213: ok | ok | ok |
[ 0.375299][ T0] hard-safe-A + unsafe-B #1/231: ok | ok | ok |
[ 0.381629][ T0] soft-safe-A + unsafe-B #1/231: ok | ok | ok |
[ 0.387777][ T0] hard-safe-A + unsafe-B #1/312: ok | ok | ok |
[ 0.393484][ T0] soft-safe-A + unsafe-B #1/312: ok | ok | ok |
[ 0.399117][ T0] hard-safe-A + unsafe-B #1/321: ok | ok | ok |
[ 0.405361][ T0] soft-safe-A + unsafe-B #1/321: ok | ok | ok |
[ 0.411995][ T0] hard-safe-A + unsafe-B #2/123: ok | ok | ok |
[ 0.418450][ T0] soft-safe-A + unsafe-B #2/123: ok | ok | ok |
[ 0.424913][ T0] hard-safe-A + unsafe-B #2/132: ok | ok | ok |
[ 0.431446][ T0] soft-safe-A + unsafe-B #2/132: ok | ok | ok |
[ 0.437784][ T0] hard-safe-A + unsafe-B #2/213: ok | ok | ok |
[ 0.447485][ T0] soft-safe-A + unsafe-B #2/213: ok | ok | ok |
[ 0.455678][ T0] hard-safe-A + unsafe-B #2/231: ok | ok | ok |
[ 0.462876][ T0] soft-safe-A + unsafe-B #2/231: ok | ok | ok |
[ 0.469234][ T0] hard-safe-A + unsafe-B #2/312: ok | ok | ok |
[ 0.475729][ T0] soft-safe-A + unsafe-B #2/312: ok | ok | ok |
[ 0.481936][ T0] hard-safe-A + unsafe-B #2/321: ok | ok | ok |
[ 0.488372][ T0] soft-safe-A + unsafe-B #2/321: ok | ok | ok |
[ 0.494631][ T0] hard-irq lock-inversion/123: ok | ok | ok |
[ 0.501236][ T0] soft-irq lock-inversion/123: ok | ok | ok |
[ 0.507923][ T0] hard-irq lock-inversion/132: ok | ok | ok |
[ 0.514774][ T0] soft-irq lock-inversion/132: ok | ok | ok |
[ 0.521709][ T0] hard-irq lock-inversion/213: ok | ok | ok |
[ 0.528010][ T0] soft-irq lock-inversion/213: ok | ok | ok |
[ 0.535301][ T0] hard-irq lock-inversion/231: ok | ok | ok |
[ 0.541693][ T0] soft-irq lock-inversion/231: ok | ok | ok |
[ 0.548029][ T0] hard-irq lock-inversion/312: ok | ok | ok |
[ 0.554493][ T0] soft-irq lock-inversion/312: ok | ok | ok |
[ 0.561569][ T0] hard-irq lock-inversion/321: ok | ok | ok |
[ 0.568094][ T0] soft-irq lock-inversion/321: ok | ok | ok |
[ 0.574559][ T0] hard-irq read-recursion/123: | ok | ok |
[ 0.578977][ T0] soft-irq read-recursion/123: | ok | ok |
[ 0.583251][ T0] hard-irq read-recursion/132: | ok | ok |
[ 0.587936][ T0] soft-irq read-recursion/132: | ok | ok |
[ 0.592573][ T0] hard-irq read-recursion/213: | ok | ok |
[ 0.596938][ T0] soft-irq read-recursion/213: | ok | ok |
[ 0.600913][ T0] hard-irq read-recursion/231: | ok | ok |
[ 0.604965][ T0] soft-irq read-recursion/231: | ok | ok |
[ 0.609102][ T0] hard-irq read-recursion/312: | ok | ok |
[ 0.613560][ T0] soft-irq read-recursion/312: | ok | ok |
[ 0.618017][ T0] hard-irq read-recursion/321: | ok | ok |
[ 0.622508][ T0] soft-irq read-recursion/321: | ok | ok |
[ 0.626868][ T0] hard-irq read-recursion #2/123: | ok | ok |
[ 0.631391][ T0] soft-irq read-recursion #2/123: | ok | ok |
[ 0.635753][ T0] hard-irq read-recursion #2/132: | ok | ok |
[ 0.640608][ T0] soft-irq read-recursion #2/132: | ok | ok |
[ 0.644958][ T0] hard-irq read-recursion #2/213: | ok | ok |
[ 0.649470][ T0] soft-irq read-recursion #2/213: | ok | ok |
[ 0.653954][ T0] hard-irq read-recursion #2/231: | ok | ok |
[ 0.658352][ T0] soft-irq read-recursion #2/231: | ok | ok |
[ 0.663008][ T0] hard-irq read-recursion #2/312: | ok | ok |
[ 0.667407][ T0] soft-irq read-recursion #2/312: | ok | ok |
[ 0.671847][ T0] hard-irq read-recursion #2/321: | ok | ok |
[ 0.676744][ T0] soft-irq read-recursion #2/321: | ok | ok |
[ 0.681763][ T0] hard-irq read-recursion #3/123: | ok | ok |
[ 0.686669][ T0] soft-irq read-recursion #3/123: | ok | ok |
[ 0.691021][ T0] hard-irq read-recursion #3/132: | ok | ok |
[ 0.695718][ T0] soft-irq read-recursion #3/132: | ok | ok |
[ 0.700074][ T0] hard-irq read-recursion #3/213: | ok | ok |
[ 0.704752][ T0] soft-irq read-recursion #3/213: | ok | ok |
[ 0.713237][ T0] hard-irq read-recursion #3/231: | ok | ok |
[ 0.718254][ T0] soft-irq read-recursion #3/231: | ok | ok |
[ 0.722683][ T0] hard-irq read-recursion #3/312: | ok | ok |
[ 0.727007][ T0] soft-irq read-recursion #3/312: | ok | ok |
[ 0.731373][ T0] hard-irq read-recursion #3/321: | ok | ok |
[ 0.735706][ T0] soft-irq read-recursion #3/321: | ok | ok |
[ 0.739976][ T0] --------------------------------------------------------------------------
[ 0.740294][ T0] | Wound/wait tests |
[ 0.740456][ T0] ---------------------
[ 0.740616][ T0] ww api failures: ok | ok | ok |
[ 0.747943][ T0] ww contexts mixing: ok | ok |
[ 0.751839][ T0] finishing ww context: ok | ok | ok | ok |
[ 0.759807][ T0] locking mismatches: ok | ok | ok |
[ 0.765794][ T0] EDEADLK handling: ok | ok | ok | ok | ok | ok | ok | ok | ok | ok |
[ 0.786926][ T0] spinlock nest unlocked: ok |
[ 0.788813][ T0] spinlock nest test: ok |
[ 0.791472][ T0] -----------------------------------------------------
[ 0.791735][ T0] |block | try |context|
[ 0.792000][ T0] -----------------------------------------------------
[ 0.792252][ T0] context: ok | ok | ok |
[ 0.798615][ T0] try: ok | ok | ok |
[ 0.804046][ T0] block: ok | ok | ok |
[ 0.810770][ T0] spinlock: ok | ok | ok |
[ 0.821347][ T0] --------------------------------------------------------------------------
[ 0.821673][ T0] | queued read lock tests |
[ 0.821856][ T0] ---------------------------
[ 0.822041][ T0] hardirq read-lock/lock-read: ok |
[ 0.824356][ T0] hardirq lock-read/read-lock: ok |
[ 0.826567][ T0] hardirq inversion: ok |
[ 0.828774][ T0] --------------------
[ 0.828939][ T0] | fs_reclaim tests |
[ 0.829097][ T0] --------------------
[ 0.829252][ T0] correct nesting: ok |
[ 0.830836][ T0] wrong nesting: ok |
[ 0.832385][ T0] protected nesting: ok |
[ 0.833899][ T0] --------------------------------------------------------------------------
[ 0.834216][ T0] | local_lock tests |
[ 0.834373][ T0] ---------------------
[ 0.834531][ T0] local_lock inversion 2: ok |
[ 0.836820][ T0] local_lock inversion 3A: ok |
[ 0.839520][ T0] local_lock inversion 3B: ok |
[ 0.842690][ T0] hardirq_unsafe_softirq_safe: ok |
[ 0.846193][ T0] -------------------------------------------------------
[ 0.846452][ T0] Good, all 358 testcases passed! |
[ 0.846645][ T0] ---------------------------------
[ 0.848247][ T0] pid_max: default: 32768 minimum: 301
[ 0.850462][ T0] Mount-cache hash table entries: 8192 (order: 0, 65536 bytes, linear)
[ 0.850823][ T0] Mountpoint-cache hash table entries: 8192 (order: 0, 65536 bytes, linear)
[ 0.902548][ T1] Running RCU-tasks wait API self tests
[ 0.909691][ T1] POWER9 performance monitor hardware support registered
[ 0.911844][ T1] rcu: Hierarchical SRCU implementation.
[ 0.929941][ T10] Callback from call_rcu_tasks_trace() invoked.
[ 0.932539][ T1] smp: Bringing up secondary CPUs ...
[ 0.932888][ T1] smp: Brought up 1 node, 1 CPU
[ 0.933249][ T1] numa: Node 0 CPUs: 0
[ 0.943941][ T16] node 0 deferred pages initialised in 0ms
[ 0.948649][ T16] pgdatinit0 (16) used greatest stack depth: 12528 bytes left
[ 0.960416][ T1] devtmpfs: initialized
[ 1.045777][ T9] Callback from call_rcu_tasks_rude() invoked.
[ 1.051318][ T1] Initializing IODA2 PHB (/pciex@600c3c0000000)
[ 1.052702][ T1] PCI host bridge /pciex@600c3c0000000 (primary) ranges:
[ 1.053465][ T1] MEM 0x000600c000000000..0x000600c07ffeffff -> 0x0000000080000000
[ 1.054400][ T1] MEM 0x0006000000000000..0x0006003fffffffff -> 0x0006000000000000 (M64 #1..31)
[ 1.054813][ T1] Using M64 #31 as default window
[ 1.056081][ T1] 512 (511) PE's M32: 0x80000000 [segment=0x400000]
[ 1.056408][ T1] M64: 0x4000000000 [segment=0x20000000]
[ 1.056858][ T1] Allocated bitmap for 4088 MSIs (base IRQ 0xfe000)
[ 1.061975][ T1] Initializing IODA2 PHB (/pciex@600c3c0100000)
[ 1.062583][ T1] PCI host bridge /pciex@600c3c0100000 ranges:
[ 1.062929][ T1] MEM 0x000600c080000000..0x000600c0fffeffff -> 0x0000000080000000
[ 1.063511][ T1] MEM 0x0006004000000000..0x0006007fffffffff -> 0x0006004000000000 (M64 #1..15)
[ 1.063907][ T1] Using M64 #15 as default window
[ 1.064324][ T1] 256 (255) PE's M32: 0x80000000 [segment=0x800000]
[ 1.064617][ T1] M64: 0x4000000000 [segment=0x40000000]
[ 1.064944][ T1] Allocated bitmap for 2040 MSIs (base IRQ 0xfd800)
[ 1.066901][ T1] Initializing IODA2 PHB (/pciex@600c3c0200000)
[ 1.067465][ T1] PCI host bridge /pciex@600c3c0200000 ranges:
[ 1.067794][ T1] MEM 0x000600c100000000..0x000600c17ffeffff -> 0x0000000080000000
[ 1.068359][ T1] MEM 0x0006008000000000..0x000600bfffffffff -> 0x0006008000000000 (M64 #1..15)
[ 1.068745][ T1] Using M64 #15 as default window
[ 1.069417][ T1] 256 (255) PE's M32: 0x80000000 [segment=0x800000]
[ 1.069708][ T1] M64: 0x4000000000 [segment=0x40000000]
[ 1.070032][ T1] Allocated bitmap for 2040 MSIs (base IRQ 0xfd000)
[ 1.072066][ T1] Initializing IODA2 PHB (/pciex@600c3c0300000)
[ 1.072637][ T1] PCI host bridge /pciex@600c3c0300000 ranges:
[ 1.072969][ T1] MEM 0x000600c180000000..0x000600c1fffeffff -> 0x0000000080000000
[ 1.073537][ T1] MEM 0x0006020000000000..0x0006023fffffffff -> 0x0006020000000000 (M64 #1..31)
[ 1.073922][ T1] Using M64 #31 as default window
[ 1.074531][ T1] 512 (511) PE's M32: 0x80000000 [segment=0x400000]
[ 1.074818][ T1] M64: 0x4000000000 [segment=0x20000000]
[ 1.075132][ T1] Allocated bitmap for 4088 MSIs (base IRQ 0xfc000)
[ 1.077220][ T1] Initializing IODA2 PHB (/pciex@600c3c0400000)
[ 1.077782][ T1] PCI host bridge /pciex@600c3c0400000 ranges:
[ 1.078120][ T1] MEM 0x000600c200000000..0x000600c27ffeffff -> 0x0000000080000000
[ 1.078682][ T1] MEM 0x0006024000000000..0x0006027fffffffff -> 0x0006024000000000 (M64 #1..15)
[ 1.079077][ T1] Using M64 #15 as default window
[ 1.079742][ T1] 256 (255) PE's M32: 0x80000000 [segment=0x800000]
[ 1.080035][ T1] M64: 0x4000000000 [segment=0x40000000]
[ 1.080352][ T1] Allocated bitmap for 2040 MSIs (base IRQ 0xfb800)
[ 1.082665][ T1] Initializing IODA2 PHB (/pciex@600c3c0500000)
[ 1.083238][ T1] PCI host bridge /pciex@600c3c0500000 ranges:
[ 1.083563][ T1] MEM 0x000600c280000000..0x000600c2fffeffff -> 0x0000000080000000
[ 1.084123][ T1] MEM 0x0006028000000000..0x000602bfffffffff -> 0x0006028000000000 (M64 #1..15)
[ 1.084504][ T1] Using M64 #15 as default window
[ 1.084916][ T1] 256 (255) PE's M32: 0x80000000 [segment=0x800000]
[ 1.085203][ T1] M64: 0x4000000000 [segment=0x40000000]
[ 1.085519][ T1] Allocated bitmap for 2040 MSIs (base IRQ 0xfb000)
[ 1.088892][ T1] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 1.089557][ T1] futex hash table entries: 256 (order: -1, 32768 bytes, linear)
[ 1.101390][ T1] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[ 1.109073][ T1] audit: initializing netlink subsys (disabled)
[ 1.118056][ T1] cpuidle: using governor menu
[ 1.119320][ T1] Failed to initialize. Disabling HugeTLB
[ 1.119642][ T1] nvram: No room to create lnx,oops-log partition, deleting any obsolete OS partitions...
[ 1.120368][ T1] nvram: Failed to find or create lnx,oops-log partition, err -28
[ 1.120723][ T1] nvram: Failed to initialize oops partition!
[ 1.134049][ T20] audit: type=2000 audit(1629254531.000:1): state=initialized audit_enabled=0 res=1
[ 1.137609][ T1] EEH: PowerNV platform initialized
[ 1.145237][ T1] PCI: Probing PCI hardware
[ 1.149106][ T1] PCI host bridge to bus 0000:00
[ 1.149625][ T1] pci_bus 0000:00: root bus resource [mem 0x600c000000000-0x600c07ffeffff] (bus address [0x80000000-0xfffeffff])
[ 1.150397][ T1] pci_bus 0000:00: root bus resource [mem 0x6000000000000-0x6003fbfffffff 64bit pref]
[ 1.151013][ T1] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 1.151524][ T1] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to ff
[ 1.154823][ T1] pci 0000:00:00.0: [1014:04c1] type 01 class 0x060400
[ 1.167476][ T1] pci 0000:01:00.0: [10ec:8139] type 00 class 0x020000
[ 1.168101][ T1] pci 0000:01:00.0: reg 0x10: [io 0x0000-0x00ff]
[ 1.168442][ T1] pci 0000:01:00.0: reg 0x14: [mem 0x00000000-0x000000ff]
[ 1.168858][ T1] pci 0000:01:00.0: reg 0x30: [mem 0x00000000-0x0003ffff pref]
[ 1.169311][ T1] pci 0000:01:00.0: BAR1 [mem size 0x00000100]: requesting alignment to 0x10000
[ 1.172922][ T1] pci 0000:00:00.0: PCI bridge to [bus 01]
[ 1.174447][ T1] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 01
[ 1.176415][ T1] PCI host bridge to bus 0001:00
[ 1.176674][ T1] pci_bus 0001:00: root bus resource [mem 0x600c080000000-0x600c0fffeffff] (bus address [0x80000000-0xfffeffff])
[ 1.177170][ T1] pci_bus 0001:00: root bus resource [mem 0x6004000000000-0x6007f7fffffff 64bit pref]
[ 1.177597][ T1] pci_bus 0001:00: root bus resource [bus 00-ff]
[ 1.177871][ T1] pci_bus 0001:00: busn_res: [bus 00-ff] end is updated to ff
[ 1.178330][ T1] pci 0001:00:00.0: [1014:04c1] type 01 class 0x060400
[ 1.184174][ T1] pci 0001:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 1.187991][ T1] pci 0001:00:00.0: PCI bridge to [bus 01-ff]
[ 1.188371][ T1] pci_bus 0001:01: busn_res: [bus 01-ff] end is updated to 01
[ 1.189153][ T1] pci_bus 0001:00: busn_res: [bus 00-ff] end is updated to 01
[ 1.190752][ T1] PCI host bridge to bus 0002:00
[ 1.191002][ T1] pci_bus 0002:00: root bus resource [mem 0x600c100000000-0x600c17ffeffff] (bus address [0x80000000-0xfffeffff])
[ 1.191493][ T1] pci_bus 0002:00: root bus resource [mem 0x6008000000000-0x600bf7fffffff 64bit pref]
[ 1.191911][ T1] pci_bus 0002:00: root bus resource [bus 00-ff]
[ 1.192184][ T1] pci_bus 0002:00: busn_res: [bus 00-ff] end is updated to ff
[ 1.192636][ T1] pci 0002:00:00.0: [1014:04c1] type 01 class 0x060400
[ 1.199010][ T1] pci 0002:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 1.202319][ T1] pci 0002:00:00.0: PCI bridge to [bus 01-ff]
[ 1.202673][ T1] pci_bus 0002:01: busn_res: [bus 01-ff] end is updated to 01
[ 1.203269][ T1] pci_bus 0002:00: busn_res: [bus 00-ff] end is updated to 01
[ 1.204899][ T1] PCI host bridge to bus 0003:00
[ 1.205148][ T1] pci_bus 0003:00: root bus resource [mem 0x600c180000000-0x600c1fffeffff] (bus address [0x80000000-0xfffeffff])
[ 1.205642][ T1] pci_bus 0003:00: root bus resource [mem 0x6020000000000-0x6023fbfffffff 64bit pref]
[ 1.206748][ T1] pci_bus 0003:00: root bus resource [bus 00-ff]
[ 1.207045][ T1] pci_bus 0003:00: busn_res: [bus 00-ff] end is updated to ff
[ 1.207505][ T1] pci 0003:00:00.0: [1014:04c1] type 01 class 0x060400
[ 1.213117][ T1] pci 0003:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 1.216451][ T1] pci 0003:00:00.0: PCI bridge to [bus 01-ff]
[ 1.217503][ T1] pci_bus 0003:01: busn_res: [bus 01-ff] end is updated to 01
[ 1.218181][ T1] pci_bus 0003:00: busn_res: [bus 00-ff] end is updated to 01
[ 1.219717][ T1] PCI host bridge to bus 0004:00
[ 1.219968][ T1] pci_bus 0004:00: root bus resource [mem 0x600c200000000-0x600c27ffeffff] (bus address [0x80000000-0xfffeffff])
[ 1.220454][ T1] pci_bus 0004:00: root bus resource [mem 0x6024000000000-0x6027f7fffffff 64bit pref]
[ 1.220863][ T1] pci_bus 0004:00: root bus resource [bus 00-ff]
[ 1.221132][ T1] pci_bus 0004:00: busn_res: [bus 00-ff] end is updated to ff
[ 1.221585][ T1] pci 0004:00:00.0: [1014:04c1] type 01 class 0x060400
[ 1.227067][ T1] pci 0004:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 1.231059][ T1] pci 0004:00:00.0: PCI bridge to [bus 01-ff]
[ 1.231411][ T1] pci_bus 0004:01: busn_res: [bus 01-ff] end is updated to 01
[ 1.231984][ T1] pci_bus 0004:00: busn_res: [bus 00-ff] end is updated to 01
[ 1.233643][ T1] PCI host bridge to bus 0005:00
[ 1.233894][ T1] pci_bus 0005:00: root bus resource [mem 0x600c280000000-0x600c2fffeffff] (bus address [0x80000000-0xfffeffff])
[ 1.234393][ T1] pci_bus 0005:00: root bus resource [mem 0x6028000000000-0x602bf7fffffff 64bit pref]
[ 1.234799][ T1] pci_bus 0005:00: root bus resource [bus 00-ff]
[ 1.235079][ T1] pci_bus 0005:00: busn_res: [bus 00-ff] end is updated to ff
[ 1.235538][ T1] pci 0005:00:00.0: [1014:04c1] type 01 class 0x060400
[ 1.241752][ T1] pci 0005:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 1.245089][ T1] pci 0005:00:00.0: PCI bridge to [bus 01-ff]
[ 1.245444][ T1] pci_bus 0005:01: busn_res: [bus 01-ff] end is updated to 01
[ 1.246021][ T1] pci_bus 0005:00: busn_res: [bus 00-ff] end is updated to 01
[ 1.247644][ T1] pci 0000:00:00.0: bridge window [mem 0x20000000-0x1fffffff 64bit pref] to [bus 01] add_size 20000000 add_align 20000000
[ 1.249777][ T1] pci 0000:00:00.0: BAR 9: assigned [mem 0x6000000000000-0x600001fffffff 64bit pref]
[ 1.250256][ T1] pci 0000:00:00.0: BAR 8: assigned [mem 0x600c000000000-0x600c0003fffff]
[ 1.250664][ T1] pci 0000:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.250986][ T1] pci 0000:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.251724][ T1] pci 0000:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.252029][ T1] pci 0000:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.252488][ T1] pci 0000:01:00.0: BAR 6: assigned [mem 0x600c000000000-0x600c00003ffff pref]
[ 1.252966][ T1] pci 0000:01:00.0: BAR 1: assigned [mem 0x600c000040000-0x600c0000400ff]
[ 1.253406][ T1] pci 0000:01:00.0: BAR 0: no space for [io size 0x0100]
[ 1.253698][ T1] pci 0000:01:00.0: BAR 0: failed to assign [io size 0x0100]
[ 1.254222][ T1] pci 0000:00:00.0: PCI bridge to [bus 01]
[ 1.254868][ T1] pci 0000:00:00.0: bridge window [mem 0x600c000000000-0x600c07fefffff]
[ 1.255351][ T1] pci 0000:00:00.0: bridge window [mem 0x6000000000000-0x6003fbff0ffff 64bit pref]
[ 1.256063][ T1] pci_bus 0000:00: Some PCI device resources are unassigned, try booting with pci=realloc
[ 1.256580][ T1] pci_bus 0000:00: resource 4 [mem 0x600c000000000-0x600c07ffeffff]
[ 1.256922][ T1] pci_bus 0000:00: resource 5 [mem 0x6000000000000-0x6003fbfffffff 64bit pref]
[ 1.257298][ T1] pci_bus 0000:01: resource 1 [mem 0x600c000000000-0x600c07fefffff]
[ 1.257623][ T1] pci_bus 0000:01: resource 2 [mem 0x6000000000000-0x6003fbff0ffff 64bit pref]
[ 1.258108][ T1] pci 0001:00:00.0: bridge window [io 0x1000-0x0fff] to [bus 01] add_size 1000
[ 1.258537][ T1] pci 0001:00:00.0: bridge window [mem 0x40000000-0x3fffffff 64bit pref] to [bus 01] add_size 40000000 add_align 40000000
[ 1.259065][ T1] pci 0001:00:00.0: bridge window [mem 0x00800000-0x007fffff] to [bus 01] add_size 800000 add_align 800000
[ 1.259617][ T1] pci 0001:00:00.0: BAR 9: assigned [mem 0x6004000000000-0x600403fffffff 64bit pref]
[ 1.260009][ T1] pci 0001:00:00.0: BAR 8: assigned [mem 0x600c080000000-0x600c0807fffff]
[ 1.260501][ T1] pci 0001:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.260808][ T1] pci 0001:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.261239][ T1] pci 0001:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.261539][ T1] pci 0001:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.261933][ T1] pci 0001:00:00.0: PCI bridge to [bus 01]
[ 1.262441][ T1] pci 0001:00:00.0: bridge window [mem 0x600c080000000-0x600c0ffefffff]
[ 1.262836][ T1] pci 0001:00:00.0: bridge window [mem 0x6004000000000-0x6007f7ff0ffff 64bit pref]
[ 1.263456][ T1] pci_bus 0001:00: resource 4 [mem 0x600c080000000-0x600c0fffeffff]
[ 1.263827][ T1] pci_bus 0001:00: resource 5 [mem 0x6004000000000-0x6007f7fffffff 64bit pref]
[ 1.264186][ T1] pci_bus 0001:01: resource 1 [mem 0x600c080000000-0x600c0ffefffff]
[ 1.264507][ T1] pci_bus 0001:01: resource 2 [mem 0x6004000000000-0x6007f7ff0ffff 64bit pref]
[ 1.264910][ T1] pci 0002:00:00.0: bridge window [io 0x1000-0x0fff] to [bus 01] add_size 1000
[ 1.265291][ T1] pci 0002:00:00.0: bridge window [mem 0x40000000-0x3fffffff 64bit pref] to [bus 01] add_size 40000000 add_align 40000000
[ 1.265802][ T1] pci 0002:00:00.0: bridge window [mem 0x00800000-0x007fffff] to [bus 01] add_size 800000 add_align 800000
[ 1.266339][ T1] pci 0002:00:00.0: BAR 9: assigned [mem 0x6008000000000-0x600803fffffff 64bit pref]
[ 1.266722][ T1] pci 0002:00:00.0: BAR 8: assigned [mem 0x600c100000000-0x600c1007fffff]
[ 1.267067][ T1] pci 0002:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.267352][ T1] pci 0002:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.267712][ T1] pci 0002:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.268002][ T1] pci 0002:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.268316][ T1] pci 0002:00:00.0: PCI bridge to [bus 01]
[ 1.268818][ T1] pci 0002:00:00.0: bridge window [mem 0x600c100000000-0x600c17fefffff]
[ 1.269207][ T1] pci 0002:00:00.0: bridge window [mem 0x6008000000000-0x600bf7ff0ffff 64bit pref]
[ 1.269834][ T1] pci_bus 0002:00: resource 4 [mem 0x600c100000000-0x600c17ffeffff]
[ 1.270205][ T1] pci_bus 0002:00: resource 5 [mem 0x6008000000000-0x600bf7fffffff 64bit pref]
[ 1.270564][ T1] pci_bus 0002:01: resource 1 [mem 0x600c100000000-0x600c17fefffff]
[ 1.271232][ T1] pci_bus 0002:01: resource 2 [mem 0x6008000000000-0x600bf7ff0ffff 64bit pref]
[ 1.271649][ T1] pci 0003:00:00.0: bridge window [io 0x1000-0x0fff] to [bus 01] add_size 1000
[ 1.272043][ T1] pci 0003:00:00.0: bridge window [mem 0x20000000-0x1fffffff 64bit pref] to [bus 01] add_size 20000000 add_align 20000000
[ 1.272563][ T1] pci 0003:00:00.0: bridge window [mem 0x00400000-0x003fffff] to [bus 01] add_size 400000 add_align 400000
[ 1.273100][ T1] pci 0003:00:00.0: BAR 9: assigned [mem 0x6020000000000-0x602001fffffff 64bit pref]
[ 1.273487][ T1] pci 0003:00:00.0: BAR 8: assigned [mem 0x600c180000000-0x600c1803fffff]
[ 1.273832][ T1] pci 0003:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.274119][ T1] pci 0003:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.274478][ T1] pci 0003:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.274763][ T1] pci 0003:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.275085][ T1] pci 0003:00:00.0: PCI bridge to [bus 01]
[ 1.275632][ T1] pci 0003:00:00.0: bridge window [mem 0x600c180000000-0x600c1ffefffff]
[ 1.276022][ T1] pci 0003:00:00.0: bridge window [mem 0x6020000000000-0x6023fbff0ffff 64bit pref]
[ 1.276634][ T1] pci_bus 0003:00: resource 4 [mem 0x600c180000000-0x600c1fffeffff]
[ 1.276999][ T1] pci_bus 0003:00: resource 5 [mem 0x6020000000000-0x6023fbfffffff 64bit pref]
[ 1.277359][ T1] pci_bus 0003:01: resource 1 [mem 0x600c180000000-0x600c1ffefffff]
[ 1.277679][ T1] pci_bus 0003:01: resource 2 [mem 0x6020000000000-0x6023fbff0ffff 64bit pref]
[ 1.278082][ T1] pci 0004:00:00.0: bridge window [io 0x1000-0x0fff] to [bus 01] add_size 1000
[ 1.278464][ T1] pci 0004:00:00.0: bridge window [mem 0x40000000-0x3fffffff 64bit pref] to [bus 01] add_size 40000000 add_align 40000000
[ 1.278987][ T1] pci 0004:00:00.0: bridge window [mem 0x00800000-0x007fffff] to [bus 01] add_size 800000 add_align 800000
[ 1.279526][ T1] pci 0004:00:00.0: BAR 9: assigned [mem 0x6024000000000-0x602403fffffff 64bit pref]
[ 1.279925][ T1] pci 0004:00:00.0: BAR 8: assigned [mem 0x600c200000000-0x600c2007fffff]
[ 1.280273][ T1] pci 0004:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.280564][ T1] pci 0004:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.280932][ T1] pci 0004:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.281223][ T1] pci 0004:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.281688][ T1] pci 0004:00:00.0: PCI bridge to [bus 01]
[ 1.282222][ T1] pci 0004:00:00.0: bridge window [mem 0x600c200000000-0x600c27fefffff]
[ 1.282623][ T1] pci 0004:00:00.0: bridge window [mem 0x6024000000000-0x6027f7ff0ffff 64bit pref]
[ 1.283258][ T1] pci_bus 0004:00: resource 4 [mem 0x600c200000000-0x600c27ffeffff]
[ 1.283633][ T1] pci_bus 0004:00: resource 5 [mem 0x6024000000000-0x6027f7fffffff 64bit pref]
[ 1.284000][ T1] pci_bus 0004:01: resource 1 [mem 0x600c200000000-0x600c27fefffff]
[ 1.284324][ T1] pci_bus 0004:01: resource 2 [mem 0x6024000000000-0x6027f7ff0ffff 64bit pref]
[ 1.284724][ T1] pci 0005:00:00.0: bridge window [io 0x1000-0x0fff] to [bus 01] add_size 1000
[ 1.285109][ T1] pci 0005:00:00.0: bridge window [mem 0x40000000-0x3fffffff 64bit pref] to [bus 01] add_size 40000000 add_align 40000000
[ 1.285624][ T1] pci 0005:00:00.0: bridge window [mem 0x00800000-0x007fffff] to [bus 01] add_size 800000 add_align 800000
[ 1.286157][ T1] pci 0005:00:00.0: BAR 9: assigned [mem 0x6028000000000-0x602803fffffff 64bit pref]
[ 1.286544][ T1] pci 0005:00:00.0: BAR 8: assigned [mem 0x600c280000000-0x600c2807fffff]
[ 1.286895][ T1] pci 0005:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.287182][ T1] pci 0005:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.287543][ T1] pci 0005:00:00.0: BAR 7: no space for [io size 0x1000]
[ 1.287833][ T1] pci 0005:00:00.0: BAR 7: failed to assign [io size 0x1000]
[ 1.288149][ T1] pci 0005:00:00.0: PCI bridge to [bus 01]
[ 1.288640][ T1] pci 0005:00:00.0: bridge window [mem 0x600c280000000-0x600c2ffefffff]
[ 1.289031][ T1] pci 0005:00:00.0: bridge window [mem 0x6028000000000-0x602bf7ff0ffff 64bit pref]
[ 1.289663][ T1] pci_bus 0005:00: resource 4 [mem 0x600c280000000-0x600c2fffeffff]
[ 1.290038][ T1] pci_bus 0005:00: resource 5 [mem 0x6028000000000-0x602bf7fffffff 64bit pref]
[ 1.290415][ T1] pci_bus 0005:01: resource 1 [mem 0x600c280000000-0x600c2ffefffff]
[ 1.290744][ T1] pci_bus 0005:01: resource 2 [mem 0x6028000000000-0x602bf7ff0ffff 64bit pref]
[ 1.291302][ T1] pci_bus 0000:00: Configuring PE for bus
[ 1.292035][ T1] pci 0000:00 : [PE# 1fe] Secondary bus 0x0000000000000000 associated with PE#1fe
[ 1.293202][ T1] pci 0000:00:00.0: Configured PE#1fe
[ 1.295876][ T1] pci_bus 0000:01: Configuring PE for bus
[ 1.296332][ T1] pci 0000:01 : [PE# 1fd] Secondary bus 0x0000000000000001 associated with PE#1fd
[ 1.297103][ T1] pci 0000:01:00.0: Configured PE#1fd
[ 1.297363][ T1] pci 0000:01 : [PE# 1fd] Setting up 32-bit TCE table at 0..80000000
[ 1.298764][ T1] IOMMU table initialized, virtual merging enabled
[ 1.299106][ T1] pci 0000:01 : [PE# 1fd] Setting up window#0 0..7fffffff pg=10000
[ 1.299875][ T1] pci 0000:01 : [PE# 1fd] Enabling 64-bit DMA bypass
[ 1.301127][ T1] pci 0000:01:00.0: Adding to iommu group 0
[ 1.303551][ T1] pci_bus 0001:00: Configuring PE for bus
[ 1.303821][ T1] pci 0001:00 : [PE# fe] Secondary bus 0x0000000000000000 associated with PE#fe
[ 1.304336][ T1] pci 0001:00:00.0: Configured PE#fe
[ 1.305333][ T1] pci_bus 0002:00: Configuring PE for bus
[ 1.305584][ T1] pci 0002:00 : [PE# fe] Secondary bus 0x0000000000000000 associated with PE#fe
[ 1.306093][ T1] pci 0002:00:00.0: Configured PE#fe
[ 1.307058][ T1] pci_bus 0003:00: Configuring PE for bus
[ 1.307309][ T1] pci 0003:00 : [PE# 1fe] Secondary bus 0x0000000000000000 associated with PE#1fe
[ 1.307823][ T1] pci 0003:00:00.0: Configured PE#1fe
[ 1.308719][ T1] pci_bus 0004:00: Configuring PE for bus
[ 1.308969][ T1] pci 0004:00 : [PE# fe] Secondary bus 0x0000000000000000 associated with PE#fe
[ 1.309469][ T1] pci 0004:00:00.0: Configured PE#fe
[ 1.310396][ T1] pci_bus 0005:00: Configuring PE for bus
[ 1.310646][ T1] pci 0005:00 : [PE# fe] Secondary bus 0x0000000000000000 associated with PE#fe
[ 1.311146][ T1] pci 0005:00:00.0: Configured PE#fe
[ 1.314106][ T1] pci 0000:00:00.0: enabling device (0105 -> 0107)
[ 1.314972][ T1] EEH: Capable adapter found: recovery enabled.
[ 1.327661][ T1] cpuidle-powernv: Default stop: psscr = 0x0000000000000330,mask=0x00000000003003ff
[ 1.328088][ T1] cpuidle-powernv: Deepest stop: psscr = 0x0000000000300331,mask=0x00000000003003ff
[ 1.328467][ T1] cpuidle-powernv: First stop level that may lose SPRs = 0x10
[ 1.328771][ T1] cpuidle-powernv: First stop level that may lose timebase = 0x10
[ 1.418096][ T1] Kprobes globally optimized
[ 1.445284][ T34] cryptomgr_test (34) used greatest stack depth: 10880 bytes left
[ 1.477721][ T43] cryptomgr_test (43) used greatest stack depth: 10528 bytes left
[ 1.649775][ T1] raid6: vpermxor8 gen() 911 MB/s
[ 1.821391][ T1] raid6: vpermxor4 gen() 892 MB/s
[ 1.992859][ T1] raid6: vpermxor2 gen() 801 MB/s
[ 2.164481][ T1] raid6: vpermxor1 gen() 670 MB/s
[ 2.336154][ T1] raid6: altivecx8 gen() 1082 MB/s
[ 2.507671][ T1] raid6: altivecx4 gen() 1221 MB/s
[ 2.679460][ T1] raid6: altivecx2 gen() 1120 MB/s
[ 2.850914][ T1] raid6: altivecx1 gen() 843 MB/s
[ 3.022625][ T1] raid6: int64x8 gen() 1612 MB/s
[ 3.195010][ T1] raid6: int64x8 xor() 1085 MB/s
[ 3.366613][ T1] raid6: int64x4 gen() 2585 MB/s
[ 3.539108][ T1] raid6: int64x4 xor() 1289 MB/s
[ 3.711797][ T1] raid6: int64x2 gen() 2250 MB/s
[ 3.884349][ T1] raid6: int64x2 xor() 1449 MB/s
[ 4.055962][ T1] raid6: int64x1 gen() 1654 MB/s
[ 4.227577][ T1] raid6: int64x1 xor() 1052 MB/s
[ 4.227844][ T1] raid6: using algorithm int64x4 gen() 2585 MB/s
[ 4.228126][ T1] raid6: .... xor() 1289 MB/s, rmw enabled
[ 4.228428][ T1] raid6: using intx1 recovery algorithm
[ 4.229638][ T1] iommu: Default domain type: Translated
[ 4.229925][ T1] iommu: DMA domain TLB invalidation policy: lazy mode
[ 4.237510][ T1] vgaarb: loaded
[ 4.246973][ T1] SCSI subsystem initialized
[ 4.250526][ T1] usbcore: registered new interface driver usbfs
[ 4.251465][ T1] usbcore: registered new interface driver hub
[ 4.252078][ T1] usbcore: registered new device driver usb
[ 4.270795][ T1] clocksource: Switched to clocksource timebase
[ 4.952052][ T1] hugetlbfs: disabling because there are no supported hugepage sizes
[ 5.048614][ T1] NET: Registered PF_INET protocol family
[ 5.050972][ T1] IP idents hash table entries: 32768 (order: 2, 262144 bytes, linear)
[ 5.058507][ T1] tcp_listen_portaddr_hash hash table entries: 1024 (order: 0, 81920 bytes, linear)
[ 5.059211][ T1] TCP established hash table entries: 16384 (order: 1, 131072 bytes, linear)
[ 5.060165][ T1] TCP bind hash table entries: 16384 (order: 4, 1179648 bytes, linear)
[ 5.063161][ T1] TCP: Hash tables configured (established 16384 bind 16384)
[ 5.064854][ T1] UDP hash table entries: 1024 (order: 1, 163840 bytes, linear)
[ 5.065745][ T1] UDP-Lite hash table entries: 1024 (order: 1, 163840 bytes, linear)
[ 5.068316][ T1] NET: Registered PF_UNIX/PF_LOCAL protocol family
[ 5.069444][ T1] PCI: CLS 0 bytes, default 128
[ 11.698074][ T1] workingset: timestamp_bits=38 max_order=15 bucket_order=0
[ 11.863823][ T1] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 11.868058][ T1] xor: measuring software checksum speed
[ 11.871448][ T1] 8regs : 3419 MB/sec
[ 11.875731][ T1] 8regs_prefetch : 2781 MB/sec
[ 11.879196][ T1] 32regs : 3140 MB/sec
[ 11.883403][ T1] 32regs_prefetch : 2606 MB/sec
[ 11.887182][ T1] altivec : 2876 MB/sec
[ 11.887443][ T1] xor: using function: 8regs (3419 MB/sec)
[ 11.888066][ T1] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
[ 11.888569][ T1] io scheduler mq-deadline registered
[ 11.888942][ T1] io scheduler kyber registered
[ 12.533563][ T1] String selftests succeeded
[ 12.536168][ T1] test_firmware: interface ready
[ 12.536606][ T1] test_bitmap: loaded.
[ 12.538982][ T1] test_bitmap: parselist: 14: input is '0-2047:128/256' OK, Time: 2500
[ 12.540499][ T1] test_bitmap: bitmap_print_to_pagebuf: input is '0-524287
[ 12.540499][ T1] ', Time: 196283
[ 12.547687][ T1] test_bitmap: all 1943 tests passed
[ 12.548124][ T1] test_uuid: all 18 tests passed
[ 12.550638][ T1] crc32: CRC_LE_BITS = 64, CRC_BE BITS = 64
[ 12.550919][ T1] crc32: self tests passed, processed 225944 bytes in 441546 nsec
[ 12.551692][ T1] crc32c: CRC_LE_BITS = 64
[ 12.551895][ T1] crc32c: self tests passed, processed 225944 bytes in 210993 nsec
[ 12.589245][ T1] crc32_combine: 8373 self tests passed
[ 12.625891][ T1] crc32c_combine: 8373 self tests passed
[ 12.626772][ T1] glob: 64 self-tests passed, 0 failed
[ 12.632624][ T1] rbtree testing
[ 12.653861][ T1] -> test 1 (latency of nnodes insert+delete): 10807 cycles
[ 12.666573][ T1] -> test 2 (latency of nnodes cached insert+delete): 6252 cycles
[ 12.669009][ T1] -> test 3 (latency of inorder traversal): 1046 cycles
[ 12.669361][ T1] -> test 4 (latency to fetch first node)
[ 12.669608][ T1] non-cached: 27 cycles
[ 12.669823][ T1] cached: 0 cycles
[ 12.769434][ T1] augmented rbtree testing
[ 12.812243][ T1] -> test 1 (latency of nnodes insert+delete): 21897 cycles
[ 12.860505][ T1] -> test 2 (latency of nnodes cached insert+delete): 24428 cycles
[ 12.994713][ T1] interval tree insert/remove
[ 13.018177][ T1] -> 11958 cycles
[ 13.018560][ T1] interval tree search
[ 13.112939][ T1] -> 48288 cycles (2692 results)
[ 13.114012][ T1] IPMI message handler: version 39.2
[ 13.114781][ T1] ipmi device interface
[ 13.345730][ T1] ipmi-powernv ibm,opal:ipmi: IPMI message handler: Found new BMC (man_id: 0x000000, prod_id: 0x0000, dev_id: 0x20)
[ 13.569872][ T1] hvc0: raw protocol on /ibm,opal/consoles/serial@0 (boot console)
[ 13.571124][ T1] hvc0: No interrupts property, using OPAL event
[ 13.579830][ T1] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[ 13.647596][ T1] loop: module loaded
[ 13.650217][ T1] Adaptec aacraid driver 1.2.1[50983]-custom
[ 13.652349][ T1] megasas: 07.717.02.00-rc1
[ 13.653397][ T1] ipr: IBM Power RAID SCSI Device Driver version: 2.6.4 (March 14, 2017)
[ 13.679028][ T1] 1 fixed-partitions partitions found on MTD device flash@0
[ 13.679453][ T1] Creating 1 MTD partitions on "flash@0":
[ 13.679876][ T1] 0x000000000000-0x000002000000 : "PNOR"
[ 13.711952][ T1] libphy: Fixed MDIO Bus: probed
[ 13.715189][ T1] e100: Intel(R) PRO/100 Network Driver
[ 13.715437][ T1] e100: Copyright(c) 1999-2006 Intel Corporation
[ 13.715979][ T1] e1000: Intel(R) PRO/1000 Network Driver
[ 13.716232][ T1] e1000: Copyright (c) 1999-2006 Intel Corporation.
[ 13.716928][ T1] e1000e: Intel(R) PRO/1000 Network Driver
[ 13.717181][ T1] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
[ 13.718728][ T11] 8139cp: 8139cp: 10/100 PCI Ethernet driver v1.3 (Mar 22, 2004)
[ 13.719630][ T11] 8139cp 0000:01:00.0: enabling device (0100 -> 0102)
[ 13.726664][ T11] 8139cp 0000:01:00.0 eth0: RTL-8139C+ at 0xc00a000080630000, 52:54:00:12:34:56, IRQ 32
[ 13.728905][ T1] usbcore: registered new interface driver asix
[ 13.729476][ T1] usbcore: registered new interface driver ax88179_178a
[ 13.730006][ T1] usbcore: registered new interface driver cdc_ether
[ 13.730746][ T1] usbcore: registered new interface driver net1080
[ 13.731272][ T1] usbcore: registered new interface driver cdc_subset
[ 13.731791][ T1] usbcore: registered new interface driver zaurus
[ 13.732528][ T1] usbcore: registered new interface driver cdc_ncm
[ 13.732828][ T1] Fusion MPT base driver 3.04.20
[ 13.733047][ T1] Copyright (c) 1999-2008 LSI Corporation
[ 13.733504][ T1] Fusion MPT SAS Host driver 3.04.20
[ 13.735177][ T1] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 13.735547][ T1] ehci-pci: EHCI PCI platform driver
[ 13.736156][ T1] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 13.738233][ T1] usbcore: registered new interface driver uas
[ 13.738956][ T1] usbcore: registered new interface driver usb-storage
[ 13.739614][ T1] usbcore: registered new interface driver usbtest
[ 13.740123][ T1] usbcore: registered new interface driver usb_ehset_test
[ 13.740829][ T1] usbcore: registered new interface driver lvs
[ 13.984603][ T1] rtc-opal opal-rtc: registered as rtc0
[ 14.191792][ T1] rtc-opal opal-rtc: setting system clock to 2021-08-18T02:42:24 UTC (1629254544)
[ 14.193896][ T1] i2c /dev entries driver
[ 14.202822][ T1] device-mapper: uevent: version 1.0.3
[ 14.209077][ T1] device-mapper: ioctl: 4.45.0-ioctl (2021-03-22) initialised: dm-devel@redhat.com
[ 14.209551][ T1] powernv-cpufreq: ibm,pstate-min node not found
[ 14.209825][ T1] powernv-cpufreq: Platform driver disabled. System does not support PState control
[ 14.213922][ T1] sdhci: Secure Digital Host Controller Interface driver
[ 14.214246][ T1] sdhci: Copyright(c) Pierre Ossman
[ 14.216479][ T1] ipip: IPv4 and MPLS over IPv4 tunneling driver
[ 14.228886][ T1] NET: Registered PF_INET6 protocol family
[ 14.243458][ T1] Segment Routing with IPv6
[ 14.243966][ T1] In-situ OAM (IOAM) with IPv6
[ 14.244762][ T1] NET: Registered PF_PACKET protocol family
[ 14.246324][ T1] Key type dns_resolver registered
[ 14.246774][ T1] drmem: No dynamic reconfiguration memory found
[ 14.258788][ T1] registered taskstats version 1
[ 14.282301][ T1] Btrfs loaded, crc32c=crc32c-generic, zoned=no, fsverity=no
[ 14.292334][ T1] ### dt-test ### start of unittest - you will see error messages
[ 14.296627][ T1] ### dt-test ### EXPECT \ : Duplicate name in testcase-data, renamed to "duplicate-name#1"
[ 14.297957][ T1] Duplicate name in testcase-data, renamed to "duplicate-name#1"
[ 14.322891][ T1] ### dt-test ### EXPECT / : Duplicate name in testcase-data, renamed to "duplicate-name#1"
[ 14.328302][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-a: could not get #phandle-cells-missing for /testcase-data/phandle-tests/provider1
[ 14.328760][ T1] OF: /testcase-data/phandle-tests/consumer-a: could not get #phandle-cells-missing for /testcase-data/phandle-tests/provider1
[ 14.329967][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-a: could not get #phandle-cells-missing for /testcase-data/phandle-tests/provider1
[ 14.329990][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-a: could not get #phandle-cells-missing for /testcase-data/phandle-tests/provider1
[ 14.330773][ T1] OF: /testcase-data/phandle-tests/consumer-a: could not get #phandle-cells-missing for /testcase-data/phandle-tests/provider1
[ 14.331988][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-a: could not get #phandle-cells-missing for /testcase-data/phandle-tests/provider1
[ 14.332025][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-a: could not find phandle
[ 14.332660][ T1] OF: /testcase-data/phandle-tests/consumer-a: could not find phandle 12345678
[ 14.333489][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-a: could not find phandle
[ 14.333533][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-a: could not find phandle
[ 14.333966][ T1] OF: /testcase-data/phandle-tests/consumer-a: could not find phandle 12345678
[ 14.334811][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-a: could not find phandle
[ 14.334842][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-a: #phandle-cells = 3 found -1
[ 14.335284][ T1] OF: /testcase-data/phandle-tests/consumer-a: #phandle-cells = 3 found -1
[ 14.336102][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-a: #phandle-cells = 3 found -1
[ 14.336124][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-a: #phandle-cells = 3 found -1
[ 14.336574][ T1] OF: /testcase-data/phandle-tests/consumer-a: #phandle-cells = 3 found -1
[ 14.337380][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-a: #phandle-cells = 3 found -1
[ 14.338978][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-b: could not get #phandle-missing-cells for /testcase-data/phandle-tests/provider1
[ 14.339501][ T1] OF: /testcase-data/phandle-tests/consumer-b: could not get #phandle-missing-cells for /testcase-data/phandle-tests/provider1
[ 14.341394][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-b: could not get #phandle-missing-cells for /testcase-data/phandle-tests/provider1
[ 14.341466][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-b: could not find phandle
[ 14.342848][ T1] OF: /testcase-data/phandle-tests/consumer-b: could not find phandle 12345678
[ 14.344546][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-b: could not find phandle
[ 14.344606][ T1] ### dt-test ### EXPECT \ : OF: /testcase-data/phandle-tests/consumer-b: #phandle-cells = 2 found -1
[ 14.345657][ T1] OF: /testcase-data/phandle-tests/consumer-b: #phandle-cells = 2 found -1
[ 14.347372][ T1] ### dt-test ### EXPECT / : OF: /testcase-data/phandle-tests/consumer-b: #phandle-cells = 2 found -1
[ 14.353289][ T1] ### dt-test ### FAIL of_unittest_dma_ranges_one():922 of_dma_get_range: wrong phys addr 0x0000000000000000 (expecting 20000000) on node /testcase-data/address-tests/device@70000000
[ 14.354511][ T1] ### dt-test ### FAIL of_unittest_dma_ranges_one():925 of_dma_get_range: wrong DMA addr 0x0000000020000000 (expecting 0) on node /testcase-data/address-tests/device@70000000
[ 14.355461][ T1] ### dt-test ### FAIL of_unittest_dma_ranges_one():922 of_dma_get_range: wrong phys addr 0x0000000100000000 (expecting 20000000) on node /testcase-data/address-tests/bus@80000000/device@1000
[ 14.356255][ T1] ### dt-test ### FAIL of_unittest_dma_ranges_one():925 of_dma_get_range: wrong DMA addr 0x0000000020000000 (expecting 100000000) on node /testcase-data/address-tests/bus@80000000/device@1000
[ 14.357459][ T1] ### dt-test ### FAIL of_unittest_dma_ranges_one():922 of_dma_get_range: wrong phys addr 0x0000000080000000 (expecting 20000000) on node /testcase-data/address-tests/pci@90000000
[ 14.358210][ T1] ### dt-test ### FAIL of_unittest_dma_ranges_one():925 of_dma_get_range: wrong DMA addr 0x0000000020000000 (expecting 80000000) on node /testcase-data/address-tests/pci@90000000
[ 14.361799][ T1] ### dt-test ### EXPECT \ : platform testcase-data:testcase-device2: IRQ index 0 not found
[ 14.361874][ T1] platform testcase-data:testcase-device2: IRQ index 0 not found
[ 14.362644][ T1] ### dt-test ### EXPECT / : platform testcase-data:testcase-device2: IRQ index 0 not found
[ 14.371513][ T1] ### dt-test ### end of unittest - 184 passed, 6 failed
[ 14.375004][ T1] TAP version 14
[ 14.375192][ T1] 1..11
[ 14.375391][ T1] # Subtest: sysctl_test
[ 14.375460][ T1] 1..10
[ 14.378464][ T1] ok 1 - sysctl_test_api_dointvec_null_tbl_data
[ 14.379651][ T1] ok 2 - sysctl_test_api_dointvec_table_maxlen_unset
[ 14.381506][ T1] ok 3 - sysctl_test_api_dointvec_table_len_is_zero
[ 14.382656][ T1] ok 4 - sysctl_test_api_dointvec_table_read_but_position_set
[ 14.384011][ T1] ok 5 - sysctl_test_dointvec_read_happy_single_positive
[ 14.385228][ T1] ok 6 - sysctl_test_dointvec_read_happy_single_negative
[ 14.386628][ T1] ok 7 - sysctl_test_dointvec_write_happy_single_positive
[ 14.387832][ T1] ok 8 - sysctl_test_dointvec_write_happy_single_negative
[ 14.389086][ T1] ok 9 - sysctl_test_api_dointvec_write_single_less_int_min
[ 14.390490][ T1] ok 10 - sysctl_test_api_dointvec_write_single_greater_int_max
[ 14.390881][ T1] # sysctl_test: pass:10 fail:0 skip:0 total:10
[ 14.391258][ T1] # Totals: pass:10 fail:0 skip:0 total:10
[ 14.391605][ T1] ok 1 - sysctl_test
[ 14.392077][ T1] # Subtest: ext4_inode_test
[ 14.392090][ T1] 1..1
[ 14.393284][ T1] # inode_test_xtimestamp_decoding: ok 1 - 1901-12-13 Lower bound of 32bit < 0 timestamp, no extra bits
[ 14.394195][ T1] # inode_test_xtimestamp_decoding: ok 2 - 1969-12-31 Upper bound of 32bit < 0 timestamp, no extra bits
[ 14.395457][ T1] # inode_test_xtimestamp_decoding: ok 3 - 1970-01-01 Lower bound of 32bit >=0 timestamp, no extra bits
[ 14.396662][ T1] # inode_test_xtimestamp_decoding: ok 4 - 2038-01-19 Upper bound of 32bit >=0 timestamp, no extra bits
[ 14.397815][ T1] # inode_test_xtimestamp_decoding: ok 5 - 2038-01-19 Lower bound of 32bit <0 timestamp, lo extra sec bit on
[ 14.398969][ T1] # inode_test_xtimestamp_decoding: ok 6 - 2106-02-07 Upper bound of 32bit <0 timestamp, lo extra sec bit on
[ 14.400124][ T1] # inode_test_xtimestamp_decoding: ok 7 - 2106-02-07 Lower bound of 32bit >=0 timestamp, lo extra sec bit on
[ 14.402278][ T1] # inode_test_xtimestamp_decoding: ok 8 - 2174-02-25 Upper bound of 32bit >=0 timestamp, lo extra sec bit on
[ 14.403526][ T1] # inode_test_xtimestamp_decoding: ok 9 - 2174-02-25 Lower bound of 32bit <0 timestamp, hi extra sec bit on
[ 14.404696][ T1] # inode_test_xtimestamp_decoding: ok 10 - 2242-03-16 Upper bound of 32bit <0 timestamp, hi extra sec bit on
[ 14.405854][ T1] # inode_test_xtimestamp_decoding: ok 11 - 2242-03-16 Lower bound of 32bit >=0 timestamp, hi extra sec bit on
[ 14.407020][ T1] # inode_test_xtimestamp_decoding: ok 12 - 2310-04-04 Upper bound of 32bit >=0 timestamp, hi extra sec bit on
[ 14.408178][ T1] # inode_test_xtimestamp_decoding: ok 13 - 2310-04-04 Upper bound of 32bit>=0 timestamp, hi extra sec bit 1. 1 ns
[ 14.409335][ T1] # inode_test_xtimestamp_decoding: ok 14 - 2378-04-22 Lower bound of 32bit>= timestamp. Extra sec bits 1. Max ns
[ 14.411220][ T1] # inode_test_xtimestamp_decoding: ok 15 - 2378-04-22 Lower bound of 32bit >=0 timestamp. All extra sec bits on
[ 14.412401][ T1] # inode_test_xtimestamp_decoding: ok 16 - 2446-05-10 Upper bound of 32bit >=0 timestamp. All extra sec bits on
[ 14.412926][ T1] # inode_test_xtimestamp_decoding: pass:16 fail:0 skip:0 total:16
[ 14.413434][ T1] ok 1 - inode_test_xtimestamp_decoding
[ 14.413780][ T1] # Totals: pass:16 fail:0 skip:0 total:16
[ 14.414032][ T1] ok 2 - ext4_inode_test
[ 14.414468][ T1] # Subtest: lib_sort
[ 14.414480][ T1] 1..1
[ 14.415945][ T1] ok 1 - test_sort
[ 14.416111][ T1] ok 3 - lib_sort
[ 14.416444][ T1] # Subtest: kunit_executor_test
[ 14.416455][ T1] 1..3
[ 14.417902][ T1] ok 1 - filter_subsuite_test
[ 14.418905][ T1] ok 2 - filter_subsuite_to_empty_test
[ 14.420261][ T1] ok 3 - filter_suites_test
[ 14.421124][ T1] # kunit_executor_test: pass:3 fail:0 skip:0 total:3
[ 14.421343][ T1] # Totals: pass:3 fail:0 skip:0 total:3
[ 14.421626][ T1] ok 4 - kunit_executor_test
[ 14.422053][ T1] # Subtest: kunit-try-catch-test
[ 14.422065][ T1] 1..2
[ 14.424075][ T1] ok 1 - kunit_test_try_catch_successful_try_no_catch
[ 14.425713][ T1] ok 2 - kunit_test_try_catch_unsuccessful_try_does_catch
[ 14.426024][ T1] # kunit-try-catch-test: pass:2 fail:0 skip:0 total:2
[ 14.426347][ T1] # Totals: pass:2 fail:0 skip:0 total:2
[ 14.426633][ T1] ok 5 - kunit-try-catch-test
[ 14.427069][ T1] # Subtest: kunit-resource-test
[ 14.427080][ T1] 1..7
[ 14.428173][ T1] ok 1 - kunit_resource_test_init_resources
[ 14.429237][ T1] ok 2 - kunit_resource_test_alloc_resource
[ 14.431621][ T1] ok 3 - kunit_resource_test_destroy_resource
[ 14.432898][ T1] ok 4 - kunit_resource_test_cleanup_resources
[ 14.434190][ T1] ok 5 - kunit_resource_test_proper_free_ordering
[ 14.435279][ T1] ok 6 - kunit_resource_test_static
[ 14.436861][ T1] ok 7 - kunit_resource_test_named
[ 14.437112][ T1] # kunit-resource-test: pass:7 fail:0 skip:0 total:7
[ 14.437346][ T1] # Totals: pass:7 fail:0 skip:0 total:7
[ 14.437627][ T1] ok 6 - kunit-resource-test
[ 14.438049][ T1] # Subtest: kunit-log-test
[ 14.438059][ T1] 1..1
[ 14.438771][ T104] put this in log.
[ 14.438939][ T104] this too.
[ 14.439116][ T104] add to suite log.
[ 14.439272][ T104] along with this.
[ 14.439707][ T1] ok 1 - kunit_log_test
[ 14.439888][ T1] ok 7 - kunit-log-test
[ 14.440257][ T1] # Subtest: kunit_status
[ 14.440268][ T1] 1..2
[ 14.441840][ T1] ok 1 - kunit_status_set_failure_test
[ 14.442860][ T1] ok 2 - kunit_status_mark_skipped_test
[ 14.443125][ T1] # kunit_status: pass:2 fail:0 skip:0 total:2
[ 14.443377][ T1] # Totals: pass:2 fail:0 skip:0 total:2
[ 14.443637][ T1] ok 8 - kunit_status
[ 14.444039][ T1] # Subtest: string-stream-test
[ 14.444050][ T1] 1..3
[ 14.445245][ T1] ok 1 - string_stream_test_empty_on_creation
[ 14.446679][ T1] ok 2 - string_stream_test_not_empty_after_add
[ 14.448202][ T1] ok 3 - string_stream_test_get_string
[ 14.448495][ T1] # string-stream-test: pass:3 fail:0 skip:0 total:3
[ 14.448746][ T1] # Totals: pass:3 fail:0 skip:0 total:3
[ 14.449023][ T1] ok 9 - string-stream-test
[ 14.449446][ T1] # Subtest: list-kunit-test
[ 14.449457][ T1] 1..36
[ 14.451451][ T1] ok 1 - list_test_list_init
[ 14.452493][ T1] ok 2 - list_test_list_add
[ 14.453552][ T1] ok 3 - list_test_list_add_tail
[ 14.454616][ T1] ok 4 - list_test_list_del
[ 14.455644][ T1] ok 5 - list_test_list_replace
[ 14.456671][ T1] ok 6 - list_test_list_replace_init
[ 14.457789][ T1] ok 7 - list_test_list_swap
[ 14.458867][ T1] ok 8 - list_test_list_del_init
[ 14.459925][ T1] ok 9 - list_test_list_move
[ 14.461559][ T1] ok 10 - list_test_list_move_tail
[ 14.462757][ T1] ok 11 - list_test_list_bulk_move_tail
[ 14.463787][ T1] ok 12 - list_test_list_is_first
[ 14.464823][ T1] ok 13 - list_test_list_is_last
[ 14.465859][ T1] ok 14 - list_test_list_empty
[ 14.466872][ T1] ok 15 - list_test_list_empty_careful
[ 14.467928][ T1] ok 16 - list_test_list_rotate_left
[ 14.469065][ T1] ok 17 - list_test_list_rotate_to_front
[ 14.470131][ T1] ok 18 - list_test_list_is_singular
[ 14.471588][ T1] ok 19 - list_test_list_cut_position
[ 14.472793][ T1] ok 20 - list_test_list_cut_before
[ 14.473933][ T1] ok 21 - list_test_list_splice
[ 14.475096][ T1] ok 22 - list_test_list_splice_tail
[ 14.476234][ T1] ok 23 - list_test_list_splice_init
[ 14.477388][ T1] ok 24 - list_test_list_splice_tail_init
[ 14.478401][ T1] ok 25 - list_test_list_entry
[ 14.479436][ T1] ok 26 - list_test_list_first_entry
[ 14.481777][ T1] ok 27 - list_test_list_last_entry
[ 14.482916][ T1] ok 28 - list_test_list_first_entry_or_null
[ 14.483933][ T1] ok 29 - list_test_list_next_entry
[ 14.484971][ T1] ok 30 - list_test_list_prev_entry
[ 14.486050][ T1] ok 31 - list_test_list_for_each
[ 14.487135][ T1] ok 32 - list_test_list_for_each_prev
[ 14.488253][ T1] ok 33 - list_test_list_for_each_safe
[ 14.489385][ T1] ok 34 - list_test_list_for_each_prev_safe
[ 14.491430][ T1] ok 35 - list_test_list_for_each_entry
[ 14.492601][ T1] ok 36 - list_test_list_for_each_entry_reverse
[ 14.492868][ T1] # list-kunit-test: pass:36 fail:0 skip:0 total:36
[ 14.493149][ T1] # Totals: pass:36 fail:0 skip:0 total:36
[ 14.493425][ T1] ok 10 - list-kunit-test
[ 14.493848][ T1] # Subtest: qos-kunit-test
[ 14.493859][ T1] 1..3
[ 14.495411][ T1] ok 1 - freq_qos_test_min
[ 14.496624][ T1] ok 2 - freq_qos_test_maxdef
[ 14.497716][ T1] ok 3 - freq_qos_test_readd
[ 14.497949][ T1] # qos-kunit-test: pass:3 fail:0 skip:0 total:3
[ 14.498176][ T1] # Totals: pass:3 fail:0 skip:0 total:3
[ 14.498441][ T1] ok 11 - qos-kunit-test
[ 14.505883][ T1] md: Waiting for all devices to be available before autodetect
[ 14.506243][ T1] md: If you don't use raid, use raid=noautodetect
[ 14.506595][ T1] md: Autodetecting RAID arrays.
[ 14.506868][ T1] md: autorun ...
[ 14.507051][ T1] md: ... autorun DONE.
[ 14.509976][ T1]
[ 14.510063][ T1] ======================================================
[ 14.510243][ T1] WARNING: possible circular locking dependency detected
[ 14.510463][ T1] 5.14.0-rc6-next-20210817 #1 Not tainted
[ 14.510664][ T1] ------------------------------------------------------
[ 14.510835][ T1] swapper/0/1 is trying to acquire lock:
[ 14.511006][ T1] c00000000192c620 (mtd_table_mutex){+.+.}-{3:3}, at: blktrans_open+0x60/0x300
[ 14.511490][ T1]
[ 14.511490][ T1] but task is already holding lock:
[ 14.511672][ T1] c000000005a7b118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev+0x20c/0x3c0
[ 14.511946][ T1]
[ 14.511946][ T1] which lock already depends on the new lock.
[ 14.511946][ T1]
[ 14.512198][ T1]
[ 14.512198][ T1] the existing dependency chain (in reverse order) is:
[ 14.512434][ T1]
[ 14.512434][ T1] -> #1 (&disk->open_mutex){+.+.}-{3:3}:
[ 14.512676][ T1] __mutex_lock+0xd8/0xaf0
[ 14.512849][ T1] bd_register_pending_holders+0x48/0x190
[ 14.513013][ T1] device_add_disk+0x27c/0x3d0
[ 14.513171][ T1] add_mtd_blktrans_dev+0x358/0x620
[ 14.513332][ T1] mtdblock_add_mtd+0x94/0x120
[ 14.513487][ T1] blktrans_notify_add+0x7c/0xb0
[ 14.513644][ T1] add_mtd_device+0x3f8/0x600
[ 14.513789][ T1] add_mtd_partitions+0xfc/0x2b0
[ 14.513944][ T1] parse_mtd_partitions+0x2b4/0x980
[ 14.514115][ T1] mtd_device_parse_register+0xc0/0x3a0
[ 14.514281][ T1] powernv_flash_probe+0x180/0x240
[ 14.514444][ T1] platform_probe+0x78/0x120
[ 14.514598][ T1] really_probe+0x1cc/0x440
[ 14.514738][ T1] __driver_probe_device+0xb0/0x160
[ 14.514892][ T1] driver_probe_device+0x60/0x130
[ 14.515043][ T1] __driver_attach+0xe8/0x160
[ 14.515188][ T1] bus_for_each_dev+0xb4/0x130
[ 14.515328][ T1] driver_attach+0x34/0x50
[ 14.515466][ T1] bus_add_driver+0x1d8/0x2b0
[ 14.515608][ T1] driver_register+0x98/0x1a0
[ 14.515753][ T1] __platform_driver_register+0x38/0x50
[ 14.515923][ T1] powernv_flash_driver_init+0x2c/0x40
[ 14.516084][ T1] do_one_initcall+0x88/0x480
[ 14.516223][ T1] kernel_init_freeable+0x3dc/0x484
[ 14.516392][ T1] kernel_init+0x3c/0x180
[ 14.516522][ T1] ret_from_kernel_thread+0x5c/0x64
[ 14.516718][ T1]
[ 14.516718][ T1] -> #0 (mtd_table_mutex){+.+.}-{3:3}:
[ 14.516917][ T1] __lock_acquire+0x1b5c/0x21d0
[ 14.517068][ T1] lock_acquire+0x2d8/0x4b0
[ 14.517208][ T1] __mutex_lock+0xd8/0xaf0
[ 14.517342][ T1] blktrans_open+0x60/0x300
[ 14.517487][ T1] blkdev_get_whole+0x50/0x110
[ 14.517632][ T1] blkdev_get_by_dev+0x1dc/0x3c0
[ 14.517782][ T1] blkdev_get_by_path+0x90/0xe0
[ 14.517931][ T1] mount_bdev+0x6c/0x2b0
[ 14.518063][ T1] ext4_mount+0x28/0x40
[ 14.518207][ T1] legacy_get_tree+0x4c/0xb0
[ 14.518358][ T1] vfs_get_tree+0x48/0x100
[ 14.518489][ T1] path_mount+0x2d8/0xd30
[ 14.518616][ T1] init_mount+0x7c/0xcc
[ 14.518759][ T1] mount_block_root+0x230/0x454
[ 14.518894][ T1] prepare_namespace+0x1b0/0x204
[ 14.519031][ T1] kernel_init_freeable+0x428/0x484
[ 14.519193][ T1] kernel_init+0x3c/0x180
[ 14.519321][ T1] ret_from_kernel_thread+0x5c/0x64
[ 14.519501][ T1]
[ 14.519501][ T1] other info that might help us debug this:
[ 14.519501][ T1]
[ 14.519756][ T1] Possible unsafe locking scenario:
[ 14.519756][ T1]
[ 14.519934][ T1] CPU0 CPU1
[ 14.520065][ T1] ---- ----
[ 14.520194][ T1] lock(&disk->open_mutex);
[ 14.520326][ T1] lock(mtd_table_mutex);
[ 14.520506][ T1] lock(&disk->open_mutex);
[ 14.520693][ T1] lock(mtd_table_mutex);
[ 14.520822][ T1]
[ 14.520822][ T1] *** DEADLOCK ***
[ 14.520822][ T1]
[ 14.521042][ T1] 1 lock held by swapper/0/1:
[ 14.521181][ T1] #0: c000000005a7b118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev+0x20c/0x3c0
[ 14.521481][ T1]
[ 14.521481][ T1] stack backtrace:
[ 14.521733][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.14.0-rc6-next-20210817 #1
[ 14.522127][ T1] Call Trace:
[ 14.522256][ T1] [c000000002d072b0] [c0000000009106c8] dump_stack_lvl+0xac/0x108 (unreliable)
[ 14.522564][ T1] [c000000002d072f0] [c0000000001aa04c] print_circular_bug.isra.44+0x37c/0x3e0
[ 14.522812][ T1] [c000000002d07390] [c0000000001aa270] check_noncircular+0x1c0/0x1f0
[ 14.523024][ T1] [c000000002d07460] [c0000000001aff3c] __lock_acquire+0x1b5c/0x21d0
[ 14.523236][ T1] [c000000002d075a0] [c0000000001ad2b8] lock_acquire+0x2d8/0x4b0
[ 14.523439][ T1] [c000000002d076a0] [c0000000010ae868] __mutex_lock+0xd8/0xaf0
[ 14.523644][ T1] [c000000002d077b0] [c000000000bad9f0] blktrans_open+0x60/0x300
[ 14.523858][ T1] [c000000002d07800] [c000000000540050] blkdev_get_whole+0x50/0x110
[ 14.524069][ T1] [c000000002d07840] [c00000000054289c] blkdev_get_by_dev+0x1dc/0x3c0
[ 14.524286][ T1] [c000000002d078a0] [c000000000542e90] blkdev_get_by_path+0x90/0xe0
[ 14.524499][ T1] [c000000002d078f0] [c0000000004d148c] mount_bdev+0x6c/0x2b0
[ 14.524694][ T1] [c000000002d07990] [c00000000064a0f8] ext4_mount+0x28/0x40
[ 14.524887][ T1] [c000000002d079b0] [c0000000005315dc] legacy_get_tree+0x4c/0xb0
[ 14.525100][ T1] [c000000002d079e0] [c0000000004cf5e8] vfs_get_tree+0x48/0x100
[ 14.525298][ T1] [c000000002d07a50] [c00000000050fbe8] path_mount+0x2d8/0xd30
[ 14.525489][ T1] [c000000002d07ae0] [c000000001587874] init_mount+0x7c/0xcc
[ 14.525694][ T1] [c000000002d07b50] [c000000001551bd8] mount_block_root+0x230/0x454
[ 14.525894][ T1] [c000000002d07c50] [c000000001552058] prepare_namespace+0x1b0/0x204
[ 14.526106][ T1] [c000000002d07cc0] [c000000001551714] kernel_init_freeable+0x428/0x484
[ 14.526335][ T1] [c000000002d07da0] [c000000000012d1c] kernel_init+0x3c/0x180
[ 14.526529][ T1] [c000000002d07e10] [c00000000000cfd4] ret_from_kernel_thread+0x5c/0x64
[ 14.567502][ T1] EXT4-fs (mtdblock0): mounted filesystem without journal. Opts: (null). Quota mode: disabled.
[ 14.568104][ T1] VFS: Mounted root (ext4 filesystem) readonly on device 31:0.
[ 14.572575][ T1] devtmpfs: mounted
[ 14.632605][ T1] Freeing unused kernel image (initmem) memory: 1984K
[ 14.632873][ T1] Kernel memory protection not selected by kernel config.
[ 14.633341][ T1] Run /sbin/init as init process
[ 14.633475][ T1] with arguments:
[ 14.633586][ T1] /sbin/init
[ 14.633692][ T1] with environment:
[ 14.633814][ T1] HOME=/
[ 14.633912][ T1] TERM=linux
[ 14.651001][ C0] random: fast init done
[ 15.671461][ T152] mount (152) used greatest stack depth: 10048 bytes left
mount: mounting devtmpfs on /dev failed: Device or resource busy
[ 15.768631][ T48] (null): opal_flash_async_op(op=0) failed (rc -1)
[ 15.773159][ T48] blk_update_request: I/O error, dev mtdblock0, sector 2 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 15.773787][ T48] blk_update_request: I/O error, dev mtdblock0, sector 2 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0
[ 15.774151][ T48] Buffer I/O error on dev mtdblock0, logical block 1, lost sync page write
[ 15.775037][ T154] EXT4-fs (mtdblock0): I/O error while writing superblock
mount: mounting /dev/root on / failed: Input/output error
Starting syslogd: OK
Starting klogd: OK
Running sysctl: [ 16.730207][ T179] logger (179) used greatest stack depth: 9920 bytes left
OK
Saving random seed: SKIP (read-only file system detected)
Starting network: [ 17.450126][ T195] 8139cp 0000:01:00.0 eth0: link up, 100Mbps, full-duplex, lpa 0x05E1
udhcpc: started, v1.33.0
udhcpc: sending discover
udhcpc: sending select for 10.0.2.15
udhcpc: lease of 10.0.2.15 obtained, lease time 86400
deleting routers
adding dns 10.0.2.3
OK
Found console hvc0
Linux version 5.14.0-rc6-next-20210817 (groeck@server.roeck-us.net) (powerpc64-linux-gcc.br_real (Buildroot 2019.02-git-00353-g4f20f23) 7.4.0, GNU ld (GNU Binutils) 2.31.1) #1 SMP Tue Aug 17 19:13:07 PDT 2021
[ 18.515763][ T227] telnet (227) used greatest stack depth: 8528 bytes left
Network interface test passed
Boot successful.
Rebooting
[ 34.724800][ T232] reboot: Restarting system
[ 48.142228983,5] OPAL: Reboot request...
[ 48.142294919,2] NVRAM: Failed to load
------------
--
dm-devel mailing list
dm-devel@redhat.com
https://listman.redhat.com/mailman/listinfo/dm-devel
next prev parent reply other threads:[~2021-08-18 2:51 UTC|newest]
Thread overview: 70+ messages / expand[flat|nested] mbox.gz Atom feed top
2021-08-04 9:41 use regular gendisk registration in device mapper v2 Christoph Hellwig
2021-08-04 9:41 ` [dm-devel] " Christoph Hellwig
2021-08-04 9:41 ` [PATCH 1/8] block: make the block holder code optional Christoph Hellwig
2021-08-04 9:41 ` [dm-devel] " Christoph Hellwig
2021-08-04 9:41 ` [PATCH 2/8] block: remove the extra kobject reference in bd_link_disk_holder Christoph Hellwig
2021-08-04 9:41 ` [dm-devel] " Christoph Hellwig
2021-08-04 9:41 ` [PATCH 3/8] block: look up holders by bdev Christoph Hellwig
2021-08-04 9:41 ` [dm-devel] " Christoph Hellwig
2021-08-04 9:41 ` [PATCH 4/8] block: support delayed holder registration Christoph Hellwig
2021-08-04 9:41 ` [dm-devel] " Christoph Hellwig
[not found] ` <CGME20210810213058eucas1p109323e3c3ecaa76d37d8cf63b6d8ecfd@eucas1p1.samsung.com>
2021-08-10 21:30 ` Marek Szyprowski
2021-08-10 21:30 ` [dm-devel] " Marek Szyprowski
2021-08-14 21:13 ` Guenter Roeck
2021-08-14 21:13 ` Guenter Roeck
2021-08-15 7:07 ` Christoph Hellwig
2021-08-15 7:07 ` Christoph Hellwig
2021-08-15 14:27 ` Guenter Roeck
2021-08-15 14:27 ` Guenter Roeck
2021-08-16 7:21 ` Christoph Hellwig
2021-08-16 7:21 ` Christoph Hellwig
2021-08-16 14:17 ` Guenter Roeck
2021-08-16 14:17 ` Guenter Roeck
2021-08-20 15:08 ` Christoph Hellwig
2021-08-20 15:08 ` Christoph Hellwig
2021-08-21 3:17 ` Guenter Roeck
2021-08-21 3:17 ` Guenter Roeck
2021-08-18 2:51 ` Guenter Roeck [this message]
2021-08-18 2:51 ` Guenter Roeck
2021-08-04 9:41 ` [PATCH 5/8] dm: cleanup cleanup_mapped_device Christoph Hellwig
2021-08-04 9:41 ` [dm-devel] " Christoph Hellwig
2021-08-04 9:41 ` [PATCH 6/8] dm: move setting md->type into dm_setup_md_queue Christoph Hellwig
2021-08-04 9:41 ` [dm-devel] " Christoph Hellwig
2021-08-04 9:41 ` [PATCH 7/8] dm: delay registering the gendisk Christoph Hellwig
2021-08-04 9:41 ` [dm-devel] " Christoph Hellwig
2021-08-09 23:31 ` Alasdair G Kergon
2021-08-09 23:31 ` Alasdair G Kergon
2021-08-10 0:17 ` Alasdair G Kergon
2021-08-10 0:17 ` Alasdair G Kergon
2021-08-10 13:12 ` Peter Rajnoha
2021-08-10 13:12 ` Peter Rajnoha
2021-08-10 15:05 ` Alasdair G Kergon
2021-08-10 15:05 ` Alasdair G Kergon
2022-07-07 3:29 ` Yu Kuai
2022-07-07 3:29 ` [dm-devel] " Yu Kuai
2022-07-07 5:24 ` Christoph Hellwig
2022-07-07 5:24 ` [dm-devel] " Christoph Hellwig
2022-07-07 7:20 ` Yu Kuai
2022-07-07 7:20 ` [dm-devel] " Yu Kuai
2022-07-15 3:24 ` Yu Kuai
2022-07-15 3:24 ` [dm-devel] " Yu Kuai
2022-08-01 1:04 ` Yu Kuai
2022-08-01 1:04 ` [dm-devel] " Yu Kuai
2021-08-04 9:41 ` [PATCH 8/8] block: remove support for delayed queue registrations Christoph Hellwig
2021-08-04 9:41 ` [dm-devel] " Christoph Hellwig
2021-08-09 17:51 ` use regular gendisk registration in device mapper v2 Jens Axboe
2021-08-09 17:51 ` [dm-devel] " Jens Axboe
2021-08-10 0:36 ` Alasdair G Kergon
2021-08-10 0:36 ` Alasdair G Kergon
2021-08-10 14:41 ` Alasdair G Kergon
2021-08-10 14:41 ` Alasdair G Kergon
2021-08-19 15:58 ` holders not working properly, regression [was: Re: use regular gendisk registration in device mapper v2] Mike Snitzer
2021-08-19 15:58 ` [dm-devel] " Mike Snitzer
2021-08-19 18:05 ` Christoph Hellwig
2021-08-19 18:05 ` [dm-devel] " Christoph Hellwig
2021-08-19 22:08 ` Mike Snitzer
2021-08-19 22:08 ` [dm-devel] " Mike Snitzer
-- strict thread matches above, loose matches on Subject: below --
2021-07-25 5:54 use regular gendisk registration in device mapper Christoph Hellwig
2021-07-25 5:54 ` [dm-devel] [PATCH 4/8] block: support delayed holder registration Christoph Hellwig
2021-07-27 16:06 ` Mike Snitzer
2021-07-28 6:54 ` Christoph Hellwig
2021-07-29 16:32 ` Mike Snitzer
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20210818025153.GA1053733@roeck-us.net \
--to=linux@roeck-us.net \
--cc=axboe@kernel.dk \
--cc=dm-devel@redhat.com \
--cc=hch@lst.de \
--cc=linux-block@vger.kernel.org \
--cc=snitzer@redhat.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.