search

Dasharo / dasharo-issues

The Dasharo issue tracker
https://dasharo.com/
25 stars 0 forks source link

Talos II under Heads rolling release: TPM module (revision prior of 1.1) : not detected #272

Closed tlaurion closed 1 year ago

tlaurion commented 1 year ago

Dasharo version Heads running release. Command line download of required images, links obtained from CircleCI build of master's server board's artifacts: user@talos-tests:~/QubesIncoming/heads-tests$ rm * && wget https://output.circle-artifacts.com/output/job/90adf917-76d4-4d26-be2a-e1f0cf121724/artifacts/0/build/ppc64/talos-2_server/heads-talos-2_server-v0.2.0-1296-g139ecb8-zImage.bundled https://output.circle-artifacts.com/output/job/90adf917-76d4-4d26-be2a-e1f0cf121724/artifacts/0/build/ppc64/talos-2_server/heads-talos-2_server-v0.2.0-1296-g139ecb8.bootblock https://output.circle-artifacts.com/output/job/90adf917-76d4-4d26-be2a-e1f0cf121724/artifacts/0/build/ppc64/talos-2_server/heads-talos-2_server-v0.2.0-1296-g139ecb8.rom

Upload: rsync -ravczz --inplace --delete /home/user/QubesIncoming/heads-tests root@192.168.2.187:/tmp/images/

BMC creation of test image (boot from BMC flash without actually flashing): ssh -l root 192.168.2.187 "pflash -r /tmp/talos.pnor && cd /tmp/images/heads-tests && pflash -F ../../talos.pnor -f -P HBB -p *.bootblock && pflash -F ../../talos.pnor -f -P HBI -p *.rom && pflash -F ../../talos.pnor -f -P BOOTKERNEL -p *zImage.bundled && mboxctl --backend file:/tmp/talos.pnor"

Boot from modified BMC image: ssh -l root 192.168.2.187 obmcutil poweron && obmc-console-client

Dasharo variant

Server

Affected component(s) or functionality

TPM module, first revision is not detected

Brief summary

# cbmem -L
No tcpa log found in coreboot table.
~ # dmesg | grep -i tpm
[    4.802683] ima: No TPM chip found, activating TPM-bypass!
~ # ls /dev/tpm0
ls: /dev/tpm0: No such file or directory

How reproducible

100%

How to reproduce Test with above instructions with a TPM module connected

Expected behavior

TPM being detected from coreboot (cbmem -L) then detected under Heads and used to extend measurements

Actual behavior

TPM is not discovered

Screenshots

I replicated connection/orientation as shown under https://github.com/3mdeb/talos-tpm-module/issues/2#issuecomment-1325144582, connected with and without jumper to obtain same undetected module from coreboot and Heads

ConnectedTPM

Additional context

From within Heads:
~ # cbmem -1

coreboot--TIMELESS--LESSTIME--Heads-v0.2.0-1296-g139ecb8 Thu Jan  1 00:00:00 UTC 1970 bootblock starting (log level: 7)...
FFS header at 0x80060300ffff7000
PNOR base at 0x80060300fc000000
HBI partition has ECC
HBI is in 0x00426200 through 0x0175f037
FMAP: Found "FLASH" version 1.1 at 0x20000.
FMAP: base = 0x0 size = 0x200000 #areas = 4
FMAP: area COREBOOT found @ 20200 (1965568 bytes)
CBFS: mcache @0xf8231000 built for 10 files, used 0x1f0 of 0x2000 bytes
CBFS: Found 'fallback/romstage' @0x80 size 0x124a1 in mcache @0xf823102c
BS: bootblock times (exec / console): total (unknown) / 2 ms

coreboot--TIMELESS--LESSTIME--Heads-v0.2.0-1296-g139ecb8 Thu Jan  1 00:00:00 UTC 1970 romstage starting (log level: 7)...
IPMI: romstage PNP BT 0xe4
Get BMC self test result...Function Not Implemented
Initializing IPMI BMC watchdog timer
IPMI BMC watchdog initialized and started.
Initializing FSI...
Initialized FSI (chips mask: 0x01)
Building MVPDs...
starting istep 8.1
starting istep 8.2
starting istep 8.3
starting istep 8.4
starting istep 8.9
Base epsilon values read from table:
 R_T[0] = 22
 R_T[1] = 22
 R_T[2] = 103
 W_T[0] = 5
 W_T[1] = 33
Scaled epsilon values based on +20 percent guardband:
 R_T[0] = 27
 R_T[1] = 27
 R_T[2] = 124
 W_T[0] = 6
 W_T[1] = 40
starting istep 8.10
starting istep 8.11
starting istep 9.2
starting istep 9.4
starting istep 9.6
starting istep 9.7
starting istep 10.1
starting istep 10.6
starting istep 10.10
starting istep 10.12
starting istep 10.13
FFS header at 0x80060300ffff7000
PNOR base at 0x80060300fc000000
MEMD partition has ECC
MEMD is in 0x03cef200 through 0x03cfb917
I2C transfer failed to complete (0x04011f0104000000)
No memory DIMM at address 51
I2C transfer failed to complete (0x04011f0104000000)
No memory DIMM at address 52
I2C transfer failed to complete (0x04011f0104000000)
No memory DIMM at address 53
I2C transfer failed to complete (0x04011f0104000000)
No memory DIMM at address D4
I2C transfer failed to complete (0x04011f0104000000)
No memory DIMM at address D5
I2C transfer failed to complete (0x04011f0104000000)
No memory DIMM at address D6
I2C transfer failed to complete (0x04011f0104000000)
No memory DIMM at address D7
SPD @ 0x50
SPD: module type is DDR4
SPD: module part number is M393A1K43BB0-CRC    
SPD: banks 16, ranks 1, rows 16, columns 10, density 8192 Mb
SPD: device width 8 bits, bus width 64 bits
SPD: module size is 8192 MB (per channel)
starting istep 13.1
starting istep 13.2
starting istep 13.3
starting istep 13.4
starting istep 13.5
starting istep 13.6
starting istep 13.7
starting istep 13.8
starting istep 13.9
starting istep 13.10
CCS took 2 us (3 us timeout), 1 instruction(s)
CCS took 2 us (2 us timeout), 14 instruction(s)
RCD dump for I2C address 0x58:
0xf820fa30: 80 b3 40 42 30 00 00 00 02 01 00 03 cb e3 c0 0d  ..@B0...........
0xf820fa40: 00 00 39 00 00 00 00 00 00 00 07 00 00 00 00 00  ..9.............
starting istep 13.11
CCS took 2 us (7 us timeout), 2 instruction(s)
Write Leveling starting
CCS took 12 us (92 us timeout), 5 instruction(s)
Write Leveling done
Initial Pattern Write starting
CCS took 5 us (38 us timeout), 5 instruction(s)
Initial Pattern Write done
DQS alignment starting
CCS took 10 us (44 us timeout), 1 instruction(s)
DQS alignment done
Read Clock Alignment starting
CCS took 8 us (82 us timeout), 1 instruction(s)
Read Clock Alignment done
Read Centering starting
CCS took 37 us (120 us timeout), 1 instruction(s)
Read Centering done
Write Centering starting
CCS took 8961 us (11314 us timeout), 7 instruction(s)
Write Centering done
Coarse write/read starting
CCS took 5 us (24 us timeout), 1 instruction(s)
Coarse write/read done
starting istep 13.12
starting istep 13.13
starting istep 14.1
starting istep 14.2
starting istep 14.3
Initializing PEC0...
Initializing PEC1...
Initializing PEC2...
Initializing PHB0...
Initializing PHB1...
Initializing PHB2...
Initializing PHB3...
Initializing PHB4...
Initializing PHB5...
starting istep 14.4
starting istep 14.5
0xF000F = 221d104900008040
CBMEM:
IMD: root @ 0xffeff000 254 entries.
IMD: root @ 0xffefec00 62 entries.
FMAP: area COREBOOT found @ 20200 (1965568 bytes)
FFS header at 0x80060300ffff7000
PNOR base at 0x80060300fc000000
HBI partition has ECC
HBI is in 0x00426200 through 0x0175f037
CBFS: Found 'fallback/ramstage' @0x12580 size 0xcca9 in mcache @0xf8231080
BS: romstage times (exec / console): total (unknown) / 17 ms

coreboot--TIMELESS--LESSTIME--Heads-v0.2.0-1296-g139ecb8 Thu Jan  1 00:00:00 UTC 1970 ramstage starting (log level: 7)...
Enumerating buses...
Root Device scanning...
DD21, boot core: 18
FFS header at 0x80060300ffff7000
PNOR base at 0x80060300fc000000
HCODE partition has ECC
HCODE is in 0x01a82200 through 0x01b821ff
FFS header at 0x80060300ffff7000
PNOR base at 0x80060300fc000000
OCC partition has ECC
OCC is in 0x03822200 through 0x039221ff
Base epsilon values read from table:
 R_T[0] = 22
 R_T[1] = 22
 R_T[2] = 103
 W_T[0] = 5
 W_T[1] = 33
Scaled epsilon values based on +20 percent guardband:
 R_T[0] = 27
 R_T[1] = 27
 R_T[2] = 124
 W_T[0] = 6
 W_T[1] = 40
FFS header at 0x80060300ffff7000
PNOR base at 0x80060300fc000000
WOFDATA partition has ECC
WOFDATA is in 0x039ea200 through 0x03c94ca7
Matching WOF tables section not found, disabling WOF
Safe mode freq = 1833412 kHZ, voltage = 711 mv
starting istep 15.2
starting istep 15.3
starting istep 15.4
Starting PM complex...
Attempting PGPE activation...
PGPE was activated successfully
Done starting PM complex
Activating OCC...
Done activating OCC
starting istep 16.1
XIVE configured, entering dead man loop
ASSERTION ERROR: file '(filenames not available on timeless builds)', line 404
starting istep 18.11
starting istep 18.12
CPU_CLUSTER: 0 enabled
PNP: 00e4.0 enabled
scan_bus: bus Root Device finished in 3070 msecs
done
BS: BS_DEV_ENUMERATE run times (exec / console): 3065 / 6 ms
Allocating resources...
Reading resources...
CPU_CLUSTER: 0 missing read_resources
Done reading resources.
CPU_CLUSTER: 0 missing set_resources
PNP: 00e4.0 00 <- [0x00000000e4 - 0x00000000e6] size 0x00000003 gran 0x00 io
Done setting resources.
Done allocating resources.
BS: BS_DEV_RESOURCES run times (exec / console): 0 / 1 ms
Enabling resources...
done.
Initializing devices...
PNP: 00e4.0 init
IPMI: PNP BT 0xe4
Get BMC self test result...Function Not Implemented
IPMI: Found man_id 0x6cb0000, prod_id 0x1000000
IPMI: Version 2.0
PNP: 00e4.0 init finished in 37 msecs
Devices initialized
BS: BS_DEV_INIT run times (exec / console): 37 / 1 ms
Finalize devices...
Devices finalized
Writing coreboot table at 0xffed9000
 0. 0000000000000000-00000000f8207fff: RAM
 1. 00000000f8208000-00000000f820ffff: RAMSTAGE
 2. 00000000f8210000-00000000f8ffffff: RAM
 3. 00000000f9000000-00000000f929bfff: RAMSTAGE
 4. 00000000f929c000-00000000ffed8fff: RAM
 5. 00000000ffed9000-00000000ffefffff: CONFIGURATION TABLES
 6. 00000000fff00000-00000001ff3fffff: RAM
 7. 00000001ff400000-00000001ffffffff: RESERVED
FMAP: area COREBOOT found @ 20200 (1965568 bytes)
FFS header at 0x80060300ffff7000
PNOR base at 0x80060300fc000000
HBI partition has ECC
HBI is in 0x00426200 through 0x0175f037
Wrote coreboot table at: 0xffed9000, 0x214 bytes, checksum 3514
coreboot table: 556 bytes.
IMD ROOT    0. 0xffeff000 0x00001000
IMD SMALL   1. 0xffefe000 0x00001000
CONSOLE     2. 0xffede000 0x00020000
MEM INFO    3. 0xffedb000 0x000022b0
COREBOOT    4. 0xffed9000 0x00002000
IMD small region:
  IMD ROOT    0. 0xffefec00 0x00000400
  RO MCACHE   1. 0xffefea00 0x000001f0
  FMAP        2. 0xffefe920 0x000000e0
BS: BS_WRITE_TABLES run times (exec / console): 1 / 5 ms
CBFS: Found 'fallback/payload' @0x257c0 size 0x632f9 in mcache @0xffefeb84
Checking segment from ROM address 0xf8380000
Checking segment from ROM address 0xf838001c
Checking segment from ROM address 0xf8380038
Loading segment from ROM address 0xf8380000
  code (compression=1)
  New segment dstaddr 0x00000000 memsize 0x173c00 srcaddr 0xf8380054 filesize 0x632a5
Loading Segment: addr: 0x00000000 memsz: 0x0000000000173c00 filesz: 0x00000000000632a5
using LZMA
Loading segment from ROM address 0xf838001c
  BSS 0x00300000 (113776 byte)
Loading Segment: addr: 0x00300000 memsz: 0x000000000001bc70 filesz: 0x0000000000000000
it's not compressed!
Clearing Segment: addr: 0x0000000000300000 memsz: 0x000000000001bc70
Loading segment from ROM address 0xf8380038
  Entry Point 0x00002570
BS: BS_PAYLOAD_LOAD run times (exec / console): 301 / 4 ms
Jumping to boot code at 0x00002570(0xffed9000)
CBFS: Found '1-cpu.dtb' @0x1f700 size 0x24e7 in mcache @0xffefeb3c
~ # dmesg
[    0.000000] dt-cpu-ftrs: setup for ISA 3000
[    0.000000] dt-cpu-ftrs: not enabling: system-call-vectored (disabled or unsupported by kernel)
[    0.000000] dt-cpu-ftrs: final cpu/mmu features = 0x0001c86f8f5fb1a7 0x3c006041
[    0.000000] radix-mmu: Page sizes from device-tree:
[    0.000000] radix-mmu: Page size shift = 12 AP=0x0
[    0.000000] radix-mmu: Page size shift = 16 AP=0x5
[    0.000000] radix-mmu: Page size shift = 21 AP=0x1
[    0.000000] radix-mmu: Page size shift = 30 AP=0x2
[    0.000000] radix-mmu: Activating Kernel Userspace Execution Prevention
[    0.000000] radix-mmu: Activating Kernel Userspace Access Prevention
[    0.000000] radix-mmu: Mapped 0x0000000000000000-0x0000000002600000 with 2.00 MiB pages (exec)
[    0.000000] radix-mmu: Mapped 0x0000000002600000-0x0000000040000000 with 2.00 MiB pages
[    0.000000] radix-mmu: Mapped 0x0000000040000000-0x00000000c0000000 with 1.00 GiB pages
[    0.000000] radix-mmu: Mapped 0x00000000c0000000-0x00000000ffe00000 with 2.00 MiB pages
[    0.000000] radix-mmu: Mapped 0x00000000fff00000-0x0000000100000000 with 64.0 KiB pages
[    0.000000] radix-mmu: Mapped 0x0000000100000000-0x00000001c0000000 with 1.00 GiB pages
[    0.000000] radix-mmu: Mapped 0x00000001c0000000-0x00000001ff400000 with 2.00 MiB pages
[    0.000000] radix-mmu: Initializing Radix MMU
[    0.000000] Linux version 5.5.0-openpower1 (linux-talos-2_server.config@linuxboot) (gcc version 8.3.0 (GCC)) #0 SMP 1970-00-00
[    0.000000] OPAL: Found memory mapped LPC bus on chip 0
[    0.000000] ISA: Non-PCI bridge is /lpcm-opb@6030000000000/lpc@0
[    0.000000] Using PowerNV machine description
[    0.000000] printk: bootconsole [udbg0] enabled
[    0.000000] CPU maps initialized for 4 threads per core
[    0.000000]  (thread shift is 2)
[    0.000000] Allocated 3072 bytes for 16 pacas
[    0.000000] -----------------------------------------------------
[    0.000000] phys_mem_size     = 0x1ff300000
[    0.000000] dcache_bsize      = 0x80
[    0.000000] icache_bsize      = 0x80
[    0.000000] cpu_features      = 0x0001c86f8f5fb1a7
[    0.000000]   possible        = 0x0001fbefcf5fb1a7
[    0.000000]   always          = 0x00000003800081a1
[    0.000000] cpu_user_features = 0xdc0065c2 0xaee00000
[    0.000000] mmu_features      = 0xbc006041
[    0.000000] firmware_features = 0x0000000010000000
[    0.000000] vmalloc start     = 0xc008000000000000
[    0.000000] IO start          = 0xc00a000000000000
[    0.000000] vmemmap start     = 0xc00c000000000000
[    0.000000] -----------------------------------------------------
[    0.000000] numa:   NODE_DATA [mem 0x1ff1ef280-0x1ff1f3fff]
[    0.000000] rfi-flush: fallback displacement flush available
[    0.000000] rfi-flush: patched 5 locations (fallback displacement flush)
[    0.000000] link-stack-flush: software flush disabled.
[    0.000000] count-cache-flush: software flush disabled.
[    0.000000] stf-barrier: eieio barrier available
[    0.000000] stf-barrier: patched 57 entry locations (eieio barrier)
[    0.000000] stf-barrier: patched 5 exit locations (eieio barrier)
[    0.000000] Initializing IODA2 PHB (/pciex@600c3c0000000)
[    0.000000] PCI host bridge /pciex@600c3c0000000 (primary) ranges:
[    0.000000]  MEM 0x000600c000000000..0x000600c07ffeffff -> 0x0000000080000000 
[    0.000000] ioremap() called early from pnv_pci_init_ioda_phb+0x388/0xc90. Use early_ioremap() instead
[    0.000000]  MEM 0x0006000000000000..0x0006003fffffffff -> 0x0006000000000000 (M64 #1..31)
[    0.000000]  Using M64 #31 as default window
[    0.000000]   512 (511) PE's M32: 0x80000000 [segment=0x400000]
[    0.000000]                  M64: 0x4000000000 [segment=0x20000000]
[    0.000000]   Allocated bitmap for 4088 MSIs (base IRQ 0xfe000)
[    0.000000] Initializing IODA2 PHB (/pciex@600c3c0100000)
[    0.000000] PCI host bridge /pciex@600c3c0100000  ranges:
[    0.000000]  MEM 0x000600c080000000..0x000600c0fffeffff -> 0x0000000080000000 
[    0.000000] ioremap() called early from pnv_pci_init_ioda_phb+0x388/0xc90. Use early_ioremap() instead
[    0.000000]  MEM 0x0006004000000000..0x0006007fffffffff -> 0x0006004000000000 (M64 #1..15)
[    0.000000]  Using M64 #15 as default window
[    0.000000]   256 (255) PE's M32: 0x80000000 [segment=0x800000]
[    0.000000]                  M64: 0x4000000000 [segment=0x40000000]
[    0.000000]   Allocated bitmap for 2040 MSIs (base IRQ 0xfd800)
[    0.000000] Initializing IODA2 PHB (/pciex@600c3c0200000)
[    0.000000] PCI host bridge /pciex@600c3c0200000  ranges:
[    0.000000]  MEM 0x000600c100000000..0x000600c17ffeffff -> 0x0000000080000000 
[    0.000000] ioremap() called early from pnv_pci_init_ioda_phb+0x388/0xc90. Use early_ioremap() instead
[    0.000000]  MEM 0x0006008000000000..0x000600bfffffffff -> 0x0006008000000000 (M64 #1..15)
[    0.000000]  Using M64 #15 as default window
[    0.000000]   256 (255) PE's M32: 0x80000000 [segment=0x800000]
[    0.000000]                  M64: 0x4000000000 [segment=0x40000000]
[    0.000000]   Allocated bitmap for 2040 MSIs (base IRQ 0xfd000)
[    0.000000] Initializing IODA2 PHB (/pciex@600c3c0300000)
[    0.000000] PCI host bridge /pciex@600c3c0300000  ranges:
[    0.000000]  MEM 0x000600c180000000..0x000600c1fffeffff -> 0x0000000080000000 
[    0.000000] ioremap() called early from pnv_pci_init_ioda_phb+0x388/0xc90. Use early_ioremap() instead
[    0.000000]  MEM 0x0006020000000000..0x0006023fffffffff -> 0x0006020000000000 (M64 #1..31)
[    0.000000]  Using M64 #31 as default window
[    0.000000]   512 (511) PE's M32: 0x80000000 [segment=0x400000]
[    0.000000]                  M64: 0x4000000000 [segment=0x20000000]
[    0.000000]   Allocated bitmap for 4088 MSIs (base IRQ 0xfc000)
[    0.000000] Initializing IODA2 PHB (/pciex@600c3c0400000)
[    0.000000] PCI host bridge /pciex@600c3c0400000  ranges:
[    0.000000]  MEM 0x000600c200000000..0x000600c27ffeffff -> 0x0000000080000000 
[    0.000000] ioremap() called early from pnv_pci_init_ioda_phb+0x388/0xc90. Use early_ioremap() instead
[    0.000000]  MEM 0x0006024000000000..0x0006027fffffffff -> 0x0006024000000000 (M64 #1..15)
[    0.000000]  Using M64 #15 as default window
[    0.000000]   256 (255) PE's M32: 0x80000000 [segment=0x800000]
[    0.000000]                  M64: 0x4000000000 [segment=0x40000000]
[    0.000000]   Allocated bitmap for 2040 MSIs (base IRQ 0xfb800)
[    0.000000] Initializing IODA2 PHB (/pciex@600c3c0500000)
[    0.000000] PCI host bridge /pciex@600c3c0500000  ranges:
[    0.000000]  MEM 0x000600c280000000..0x000600c2fffeffff -> 0x0000000080000000 
[    0.000000] ioremap() called early from pnv_pci_init_ioda_phb+0x388/0xc90. Use early_ioremap() instead
[    0.000000]  MEM 0x0006028000000000..0x000602bfffffffff -> 0x0006028000000000 (M64 #1..15)
[    0.000000]  Using M64 #15 as default window
[    0.000000]   256 (255) PE's M32: 0x80000000 [segment=0x800000]
[    0.000000]                  M64: 0x4000000000 [segment=0x40000000]
[    0.000000]   Allocated bitmap for 2040 MSIs (base IRQ 0xfb000)
[    0.000000] OPAL nvram setup, 589824 bytes
[    0.000000] barrier-nospec: using ORI speculation barrier
[    0.000000] barrier-nospec: patched 454 locations
[    0.000000] Top of RAM: 0x1ff400000, Total RAM: 0x1ff300000
[    0.000000] Memory hole size: 1MB
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000000000000-0x00000001ff3fffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x00000000ffdfffff]
[    0.000000]   node   0: [mem 0x00000000fff00000-0x00000001ff3fffff]
[    0.000000] Zeroed struct page in unavailable ranges: 16 pages
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000001ff3fffff]
[    0.000000] On node 0 totalpages: 130864
[    0.000000]   Normal zone: 112 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 130864 pages, LIFO batch:3
[    0.000000] percpu: Embedded 2 pages/cpu s76056 r0 d55016 u131072
[    0.000000] pcpu-alloc: s76056 r0 d55016 u131072 alloc=2*65536
[    0.000000] pcpu-alloc: [0] 00 [0] 01 [0] 02 [0] 03 [0] 04 [0] 05 [0] 06 [0] 07 
[    0.000000] pcpu-alloc: [0] 08 [0] 09 [0] 10 [0] 11 [0] 12 [0] 13 [0] 14 [0] 15 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 130752
[    0.000000] Policy zone: Normal
[    0.000000] Kernel command line: console=tty0 console=hvc0 powersave=off quiet
[    0.000000] Dentry cache hash table entries: 1048576 (order: 7, 8388608 bytes, linear)
[    0.000000] Inode-cache hash table entries: 524288 (order: 6, 4194304 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 8235584K/8375296K available (13760K kernel code, 1088K rwdata, 2752K rodata, 4928K init, 1999K bss, 139712K reserved, 0K cma-reserved)
[    0.000000] random: get_random_u64 called from __kmem_cache_create+0x38/0x600 with crng_init=0
[    0.000000] SLUB: HWalign=128, Order=0-3, MinObjects=0, CPUs=16, Nodes=1
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] rcu:     RCU event tracing is enabled.
[    0.000000] rcu:     RCU restricting CPUs from NR_CPUS=2048 to nr_cpu_ids=16.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=16
[    0.000000] NR_IRQS: 512, nr_irqs: 512, preallocated irqs: 16
[    0.000000] xive: Interrupt handling initialized with native backend
[    0.000000] xive: Using priority 7 for all interrupts
[    0.000000] xive: Using 64kB queues
[    0.000000] time_init: decrementer frequency = 512.000000 MHz
[    0.000000] time_init: processor frequency   = 18446744071914.584320 MHz
[    0.000004] time_init: 56 bit decrementer (max: 7fffffffffffff)
[    0.000007] clocksource: timebase: mask: 0xffffffffffffffff max_cycles: 0x761537d007, max_idle_ns: 440795202126 ns
[    0.000010] clocksource: timebase mult[1f40000] shift[24] registered
[    0.000018] clockevent: decrementer mult[83126f] shift[24] cpu[0]
[    0.000076] Console: colour dummy device 80x25
[    0.000081] printk: console [tty0] enabled
[    0.000083] printk: console [hvc0] enabled
[    0.000085] printk: bootconsole [udbg0] disabled
[    0.000119] pid_max: default: 32768 minimum: 301
[    0.000184] LSM: Security Framework initializing
[    0.000218] Mount-cache hash table entries: 16384 (order: 1, 131072 bytes, linear)
[    0.000229] Mountpoint-cache hash table entries: 16384 (order: 1, 131072 bytes, linear)
[    0.000819] EEH: PowerNV platform initialized
[    0.000824] POWER9 performance monitor hardware support registered
[    0.000856] rcu: Hierarchical SRCU implementation.
[    0.001080] smp: Bringing up secondary CPUs ...
[    0.005686] smp: Brought up 1 node, 16 CPUs
[    0.005688] numa: Node 0 CPUs: 0-15
[    0.005691] Using shared cache scheduler topology
[    0.006595] devtmpfs: initialized
[    0.013685] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.013691] futex hash table entries: 4096 (order: 3, 524288 bytes, linear)
[    0.013850] xor: measuring software checksum speed
[    0.110059]    8regs     :  5241.600 MB/sec
[    0.210093]    8regs_prefetch:  4243.200 MB/sec
[    0.310114]    32regs    :  5344.000 MB/sec
[    0.410144]    32regs_prefetch:  4160.000 MB/sec
[    0.510175]    altivec   :  6944.000 MB/sec
[    0.510177] xor: using function: altivec (6944.000 MB/sec)
[    0.510282] NET: Registered protocol family 16
[    0.510648] cpuidle: using governor menu
[    0.515170] PCI: Probing PCI hardware
[    0.515207] PCI host bridge to bus 0000:00
[    0.515213] pci_bus 0000:00: root bus resource [mem 0x600c000000000-0x600c07ffeffff] (bus address [0x80000000-0xfffeffff])
[    0.515217] pci_bus 0000:00: root bus resource [mem 0x6000000000000-0x6003fbfffffff 64bit pref]
[    0.515220] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.515224] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to ff
[    0.515259] pci 0000:00:00.0: [1014:04c1] type 01 class 0x060400
[    0.515483] pci 0000:00:00.0: PME# supported from D0 D3hot D3cold
[    0.521424] pci 0000:00:00.0: PCI bridge to [bus 01-ff]
[    0.521464] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to ff
[    0.521495] PCI host bridge to bus 0001:00
[    0.521500] pci_bus 0001:00: root bus resource [mem 0x600c080000000-0x600c0fffeffff] (bus address [0x80000000-0xfffeffff])
[    0.521502] pci_bus 0001:00: root bus resource [mem 0x6004000000000-0x6007f7fffffff 64bit pref]
[    0.521505] pci_bus 0001:00: root bus resource [bus 00-ff]
[    0.521508] pci_bus 0001:00: busn_res: [bus 00-ff] end is updated to ff
[    0.521535] pci 0001:00:00.0: [1014:04c1] type 01 class 0x060400
[    0.521748] pci 0001:00:00.0: PME# supported from D0 D3hot D3cold
[    0.527664] pci 0001:00:00.0: PCI bridge to [bus 01-ff]
[    0.527703] pci_bus 0001:00: busn_res: [bus 00-ff] end is updated to ff
[    0.527734] PCI host bridge to bus 0002:00
[    0.527738] pci_bus 0002:00: root bus resource [mem 0x600c100000000-0x600c17ffeffff] (bus address [0x80000000-0xfffeffff])
[    0.527741] pci_bus 0002:00: root bus resource [mem 0x6008000000000-0x600bf7fffffff 64bit pref]
[    0.527743] pci_bus 0002:00: root bus resource [bus 00-ff]
[    0.527746] pci_bus 0002:00: busn_res: [bus 00-ff] end is updated to ff
[    0.527773] pci 0002:00:00.0: [1014:04c1] type 01 class 0x060400
[    0.527987] pci 0002:00:00.0: PME# supported from D0 D3hot D3cold
[    0.533891] pci 0002:00:00.0: PCI bridge to [bus 01-ff]
[    0.533930] pci_bus 0002:00: busn_res: [bus 00-ff] end is updated to ff
[    0.533960] PCI host bridge to bus 0003:00
[    0.533964] pci_bus 0003:00: root bus resource [mem 0x600c180000000-0x600c1fffeffff] (bus address [0x80000000-0xfffeffff])
[    0.533967] pci_bus 0003:00: root bus resource [mem 0x6020000000000-0x6023fbfffffff 64bit pref]
[    0.533970] pci_bus 0003:00: root bus resource [bus 00-ff]
[    0.533973] pci_bus 0003:00: busn_res: [bus 00-ff] end is updated to ff
[    0.533999] pci 0003:00:00.0: [1014:04c1] type 01 class 0x060400
[    0.534211] pci 0003:00:00.0: PME# supported from D0 D3hot D3cold
[    0.537276] pci 0003:01:00.0: [104c:8241] type 00 class 0x0c0330
[    0.537333] pci 0003:01:00.0: reg 0x10: [mem 0x00000000-0x0000ffff 64bit]
[    0.537359] pci 0003:01:00.0: reg 0x18: [mem 0x00000000-0x00001fff 64bit]
[    0.537428] pci 0003:01:00.0: BAR2 [mem size 0x00002000 64bit]: requesting alignment to 0x10000
[    0.537549] pci 0003:01:00.0: supports D1 D2
[    0.537552] pci 0003:01:00.0: PME# supported from D0 D1 D2 D3hot
[    0.540580] pci 0003:00:00.0: PCI bridge to [bus 01]
[    0.540657] pci_bus 0003:00: busn_res: [bus 00-ff] end is updated to 01
[    0.540687] PCI host bridge to bus 0004:00
[    0.540691] pci_bus 0004:00: root bus resource [mem 0x600c200000000-0x600c27ffeffff] (bus address [0x80000000-0xfffeffff])
[    0.540694] pci_bus 0004:00: root bus resource [mem 0x6024000000000-0x6027f7fffffff 64bit pref]
[    0.540697] pci_bus 0004:00: root bus resource [bus 00-ff]
[    0.540700] pci_bus 0004:00: busn_res: [bus 00-ff] end is updated to ff
[    0.540726] pci 0004:00:00.0: [1014:04c1] type 01 class 0x060400
[    0.540938] pci 0004:00:00.0: PME# supported from D0 D3hot D3cold
[    0.544015] pci 0004:01:00.0: [14e4:1657] type 00 class 0x020000
[    0.544080] pci 0004:01:00.0: reg 0x10: [mem 0x00000000-0x0000ffff 64bit pref]
[    0.544106] pci 0004:01:00.0: reg 0x18: [mem 0x00000000-0x0000ffff 64bit pref]
[    0.544131] pci 0004:01:00.0: reg 0x20: [mem 0x00000000-0x0000ffff 64bit pref]
[    0.544148] pci 0004:01:00.0: reg 0x30: [mem 0x00000000-0x000007ff pref]
[    0.544179] pci 0004:01:00.0: BAR6 [mem size 0x00000800 pref]: requesting alignment to 0x10000
[    0.544364] pci 0004:01:00.0: PME# supported from D0 D3hot D3cold
[    0.544510] pci 0004:01:00.1: [14e4:1657] type 00 class 0x020000
[    0.544576] pci 0004:01:00.1: reg 0x10: [mem 0x00000000-0x0000ffff 64bit pref]
[    0.544602] pci 0004:01:00.1: reg 0x18: [mem 0x00000000-0x0000ffff 64bit pref]
[    0.544628] pci 0004:01:00.1: reg 0x20: [mem 0x00000000-0x0000ffff 64bit pref]
[    0.544644] pci 0004:01:00.1: reg 0x30: [mem 0x00000000-0x000007ff pref]
[    0.544674] pci 0004:01:00.1: BAR6 [mem size 0x00000800 pref]: requesting alignment to 0x10000
[    0.544861] pci 0004:01:00.1: PME# supported from D0 D3hot D3cold
[    0.547854] pci 0004:00:00.0: PCI bridge to [bus 01]
[    0.547948] pci_bus 0004:00: busn_res: [bus 00-ff] end is updated to 01
[    0.547979] PCI host bridge to bus 0005:00
[    0.547983] pci_bus 0005:00: root bus resource [mem 0x600c280000000-0x600c2fffeffff] (bus address [0x80000000-0xfffeffff])
[    0.547986] pci_bus 0005:00: root bus resource [mem 0x6028000000000-0x602bf7fffffff 64bit pref]
[    0.547989] pci_bus 0005:00: root bus resource [bus 00-ff]
[    0.547992] pci_bus 0005:00: busn_res: [bus 00-ff] end is updated to ff
[    0.548018] pci 0005:00:00.0: [1014:04c1] type 01 class 0x060400
[    0.548231] pci 0005:00:00.0: PME# supported from D0 D3hot D3cold
[    0.551295] pci 0005:01:00.0: [1a03:1150] type 01 class 0x060400
[    0.551426] pci 0005:01:00.0: enabling Extended Tags
[    0.551578] pci 0005:01:00.0: supports D1 D2
[    0.551581] pci 0005:01:00.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.554592] pci 0005:00:00.0: PCI bridge to [bus 01-02]
[    0.554721] pci_bus 0005:02: extended config space not accessible
[    0.554772] pci 0005:02:00.0: [1a03:2000] type 00 class 0x030000
[    0.554806] pci 0005:02:00.0: reg 0x10: [mem 0x00000000-0x00ffffff]
[    0.554822] pci 0005:02:00.0: reg 0x14: [mem 0x00000000-0x0001ffff]
[    0.554838] pci 0005:02:00.0: reg 0x18: [io  0x0000-0x007f]
[    0.554984] pci 0005:02:00.0: supports D1 D2
[    0.554987] pci 0005:02:00.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.557953] pci 0005:01:00.0: PCI bridge to [bus 02]
[    0.558019] pci_bus 0005:00: busn_res: [bus 00-ff] end is updated to 02
[    0.558034] pci 0000:00     : [PE# 1fe] Secondary bus 0x0000000000000000 associated with PE#1fe
[    0.558272] pci 0000:00:00.0: PCI bridge to [bus 01-ff]
[    0.558294] pci_bus 0000:00: resource 4 [mem 0x600c000000000-0x600c07ffeffff]
[    0.558297] pci_bus 0000:00: resource 5 [mem 0x6000000000000-0x6003fbfffffff 64bit pref]
[    0.558302] pci 0001:00     : [PE# fe] Secondary bus 0x0000000000000000 associated with PE#fe
[    0.558538] pci 0001:00:00.0: PCI bridge to [bus 01-ff]
[    0.558559] pci_bus 0001:00: resource 4 [mem 0x600c080000000-0x600c0fffeffff]
[    0.558562] pci_bus 0001:00: resource 5 [mem 0x6004000000000-0x6007f7fffffff 64bit pref]
[    0.558566] pci 0002:00     : [PE# fe] Secondary bus 0x0000000000000000 associated with PE#fe
[    0.558801] pci 0002:00:00.0: PCI bridge to [bus 01-ff]
[    0.558822] pci_bus 0002:00: resource 4 [mem 0x600c100000000-0x600c17ffeffff]
[    0.558825] pci_bus 0002:00: resource 5 [mem 0x6008000000000-0x600bf7fffffff 64bit pref]
[    0.558833] pci 0003:00:00.0: BAR 8: assigned [mem 0x600c180000000-0x600c1803fffff]
[    0.558837] pci 0003:01:00.0: BAR 0: assigned [mem 0x600c180000000-0x600c18000ffff 64bit]
[    0.558859] pci 0003:01:00.0: BAR 2: assigned [mem 0x600c180010000-0x600c180011fff 64bit]
[    0.558880] pci 0003:00     : [PE# 1fe] Secondary bus 0x0000000000000000 associated with PE#1fe
[    0.559120] pci 0003:01     : [PE# 1fd] Secondary bus 0x0000000000000001 associated with PE#1fd
[    0.559360] pci 0003:01     : [PE# 1fd] Setting up 32-bit TCE table at 0..80000000
[    0.560365] IOMMU table initialized, virtual merging enabled
[    0.560369] pci 0003:01     : [PE# 1fd] Setting up window#0 0..ffffffff pg=10000
[    0.560376] pci 0003:01     : [PE# 1fd] Enabling 64-bit DMA bypass
[    0.560379] pci 0003:00:00.0: PCI bridge to [bus 01]
[    0.560389] pci 0003:00:00.0:   bridge window [mem 0x600c180000000-0x600c1ffefffff]
[    0.560403] pci_bus 0003:00: resource 4 [mem 0x600c180000000-0x600c1fffeffff]
[    0.560406] pci_bus 0003:00: resource 5 [mem 0x6020000000000-0x6023fbfffffff 64bit pref]
[    0.560409] pci_bus 0003:01: resource 1 [mem 0x600c180000000-0x600c1ffefffff]
[    0.560415] pci 0004:00:00.0: BAR 9: assigned [mem 0x6024000000000-0x602403fffffff 64bit pref]
[    0.560418] pci 0004:00:00.0: BAR 8: assigned [mem 0x600c200000000-0x600c2007fffff]
[    0.560423] pci 0004:01:00.0: BAR 0: assigned [mem 0x6024000000000-0x602400000ffff 64bit pref]
[    0.560444] pci 0004:01:00.0: BAR 2: assigned [mem 0x6024000010000-0x602400001ffff 64bit pref]
[    0.560465] pci 0004:01:00.0: BAR 4: assigned [mem 0x6024000020000-0x602400002ffff 64bit pref]
[    0.560485] pci 0004:01:00.0: BAR 6: assigned [mem 0x600c200000000-0x600c2000007ff pref]
[    0.560488] pci 0004:01:00.1: BAR 0: assigned [mem 0x6024000030000-0x602400003ffff 64bit pref]
[    0.560509] pci 0004:01:00.1: BAR 2: assigned [mem 0x6024000040000-0x602400004ffff 64bit pref]
[    0.560530] pci 0004:01:00.1: BAR 4: assigned [mem 0x6024000050000-0x602400005ffff 64bit pref]
[    0.560550] pci 0004:01:00.1: BAR 6: assigned [mem 0x600c200010000-0x600c2000107ff pref]
[    0.560554] pci 0004:00     : [PE# fe] Secondary bus 0x0000000000000000 associated with PE#fe
[    0.560802] pci 0004:01     : [PE# 00] Secondary bus 0x0000000000000001 associated with PE#0
[    0.561041] pci 0004:01     : [PE# 00] Setting up 32-bit TCE table at 0..80000000
[    0.562043] pci 0004:01     : [PE# 00] Setting up window#0 0..ffffffff pg=10000
[    0.562048] pci 0004:01     : [PE# 00] Enabling 64-bit DMA bypass
[    0.562052] pci 0004:00:00.0: PCI bridge to [bus 01]
[    0.562061] pci 0004:00:00.0:   bridge window [mem 0x600c200000000-0x600c27fefffff]
[    0.562067] pci 0004:00:00.0:   bridge window [mem 0x6024000000000-0x6027f7ff0ffff 64bit pref]
[    0.562078] pci_bus 0004:00: resource 4 [mem 0x600c200000000-0x600c27ffeffff]
[    0.562081] pci_bus 0004:00: resource 5 [mem 0x6024000000000-0x6027f7fffffff 64bit pref]
[    0.562084] pci_bus 0004:01: resource 1 [mem 0x600c200000000-0x600c27fefffff]
[    0.562087] pci_bus 0004:01: resource 2 [mem 0x6024000000000-0x6027f7ff0ffff 64bit pref]
[    0.562093] pci 0005:00:00.0: BAR 8: assigned [mem 0x600c280000000-0x600c2817fffff]
[    0.562096] pci 0005:00:00.0: BAR 7: no space for [io  size 0x1000]
[    0.562099] pci 0005:00:00.0: BAR 7: failed to assign [io  size 0x1000]
[    0.562102] pci 0005:01:00.0: BAR 8: assigned [mem 0x600c280000000-0x600c2817fffff]
[    0.562105] pci 0005:01:00.0: BAR 7: no space for [io  size 0x1000]
[    0.562108] pci 0005:01:00.0: BAR 7: failed to assign [io  size 0x1000]
[    0.562112] pci 0005:02:00.0: BAR 0: assigned [mem 0x600c280000000-0x600c280ffffff]
[    0.562120] pci 0005:02:00.0: BAR 1: assigned [mem 0x600c281000000-0x600c28101ffff]
[    0.562128] pci 0005:02:00.0: BAR 2: no space for [io  size 0x0080]
[    0.562131] pci 0005:02:00.0: BAR 2: failed to assign [io  size 0x0080]
[    0.562134] pci 0005:00     : [PE# fe] Secondary bus 0x0000000000000000 associated with PE#fe
[    0.562373] pci 0005:02     : [PE# fd] Secondary bus 0x0000000000000002..0x0000000000000002 associated with PE#fd
[    0.562613] pci 0005:02     : [PE# fd] Setting up 32-bit TCE table at 0..80000000
[    0.563618] pci 0005:02     : [PE# fd] Setting up window#0 0..ffffffff pg=10000
[    0.563623] pci 0005:02     : [PE# fd] Enabling 64-bit DMA bypass
[    0.563627] pci 0005:01:00.0: PCI bridge to [bus 02]
[    0.563636] pci 0005:01:00.0:   bridge window [mem 0x600c280000000-0x600c2ffefffff]
[    0.563655] pci 0005:01     : [PE# fc] Secondary bus 0x0000000000000001 associated with PE#fc
[    0.563893] pci 0005:00:00.0: PCI bridge to [bus 01-02]
[    0.563902] pci 0005:00:00.0:   bridge window [mem 0x600c280000000-0x600c2ffefffff]
[    0.563916] pci_bus 0005:00: Some PCI device resources are unassigned, try booting with pci=realloc
[    0.563919] pci_bus 0005:00: resource 4 [mem 0x600c280000000-0x600c2fffeffff]
[    0.563922] pci_bus 0005:00: resource 5 [mem 0x6028000000000-0x602bf7fffffff 64bit pref]
[    0.563925] pci_bus 0005:01: resource 1 [mem 0x600c280000000-0x600c2ffefffff]
[    0.563927] pci_bus 0005:02: resource 1 [mem 0x600c280000000-0x600c2ffefffff]
[    0.564581] pci 0003:01:00.0: Adding to iommu group 0
[    0.564595] pci 0004:01:00.0: Adding to iommu group 1
[    0.564600] pci 0004:01:00.1: Adding to iommu group 1
[    0.564613] pci 0005:02:00.0: Adding to iommu group 2
[    0.564649] pci 0003:00:00.0: enabling device (0105 -> 0107)
[    0.564664] pci 0004:00:00.0: enabling device (0105 -> 0107)
[    0.564677] pci 0005:00:00.0: enabling device (0105 -> 0107)
[    0.564693] pci 0005:01:00.0: enabling device (0145 -> 0147)
[    0.564705] EEH: Capable adapter found: recovery enabled.
[    0.564771] PCI: Probing PCI hardware done
[    0.740237] raid6: vpermxor8 gen()  5105 MB/s
[    0.910287] raid6: vpermxor4 gen()  5163 MB/s
[    1.080333] raid6: vpermxor2 gen()  4430 MB/s
[    1.250382] raid6: vpermxor1 gen()  3070 MB/s
[    1.420439] raid6: altivecx8 gen()  4412 MB/s
[    1.590478] raid6: altivecx4 gen()  5044 MB/s
[    1.760530] raid6: altivecx2 gen()  4428 MB/s
[    1.930577] raid6: altivecx1 gen()  3071 MB/s
[    2.100646] raid6: int64x8  gen()  2258 MB/s
[    2.270686] raid6: int64x8  xor()   837 MB/s
[    2.440721] raid6: int64x4  gen()  3049 MB/s
[    2.610799] raid6: int64x4  xor()   974 MB/s
[    2.780821] raid6: int64x2  gen()  2694 MB/s
[    2.950868] raid6: int64x2  xor()   825 MB/s
[    3.120925] raid6: int64x1  gen()  1683 MB/s
[    3.291016] raid6: int64x1  xor()   526 MB/s
[    3.291018] raid6: using algorithm vpermxor4 gen() 5163 MB/s
[    3.291019] raid6: using intx1 recovery algorithm
[    3.291115] iommu: Default domain type: Translated 
[    3.291201] pci 0005:02:00.0: vgaarb: VGA device added: decodes=io+mem,owns=none,locks=none
[    3.291204] pci 0005:02:00.0: vgaarb: bridge control possible
[    3.291209] pci 0005:02:00.0: vgaarb: setting as boot device (VGA legacy resources not available)
[    3.291210] vgaarb: loaded
[    3.291360] SCSI subsystem initialized
[    3.291423] libata version 3.00 loaded.
[    3.291455] usbcore: registered new interface driver usbfs
[    3.291469] usbcore: registered new interface driver hub
[    3.291520] usbcore: registered new device driver usb
[    3.291776] clocksource: Switched to clocksource timebase
[    3.291924] VFS: Disk quotas dquot_6.6.0
[    3.291973] VFS: Dquot-cache hash table entries: 8192 (order 0, 65536 bytes)
[    3.293802] NET: Registered protocol family 2
[    3.293970] tcp_listen_portaddr_hash hash table entries: 4096 (order: 0, 65536 bytes, linear)
[    3.293997] TCP established hash table entries: 65536 (order: 3, 524288 bytes, linear)
[    3.294250] TCP bind hash table entries: 65536 (order: 4, 1048576 bytes, linear)
[    3.294533] TCP: Hash tables configured (established 65536 bind 65536)
[    3.294582] UDP hash table entries: 4096 (order: 1, 131072 bytes, linear)
[    3.294629] UDP-Lite hash table entries: 4096 (order: 1, 131072 bytes, linear)
[    3.294731] NET: Registered protocol family 1
[    3.294868] RPC: Registered named UNIX socket transport module.
[    3.294869] RPC: Registered udp transport module.
[    3.294870] RPC: Registered tcp transport module.
[    3.294871] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    3.294903] pci 0003:01:00.0: enabling device (0140 -> 0142)
[    3.294959] PCI: CLS 0 bytes, default 128
[    4.268669] Initialise system trusted keyrings
[    4.268722] workingset: timestamp_bits=54 max_order=17 bucket_order=0
[    4.271647] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    4.271922] NFS: Registering the id_resolver key type
[    4.271930] Key type id_resolver registered
[    4.271931] Key type id_legacy registered
[    4.271936] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    4.271947] jffs2: version 2.2. (NAND) © 2001-2006 Red Hat, Inc.
[    4.272112] JFS: nTxBlock = 4021, nTxLock = 32170
[    4.273160] SGI XFS with ACLs, security attributes, realtime, quota, fatal assert, debug enabled
[    4.273692] F2FS not supported on PAGE_SIZE(65536) != 4096
[    4.273773] Key type asymmetric registered
[    4.273775] Asymmetric key parser 'x509' registered
[    4.273786] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[    4.274142] IPMI message handler: version 39.2
[    4.274155] ipmi device interface
[    4.287839] ipmi-powernv ibm,opal:ipmi: IPMI message handler: The GUID response from the BMC was too short, it was 1 but should have been 17.  Assuming GUID is not available.
[    4.303261] ipmi-powernv ibm,opal:ipmi: IPMI message handler: Found new BMC (man_id: 0x00cb06, prod_id: 0x0001, dev_id: 0x00)
[    4.404093] hvc0: raw protocol on /ibm,opal/consoles/serial@0 (boot console)
[    4.404098] hvc0: No interrupts property, using OPAL event
[    4.404361] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[    4.404628] Non-volatile memory driver v1.3
[    4.404724] [drm] radeon kernel modesetting enabled.
[    4.404823] ast 0005:02:00.0: enabling device (0140 -> 0142)
[    4.404890] [drm] platform has no IO space, trying MMIO
[    4.404893] [drm] VGA not enabled on entry, requesting chip POST
[    4.404894] [drm] Using device-tree for configuration
[    4.404896] [drm] AST 2500 detected
[    4.404898] [drm] Analog VGA only
[    4.404930] [drm] dram MCLK=800 Mhz type=7 bus_width=16 size=01000000
[    4.405014] [TTM] Zone  kernel: Available graphics memory: 4117792 KiB
[    4.405015] [TTM] Zone   dma32: Available graphics memory: 2097152 KiB
[    4.405017] [TTM] Initializing pool allocator
[    4.539290] mm/pgtable-generic.c:50: bad pmd c00600c2800001be.
[    4.539292] mm/pgtable-generic.c:50: bad pmd c00600c2802001be.
[    4.539293] mm/pgtable-generic.c:50: bad pmd c00600c2804001be.
[    4.540810] Console: switching to colour frame buffer device 240x67
[    4.553652] ast 0005:02:00.0: fb0: astdrmfb frame buffer device
[    4.588111] [drm] Initialized ast 0.1.0 20120228 for 0005:02:00.0 on minor 0
[    4.590488] brd: module loaded
[    4.593789] loop: module loaded
[    4.593808] st: Version 20160209, fixed bufsize 32768, s/g segs 256
[    4.594258] 5 fixed-partitions partitions found on MTD device flash@0
[    4.594260] Creating 5 MTD partitions on "flash@0":
[    4.594263] 0x000000000000-0x000004000000 : "PNOR"
[    4.594788] 0x0000022a1000-0x000002e5a158 : "BOOTKERNEL"
[    4.595278] 0x000003944000-0x000003946000 : "VERSION"
[    4.595763] 0x000003989000-0x0000039c9000 : "IMA_CATALOG"
[    4.596248] 0x000003e10000-0x000003ff0000 : "BOOTKERNFW"
[    4.596825] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    4.596829] ohci-pci: OHCI PCI platform driver
[    4.621823] rtc-opal opal-rtc: registered as rtc0
[    4.621840] i2c /dev entries driver
[    4.624085] powernv-cpufreq: cpufreq pstate min 0x76 nominal 0x4e max 0x0
[    4.624086] powernv-cpufreq: Workload Optimized Frequency is enabled in the platform
[    4.624444] powernv-cpufreq: Frequency Control disabled from OS
[    4.624446] powernv-cpufreq: PMSR = 4e4e763080000000
[    4.624447] powernv-cpufreq: CPU Frequency could be throttled
[    4.624525] ipip: IPv4 and MPLS over IPv4 tunneling driver
[    4.624694] NET: Registered protocol family 17
[    4.624753] NET: Registered protocol family 33
[    4.624756] Key type rxrpc registered
[    4.624757] Key type rxrpc_s registered
[    4.624772] Key type dns_resolver registered
[    4.624820] drmem: No dynamic reconfiguration memory found
[    4.625151] registered taskstats version 1
[    4.625153] Loading compiled-in X.509 certificates
[    4.627061] Loaded X.509 cert 'Build time autogenerated kernel key: de4e33eea2df7eaa7a7b1527e668d2f77cca4860'
[    4.627066] kAFS: Red Hat AFS client v0.1 registering.
[    4.801785] kAFS: failed to register: -97
[    4.802355] Btrfs loaded, crc32c=crc32c-generic
[    4.802657] Key type encrypted registered
[    4.802683] ima: No TPM chip found, activating TPM-bypass!
[    4.802686] ima: Allocated hash algorithm: sha1
[    4.802700] ima: No architecture policies found
[    4.802717] evm: Initialising EVM extended attributes:
[    4.802718] evm: security.capability
[    4.802719] evm: HMAC attrs: 0x1
[    4.831807] rtc-opal opal-rtc: setting system clock to 2022-11-23T15:13:56 UTC (1669216436)
[    4.832741] Freeing unused kernel memory: 4928K
[    4.921811] Run /init as init process
[    4.923401] [U] hello world
[    5.393715] random: fast init done
[    6.600766] ehci_hcd: module verification failed: signature and/or required key missing - tainting kernel
[    6.601018] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    6.601019] Warning! ehci_hcd should always be loaded before uhci_hcd and ohci_hcd, not after
[    6.603486] ehci-pci: EHCI PCI platform driver
[    6.610687] xhci_hcd 0003:01:00.0: xHCI Host Controller
[    6.610749] xhci_hcd 0003:01:00.0: new USB bus registered, assigned bus number 1
[    6.610869] xhci_hcd 0003:01:00.0: hcc params 0x0270f06d hci version 0x96 quirks 0x0000000004000000
[    6.611489] hub 1-0:1.0: USB hub found
[    6.611504] hub 1-0:1.0: 4 ports detected
[    6.611657] xhci_hcd 0003:01:00.0: xHCI Host Controller
[    6.611695] xhci_hcd 0003:01:00.0: new USB bus registered, assigned bus number 2
[    6.611700] xhci_hcd 0003:01:00.0: Host supports USB 3.0 SuperSpeed
[    6.611728] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
[    6.611906] hub 2-0:1.0: USB hub found
[    6.611920] hub 2-0:1.0: 4 ports detected
[    6.981784] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[    7.028221] hub 1-1:1.0: USB hub found
[    7.028822] hub 1-1:1.0: 4 ports detected
[    7.191784] usb 1-2: new high-speed USB device number 3 using xhci_hcd
[    7.371783] usb 1-3: new high-speed USB device number 4 using xhci_hcd
[    7.420066] hub 1-3:1.0: USB hub found
[    7.420417] hub 1-3:1.0: 5 ports detected
[    7.501785] usb 1-1.1: new low-speed USB device number 5 using xhci_hcd
[    7.781781] usb 1-4: new high-speed USB device number 6 using xhci_hcd
[    7.828418] hub 1-4:1.0: USB hub found
[    7.829019] hub 1-4:1.0: 4 ports detected
[    7.911780] usb 1-3.1: new high-speed USB device number 7 using xhci_hcd
[    8.041782] usb 1-1.3: new low-speed USB device number 8 using xhci_hcd
[    8.622897] input: LOGITECH G110 G-keys Keypad as /devices/pci0003:00/0003:00:00.0/0003:01:00.0/usb1/1-1/1-1.1/1-1.1:1.0/0003:046D:C22B.0001/input/input0
[    8.691872] hid-generic 0003:046D:C22B.0001: input,hiddev96: USB HID v1.00 Keypad [LOGITECH G110 G-keys] on usb-0003:01:00.0-1.1/input0
[    8.691899] usbhid 1-1.1:1.1: couldn't find an input interrupt endpoint
[    8.693494] input: OpenBMC virtual_input as /devices/pci0003:00/0003:00:00.0/0003:01:00.0/usb1/1-3/1-3.1/1-3.1:1.0/0003:1D6B:0104.0002/input/input2
[    8.761816] hid-generic 0003:1D6B:0104.0002: input: USB HID v1.01 Keyboard [OpenBMC virtual_input] on usb-0003:01:00.0-3.1/input0
[    8.763212] input: OpenBMC virtual_input as /devices/pci0003:00/0003:00:00.0/0003:01:00.0/usb1/1-3/1-3.1/1-3.1:1.1/0003:1D6B:0104.0003/input/input3
[    8.763249] hid-generic 0003:1D6B:0104.0003: input: USB HID v1.01 Mouse [OpenBMC virtual_input] on usb-0003:01:00.0-3.1/input1
[    8.766890] input: Gaming Keyboard G110 as /devices/pci0003:00/0003:00:00.0/0003:01:00.0/usb1/1-1/1-1.3/1-1.3:1.0/0003:046D:C22A.0004/input/input4
[    8.831823] hid-generic 0003:046D:C22A.0004: input: USB HID v1.10 Keyboard [Gaming Keyboard G110] on usb-0003:01:00.0-1.3/input0
[    8.836155] input: Gaming Keyboard G110 Consumer Control as /devices/pci0003:00/0003:00:00.0/0003:01:00.0/usb1/1-1/1-1.3/1-1.3:1.1/0003:046D:C22A.0005/input/input5
[    8.901855] hid-generic 0003:046D:C22A.0005: input,hiddev97: USB HID v1.10 Device [Gaming Keyboard G110] on usb-0003:01:00.0-1.3/input1
[    8.901887] usbcore: registered new interface driver usbhid
[    8.901888] usbhid: USB HID core driver
[  466.176009] random: crng init done

Solutions you've tried

None

krystian-hebel commented 1 year ago

Interesting find: if Skiboot fails to load kernel, it somehow tells BMC to drop mounted PNOR image and get back to real flash device. After that, mboxctl --lpc-state still reports LPC Bus Maps: BMC Memory. This makes debugging much harder, and may explain some of the strange behaviour we've seen. It is possible that other errors can also somehow change PNOR device.

tlaurion commented 1 year ago

I am not sure if another issue should be opened or this one bonified with more logs already posted at https://github.com/osresearch/heads/pull/1313#issuecomment-1492333112 ?

miczyg1 commented 1 year ago

Continuation here: https://github.com/Dasharo/dasharo-issues/issues/415

Closing