<div dir="ltr">Is anyone interested in boot time improvements?  I recently looked at my system just to get a baseline, and it seems like there's some low hanging fruit to be gained that could give us some significant speedups on the boot process.  Is anyone looking at this kind of thing already?<div><br></div><div>My quick analysis from timing the serial log is below.  Total time to a login is 95 seconds, which it seems like we could improve quite a bit.</div><div><br></div><div>First serial line printed to u-boot "hit any key" startup init is 3 seconds<br>3 seconds of countdown for "hit any key to stop autoboot".  I'm sure u-boot has a way to disable that, so there's 3 seconds right there.<br>Decompressing the dtb, initramfs, and kernel images is seconds 5-14.  If there's a way to optimize that better that u-bmc has implemented ahead of us, that seems like an area for improvement that we could pull in.<br>Kernel starts at ~20 seconds, then 3.5 seconds of dead air... not sure what's going on there.<br>A big 17 second pause between these two lines.  Not sure what that's about.<br>[25.443908 0.001845] [    2.294952] Driver for 1-wire Dallas network protocol.<br>[42.321590 16.877682] [   19.191143] SPI driver bmp280 has no spi_device_id for bosch,bmp085<br>6. Init script runs at 46 seconds, so we're getting into the realm of "systemd problems" at ~50% of our boot time.<br>7. 71 seconds in, all the user-facing sockets are up, and the NIC comes up;  So far as a user is concerned, the bmc is "up" (kinda), given that the user facing services are socket activated.<br>8. 71-95, launching all the various backend system services.<br>9. 95 seconds in, services have finished launching, and a login prompt is presented.<br></div><div><br></div><div>```</div><div>~/grabserial master ❯ sudo python3 grabserial -v -d /dev/ttyUSB3 -b 115200 -f -w 8 -p N -s 1 -e 150 -t -m "DRAM Init-V12-DDR4"<br>Opening serial port /dev/ttyUSB3<br>115200:8N1:xonxoff=0:rtscts=0:rts=1:dtr=1<br>Program set to end in 150 seconds<br>Printing timing information for each line<br>Using pattern 'DRAM Init-V12-DDR4' to set base time<br>Use Control-C to stop...<br>[0.000001 0.000001] <br>[0.000531 0.000530] DRAM Init-V12-DDR4<br>[0.016045 0.016045] 0abc1-4Gb-Done<br>[0.271901 0.255857] Read margin-DL:0.3647/DH:0.3745 CK (min:0.30)<br>[1.971260 1.699359] <br>[1.971447 0.000186] <br>[1.971544 0.000097] U-Boot 2016.07 (Jun 10 2020 - 10:12:49 +0000)<br>[1.973912 0.002369] <br>[1.973960 0.000047]        Watchdog enabled<br>[1.974791 0.000832] DRAM:  496 MiB<br>[2.850693 0.875902] Flash: 128 MiB<br>[2.962520 0.111827] In:    serial<br>[3.000751 0.038230] Out:   serial<br>[3.001596 0.000845] Err:   serial<br>[3.002095 0.000499] Net:   MAC0 : RMII/NCSI<br>[3.002880 0.000785] MAC1 : RGMII<br>[3.003157 0.000277] FTGMAC100#0<br>[3.003447 0.000290] Error: FTGMAC100#0 address not set.<br>[3.004289 0.000842] , FTGMAC100#1<br>[3.004628 0.000339] Error: FTGMAC100#1 address not set.<br>[3.005417 0.000789] <br>[3.005442 0.000025] Hit any key to stop autoboot:  0 <br>[5.037966 2.032524] ## Loading kernel from FIT Image at 20080000 ...<br>[5.039975 0.002010]    Using 'conf-aspeed-bmc-tyan-s7106.dtb' configuration<br>[5.041790 0.001814]    Trying 'kernel-1' kernel subimage<br>[5.042722 0.000932]      Description:  Linux kernel<br>[5.043504 0.000782]      Type:         Kernel Image<br>[5.044270 0.000766]      Compression:  uncompressed<br>[5.045040 0.000770]      Data Start:   0x20080128<br>[5.045763 0.000723]      Data Size:    3168888 Bytes = 3 MiB<br>[5.046716 0.000954]      Architecture: ARM<br>[5.047274 0.000558]      OS:           Linux<br>[5.047869 0.000595]      Load Address: 0x80001000<br>[5.048530 0.000660]      Entry Point:  0x80001000<br>[5.049099 0.000569]      Hash algo:    sha256<br>[5.049564 0.000465]      Hash value:   fed4aab9de8bc0c04cb8a180da7a817b4c0e7db8c9608e1f59a0c7385eccd7a6<br>[5.059791 0.010227]    Verifying Hash Integrity ... sha256+ OK<br>[11.582735 6.522943] ## Loading ramdisk from FIT Image at 20080000 ...<br>[11.633128 0.050394]    Using 'conf-aspeed-bmc-tyan-s7106.dtb' configuration<br>[11.634600 0.001472]    Trying 'ramdisk-1' ramdisk subimage<br>[11.635495 0.000895]      Description:  obmc-phosphor-initramfs<br>[11.636475 0.000980]      Type:         RAMDisk Image<br>[11.637248 0.000773]      Compression:  uncompressed<br>[11.637960 0.000712]      Data Start:   0x2038d038<br>[11.638650 0.000690]      Data Size:    1096840 Bytes = 1 MiB<br>[11.639495 0.000845]      Architecture: ARM<br>[11.639993 0.000498]      OS:           Linux<br>[11.640573 0.000579]      Load Address: unavailable<br>[11.641293 0.000721]      Entry Point:  unavailable<br>[11.642033 0.000740]      Hash algo:    sha256<br>[11.642632 0.000599]      Hash value:   98744c2598168b3a123ef8760636a8c5e005948e67191646c017e877e7f86e51<br>[11.654930 0.012298]    Verifying Hash Integrity ... sha256+ OK<br>[13.909357 2.254427] ## Loading fdt from FIT Image at 20080000 ...<br>[13.967636 0.058279]    Using 'conf-aspeed-bmc-tyan-s7106.dtb' configuration<br>[13.969544 0.001907]    Trying 'fdt-aspeed-bmc-tyan-s7106.dtb' fdt subimage<br>[13.970586 0.001042]      Description:  Flattened Device Tree blob<br>[13.971422 0.000836]      Type:         Flat Device Tree<br>[13.972072 0.000650]      Compression:  uncompressed<br>[13.972657 0.000585]      Data Start:   0x20385cb8<br>[13.973207 0.000550]      Data Size:    29362 Bytes = 28.7 KiB<br>[13.973970 0.000763]      Architecture: ARM<br>[13.974391 0.000420]      Hash algo:    sha256<br>[13.974972 0.000582]      Hash value:   66368a4557754ea3287198f0d2b75f98bf6a6e17a32c2a9bcc8a574b2dbe5a06<br>[13.976801 0.001829]    Verifying Hash Integrity ... sha256+ OK<br>[14.045789 0.068988]    Booting using the fdt blob at 0x20385cb8<br>[14.047312 0.001523]    Loading Kernel Image ... OK<br>[18.347361 4.300049]    Loading Ramdisk to 9ea90000, end 9eb9bc88 ... OK<br>[19.834330 1.486969]    Loading Device Tree to 9ea85000, end 9ea8f2b1 ... OK<br>[19.914132 0.079802] <br>[19.914196 0.000063] Starting kernel ...<br>[19.930654 0.016458] <br>[23.488077 3.557423] [    0.000000] Booting Linux on physical CPU 0x0<br>[23.490190 0.002112] [    0.000000] Linux version 5.15.59-51fd11b (oe-user@oe-host) (arm-openbmc-linux-gnueabi-gcc (GCC) 12.1.0, GNU ld (GNU Binutils) 2.38.20220623) #1 Thu Aug 4 03:28:18 UTC 2022<br>[23.515911 0.025721] [    0.000000] CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d<br>[23.522071 0.006160] [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache<br>[23.550850 0.028779] [    0.000000] OF: fdt: Machine model: Tyan S7106 BMC<br>[23.552944 0.002095] [    0.000000] Memory policy: Data cache writeback<br>[23.554374 0.001430] [    0.000000] Reserved memory: created CMA memory pool at 0x9d000000, size 16 MiB<br>[23.604916 0.050542] [    0.000000] OF: reserved mem: initialized node framebuffer, compatible id shared-dma-pool<br>[23.608081 0.003165] [    0.000000] cma: Reserved 16 MiB at 0x9c000000<br>[23.609227 0.001147] [    0.000000] Zone ranges:<br>[23.609886 0.000659] [    0.000000]   Normal   [mem 0x0000000080000000-0x000000009effffff]<br>[23.611526 0.001640] [    0.000000] Movable zone start for each node<br>[23.675950 0.064424] [    0.000000] Early memory node ranges<br>[23.677739 0.001789] [    0.000000]   node   0: [mem 0x0000000080000000-0x00000000987effff]<br>[23.680125 0.002386] [    0.000000]   node   0: [mem 0x00000000987f0000-0x00000000987fffff]<br>[23.681552 0.001427] [    0.000000]   node   0: [mem 0x0000000098800000-0x000000009effffff]<br>[23.682810 0.001258] [    0.000000] Initmem setup node 0 [mem 0x0000000080000000-0x000000009effffff]<br>[23.684468 0.001658] [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 125984<br>[23.706800 0.022331] [    0.000000] Kernel command line: console=ttyS4,115200n8 root=/dev/ram rw<br>[23.709396 0.002597] [    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes, linear)<br>[23.735743 0.026347] [    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes, linear)<br>[23.738499 0.002756] [    0.000000] mem auto-init: stack:all(zero), heap alloc:off, heap free:off<br>[23.765738 0.027239] [    0.000000] Memory: 457284K/507904K available (8192K kernel code, 666K rwdata, 1560K rodata, 1024K init, 156K bss, 17852K reserved, 32768K cma-reserved)<br>[23.819745 0.054007] [    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1<br>[23.822114 0.002369] [    0.000000] ftrace: allocating 23856 entries in 47 pages<br>[23.823525 0.001412] [    0.000000] ftrace: allocated 47 pages with 5 groups<br>[23.824556 0.001031] [    0.000000] trace event string verifier disabled<br>[23.825776 0.001220] [    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16<br>[23.845754 0.019979] [    0.000000] i2c controller registered, irq 17<br>[23.847347 0.001592] [    0.000000] clocksource: FTTMR010-TIMER2: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 77222644334 ns<br>[23.875768 0.028421] [    0.000004] sched_clock: 32 bits at 24MHz, resolution 40ns, wraps every 86767015915ns<br>[23.878921 0.003153] [    0.000097] Switching to timer-based delay loop, resolution 40ns<br>[23.944690 0.065770] [    0.000886] Calibrating delay loop (skipped), value calculated using timer frequency.. 49.50 BogoMIPS (lpj=247500)<br>[23.948623 0.003933] [    0.000967] pid_max: default: 32768 minimum: 301<br>[23.949579 0.000956] [    0.003104] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)<br>[23.950998 0.001419] [    0.003192] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)<br>[23.952525 0.001527] [    0.006434] CPU: Testing write buffer coherency: ok<br>[23.995660 0.043134] [    0.009700] Setting up static identity map for 0x80100000 - 0x80100038<br>[23.998464 0.002805] [    0.011248] ASPEED AST2500 rev A2 (04030303)<br>[23.999575 0.001111] [    0.012611] devtmpfs: initialized<br>[24.000401 0.000826] [    0.035630] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns<br>[24.044628 0.044227] [    0.035733] futex hash table entries: 256 (order: -1, 3072 bytes, linear)<br>[24.047093 0.002465] [    0.041939] pinctrl core: initialized pinctrl subsystem<br>[24.048455 0.001362] [    0.045095] NET: Registered PF_NETLINK/PF_ROUTE protocol family<br>[24.049654 0.001199] [    0.047578] DMA: preallocated 256 KiB pool for atomic coherent allocations<br>[24.115643 0.065989] [    0.050560] hw-breakpoint: found 6 breakpoint and 1 watchpoint registers.<br>[24.118448 0.002805] [    0.050632] hw-breakpoint: maximum watchpoint size is 4 bytes.<br>[24.119609 0.001161] [    0.127577] mc: Linux media interface: v0.10<br>[24.120438 0.000829] [    0.127769] videodev: Linux video capture interface: v2.00<br>[24.121494 0.001056] [    0.128051] pps_core: LinuxPPS API ver. 1 registered<br>[24.122430 0.000937] [    0.128105] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <<a href="mailto:giometti@linux.it">giometti@linux.it</a>><br>[24.140529 0.018099] [    0.128212] PTP clock support registered<br>[24.142585 0.002055] [    0.132611] clocksource: Switched to clocksource FTTMR010-TIMER2<br>[24.146256 0.003671] [    0.224804] NET: Registered PF_INET protocol family<br>[24.167846 0.021590] [    0.225299] IP idents hash table entries: 8192 (order: 4, 65536 bytes, linear)<br>[24.196360 0.028513] [    0.226947] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear)<br>[24.199464 0.003104] [    0.227069] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)<br>[24.226350 0.026886] [    0.227152] TCP established hash table entries: 4096 (order: 2, 16384 bytes, linear)<br>[24.228337 0.001987] [    0.227259] TCP bind hash table entries: 4096 (order: 2, 16384 bytes, linear)<br>[24.274405 0.046068] [    0.227349] TCP: Hash tables configured (established 4096 bind 4096)<br>[24.277254 0.002849] [    0.227642] UDP hash table entries: 256 (order: 0, 4096 bytes, linear)<br>[24.279681 0.002427] [    0.227756] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes, linear)<br>[24.281286 0.001605] [    0.228521] NET: Registered PF_UNIX/PF_LOCAL protocol family<br>[24.300313 0.019027] [    0.232052] Unpacking initramfs...<br>[24.301608 0.001295] [    0.242800] workingset: timestamp_bits=30 max_order=17 bucket_order=0<br>[24.303753 0.002145] [    0.257235] squashfs: version 4.0 (2009/01/31) Phillip Lougher<br>[24.368598 0.064845] [    0.257303] jffs2: version 2.2. (SUMMARY)   2001-2006 Red Hat, Inc.<br>[24.370530 0.001932] [    0.275423] NET: Registered PF_ALG protocol family<br>[24.371767 0.001237] [    0.279878] ipmi-bt-host 1e789140.ibt: Found bt bmc device<br>[24.373178 0.001411] [    0.280829] ipmi-bt-host 1e789140.ibt: Using IRQ 34<br>[24.374452 0.001274] [    0.282479] ast-kcs-bmc 1e789024.kcs: Initialised raw client for channel 1<br>[24.419349 0.044897] [    0.283020] ast-kcs-bmc 1e789024.kcs: Initialised IPMI client for channel 1<br>[24.422025 0.002676] [    0.283089] ast-kcs-bmc 1e789024.kcs: Initialised channel 1 at 0xca8<br>[24.423269 0.001244] [    0.294041] ast-kcs-bmc 1e78902c.kcs: Initialised raw client for channel 3<br>[24.424783 0.001514] [    0.294499] ast-kcs-bmc 1e78902c.kcs: Initialised IPMI client for channel 3<br>[24.446348 0.021565] [    0.294569] ast-kcs-bmc 1e78902c.kcs: Initialised channel 3 at 0xca2<br>[24.449583 0.003235] [    0.300129] aspeed-uart-routing 1e78909c.uart-routing: module loaded<br>[24.476207 0.026623] [    0.303416] Serial: 8250/16550 driver, 6 ports, IRQ sharing enabled<br>[24.478619 0.002412] [    0.317481] 1e787000.serial: ttyS5 at MMIO 0x1e787000 (irq = 34, base_baud = 1546875) is a ASPEED VUART<br>[24.511201 0.032583] [    0.319809] 1e783000.serial: ttyS0 at MMIO 0x1e783000 (irq = 32, base_baud = 1500000) is a 16550A<br>[24.514808 0.003607] [    0.321423] 1e784000.serial: ttyS4 at MMIO 0x1e784000 (irq = 33, base_baud = 1500000) is a 16550A<br>[24.527183 0.012376] [    1.393553] printk: console [ttyS4] enabled<br>[24.528688 0.001505] [    1.399759] 1e78d000.serial: ttyS1 at MMIO 0x1e78d000 (irq = 35, base_baud = 1500000) is a 16550A<br>[24.571180 0.042492] [    1.424074] 1e78e000.serial: ttyS2 at MMIO 0x1e78e000 (irq = 36, base_baud = 1500000) is a 16550A<br>[24.592127 0.020947] [    1.444561] 1e78f000.serial: ttyS3 at MMIO 0x1e78f000 (irq = 37, base_baud = 1500000) is a 16550A<br>[24.620174 0.028047] [    1.465512] timeriomem_rng 1e6e2078.hwrng: 32bits from 0x(ptrval) @ 1us<br>[24.622947 0.002773] [    1.473446] aspeed_gfx 1e6e6000.display: assigned reserved memory node framebuffer<br>[24.636189 0.013241] [    1.503570] random: crng init done<br>[24.652126 0.015937] [    1.524490] [drm] Initialized aspeed-gfx-drm 1.0.0 20180319 for 1e6e6000.display on minor 0<br>[24.701060 0.048934] [    1.553274] aspeed_gfx 1e6e6000.display: [drm] fb0: aspeed-gfx-drmd frame buffer device<br>[24.733143 0.032083] [    1.595158] loop: module loaded<br>[24.797137 0.063995] [    1.659126] spi-nor spi0.0: mx66l1g45g (131072 Kbytes)<br>[24.939029 0.141891] [    1.791345] spi-aspeed-smc 1e620000.spi: CE0 read buswidth:2 [0x203c0641]<br>[25.098046 0.159017] [    1.945137] 5 fixed-partitions partitions found on MTD device bmc<br>[25.101257 0.003211] [    1.951289] Creating 5 MTD partitions on "bmc":<br>[25.102476 0.001219] [    1.955967] 0x000000000000-0x000000060000 : "u-boot"<br>[25.113789 0.011313] [    1.984254] 0x000000060000-0x000000080000 : "u-boot-env"<br>[25.138113 0.024324] [    1.992205] 0x000000080000-0x0000004c0000 : "kernel"<br>[25.164872 0.026759] [    2.015047] 0x0000004c0000-0x000001c00000 : "rofs"<br>[25.168555 0.003682] [    2.022386] 0x000001c00000-0x000002000000 : "rwfs"<br>[25.234758 0.066204] [    2.047580] spi-nor spi1.0: unrecognized JEDEC id bytes: ff ff ff ff ff ff<br>[25.237092 0.002333] [    2.054602] spi-nor: probe of spi1.0 failed with error -2<br>[25.237974 0.000883] [    2.065146] ftgmac100 1e660000.ethernet: Generated random MAC address ee:f3:83:36:82:59<br>[25.238928 0.000954] [    2.073315] ftgmac100 1e660000.ethernet: Using NCSI interface<br>[25.239958 0.001030] [    2.080277] ftgmac100 1e660000.ethernet eth0: irq 20, mapped at fbb6b239<br>[25.241289 0.001331] [    2.087826] ftgmac100 1e680000.ethernet: Generated random MAC address 2e:e3:14:ec:62:ff<br>[25.243061 0.001772] [    2.105583] RTL8211E Gigabit Ethernet 1e680000.ethernet--1:00: attached PHY driver (mii_bus:phy_addr=1e680000.ethernet--1:00, irq=POLL)<br>[25.271468 0.028407] [    2.119043] ftgmac100 1e680000.ethernet eth1: irq 21, mapped at dd746f2b<br>[25.283708 0.012240] [    2.154169] Freeing initrd memory: 1072K<br>[25.334315 0.050606] [    2.159954] aspeed_vhub 1e6a0000.usb-vhub: Initialized virtual hub in USB2 mode<br>[25.337081 0.002767] [    2.167969] Mass Storage Function, version: 2009/09/11<br>[25.338294 0.001213] [    2.173247] LUN: removable file: (no medium)<br>[25.339165 0.000871] [    2.177613] no file given for LUN0<br>[25.339808 0.000643] [    2.181098] udc 1e6a0000.usb-vhub:p1: failed to start g_mass_storage: -22<br>[25.341107 0.001299] [    2.188670] i2c_dev: i2c /dev entries driver<br>[25.341952 0.000845] [    2.194845] aspeed-i2c-bus 1e78a040.i2c-bus: i2c bus 0 registered, irq 38<br>[25.343256 0.001304] [    2.203024] aspeed-i2c-bus 1e78a080.i2c-bus: i2c bus 1 registered, irq 39<br>[25.390362 0.047106] [    2.212682] at24 2-0050: 32768 byte 24c256 EEPROM, writable, 1 bytes/write<br>[25.392269 0.001907] [    2.219811] aspeed-i2c-bus 1e78a0c0.i2c-bus: i2c bus 2 registered, irq 40<br>[25.394077 0.001808] [    2.229401] at24 3-0050: 256 byte 24c02 EEPROM, writable, 1 bytes/write<br>[25.395848 0.001771] [    2.237783] at24 3-0051: 256 byte 24c02 EEPROM, writable, 1 bytes/write<br>[25.397618 0.001771] [    2.245540] aspeed-i2c-bus 1e78a100.i2c-bus: i2c bus 3 registered, irq 41<br>[25.399389 0.001770] [    2.253818] aspeed-i2c-bus 1e78a140.i2c-bus: i2c bus 4 registered, irq 42<br>[25.401156 0.001767] [    2.261963] aspeed-i2c-bus 1e78a180.i2c-bus: i2c bus 5 registered, irq 43<br>[25.438266 0.037110] [    2.270210] aspeed-i2c-bus 1e78a1c0.i2c-bus: i2c bus 6 registered, irq 44<br>[25.440232 0.001966] [    2.278519] aspeed-i2c-bus 1e78a300.i2c-bus: i2c bus 7 registered, irq 45<br>[25.442063 0.001831] [    2.286725] aspeed-i2c-bus 1e78a340.i2c-bus: i2c bus 8 registered, irq 46<br>[25.443908 0.001845] [    2.294952] Driver for 1-wire Dallas network protocol.<br>[42.321590 16.877682] [   19.191143] SPI driver bmp280 has no spi_device_id for bosch,bmp085<br>[42.369245 0.047655] [   19.202063] NET: Registered PF_INET6 protocol family<br>[42.370710 0.001465] [   19.210275] Segment Routing with IPv6<br>[42.371670 0.000960] [   19.214194] In-situ OAM (IOAM) with IPv6<br>[42.372684 0.001014] [   19.218587] NET: Registered PF_PACKET protocol family<br>[42.373994 0.001310] [   19.223826] 8021q: 802.1Q VLAN Support v1.8<br>[42.375069 0.001075] [   19.240013] printk: console [netcon0] enabled<br>[42.417406 0.042337] [   19.244511] netconsole: network logging started<br>[42.418871 0.001465] [   19.255290] Freeing unused kernel image (initmem) memory: 1024K<br>[42.420469 0.001598] [   19.265290] Checked W+X mappings: passed, no W+X pages found<br>[42.421951 0.001482] [   19.271013] Run /init as init process<br>[43.119224 0.697273] rofs = mtd4 squashfs rwfs = mtd5 jffs2<br>[43.346902 0.227678] [   20.193806] jffs2: notice: (101) jffs2_build_xattr_subsystem: complete building xattr subsystem, 26 of xdatum (15 unchecked, 7 orphan) and 34 of xref (8 dead, 0 orphan) found.<br>[43.522817 0.175915] Tue Apr  5 23:02:44 UTC 2011<br>[43.551731 0.028914] [   20.397227] overlayfs: upper fs does not support tmpfile.<br>[43.554043 0.002311] [   20.403610] overlayfs: upper fs does not support RENAME_WHITEOUT.<br>[46.530198 2.976155] [   23.376894] systemd[1]: Current system time is further ahead 15y after build time, but cannot correct: Invalid argument<br>[46.545993 0.015796] [   23.411753] systemd[1]: Failed to find module 'autofs4'<br>[46.773107 0.227114] [   23.598149] systemd[1]: systemd 251.2+ running in system mode (+PAM -AUDIT -SELINUX -APPARMOR -IMA -SMACK +SECCOMP -GCRYPT -GNUTLS -OPENSSL -ACL +BLKID -CURL -ELFUTILS -FIDO2 -IDN2 -IDN -IPTC +KMOD -LIBCRYPTSETUP +LIBFDISK -PCRE2 -PWQUALITY -P11KIT -QRENCODE -TPM2 -BZIP2 -LZ4 -XZ -ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON -UTMP +SYSVINIT default-hierarchy=hybrid)<br>[46.783382 0.010274] [   23.630127] systemd[1]: Detected architecture arm.<br>[46.832963 0.049582] <br>[46.833018 0.000055] Welcome to Phosphor OpenBMC (Phosphor OpenBMC Project Reference Distro) 2.11.0-dev!<br>[46.836568 0.003550] <br>[46.880928 0.044360] [   23.746391] systemd[1]: Hostname set to <s7106>.<br>[50.045951 3.165023] [   26.892896] systemd[1]: /lib/systemd/system/phosphor-ipmi-net@.socket:3: Invalid interface name, ignoring: sys-subsystem-net-devices-%i.device<br>[50.214922 0.168972] [   27.067199] systemd[1]: Queued start job for default target Multi-User System.<br>[50.251829 0.036907] [   27.097063] systemd[1]: Created slice Slice /system/getty.<br>[50.254950 0.003120] [  OK  ] Created slice Slice /system/getty.<br>[50.295814 0.040864] [   27.141348] systemd[1]: Created slice Slice /system/hostlogger.<br>[50.298493 0.002680] [  OK  ] Created slice Slice /system/hostlogger.<br>[50.344807 0.046314] [   27.191243] systemd[1]: Created slice Slice /system/mapper-wait.<br>[50.346868 0.002061] [  OK  ] Created slice Slice /system/mapper-wait.<br>[50.394869 0.048001] [   27.241200] systemd[1]: Created slice Slice /system/modprobe.<br>[50.397565 0.002697] [  OK  ] Created slice Slice /system/modprobe.<br>[50.445728 0.048163] [   27.291502] systemd[1]: Created slice Slice /system/obmc-console.<br>[50.448524 0.002795] [  OK  ] Created slice Slice /system/obmc-console.<br>[50.495677 0.047153] [   27.341588] systemd[1]: Created slice Slice /system/obmc-led-group-start.<br>[50.498699 0.003022] [  OK  ] Created slice Slice /system/obmc-led-group-start.<br>[50.545669 0.046970] [   27.391644] systemd[1]: Created slice Slice /system/phosphor-certificate-manager.<br>[50.548889 0.003220] [  OK  ] Created slice Slice /system/phosphor-certificate-manager.<br>[50.595607 0.046717] [   27.441589] systemd[1]: Created slice Slice /system/phosphor-ipmi-kcs.<br>[50.597484 0.001877] [  OK  ] Created slice Slice /system/phosphor-ipmi-kcs.<br>[50.645620 0.048136] [   27.491616] systemd[1]: Created slice Slice /system/phosphor-ipmi-net.<br>[50.649161 0.003541] [  OK  ] Created slice Slice /system/phosphor-ipmi-net.<br>[50.695552 0.046391] [   27.541962] systemd[1]: Created slice Slice /system/serial-getty.<br>[50.698557 0.003005] [  OK  ] Created slice Slice /system/serial-getty.<br>[50.751634 0.053077] [   27.591873] systemd[1]: Created slice Slice /system/xyz.openbmc_project.Chassis.Control.Power.<br>[50.755019 0.003385] [  OK  ] Created slice Slice /systeproject.Chassis.Control.Power.<br>[50.767445 0.012426] [   27.635053] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.<br>[50.795528 0.028083] [  OK  ] Started Dispatch Password ts to Console Directory Watch.<br>[50.829517 0.033989] [   27.675029] systemd[1]: Started Forward Password Requests to Wall Directory Watch.<br>[50.832890 0.003373] [  OK  ] Started Forward Password Ruests to Wall Directory Watch.<br>[50.867495 0.034605] [   27.718553] systemd[1]: Reached target Path Units.<br>[50.869946 0.002451] [  OK  ] Reached target Path Units.<br>[50.883339 0.013393] [   27.754327] systemd[1]: Reached target Remote File Systems.<br>[50.906378 0.023038] [  OK  ] Reached target Remote File Systems.<br>[50.942467 0.036089] [   27.793908] systemd[1]: Reached target Slice Units.<br>[50.945024 0.002557] [  OK  ] Reached target Slice Units.<br>[50.983415 0.038391] [   27.834719] systemd[1]: Reached target Swaps.<br>[50.985597 0.002182] [  OK  ] Reached target Swaps.<br>[51.015376 0.029778] [   27.887004] systemd[1]: Listening on Syslog Socket.<br>[51.037815 0.022439] [  OK  ] Listening on Syslog Socket.<br>[51.100454 0.062639] [   27.969505] systemd[1]: Listening on Process Core Dump Socket.<br>[51.123107 0.022654] [  OK  ] Listening on Process Core Dump Socket.<br>[51.159312 0.036204] [   28.005293] systemd[1]: Listening on initctl Compatibility Named Pipe.<br>[51.163193 0.003882] [  OK  ] Listening on initctl Compatibility Named Pipe.<br>[51.175196 0.012003] [   28.045875] systemd[1]: Journal Audit Socket was skipped because of a failed condition check (ConditionSecurity=audit).<br>[51.214864 0.039668] [   28.060598] systemd[1]: Listening on Journal Socket (/dev/log).<br>[51.216492 0.001628] [  OK  ] Listening on Journal Socket (/dev/log).<br>[51.256257 0.039765] [   28.107496] systemd[1]: Listening on Journal Socket.<br>[51.258725 0.002467] [  OK  ] Listening on Journal Socket.<br>[51.302207 0.043482] [   28.147892] systemd[1]: Listening on Network Service Netlink Socket.<br>[51.305223 0.003016] [  OK  ] Listening on Network Service Netlink Socket.<br>[51.347120 0.041897] [   28.193666] systemd[1]: Listening on udev Control Socket.<br>[51.349171 0.002052] [  OK  ] Listening on udev Control Socket.<br>[51.391152 0.041980] [   28.236804] systemd[1]: Listening on udev Kernel Socket.<br>[51.393638 0.002487] [  OK  ] Listening on udev Kernel Socket.<br>[51.407052 0.013414] [   28.277443] systemd[1]: Huge Pages File System was skipped because of a failed condition check (ConditionPathExists=/sys/kernel/mm/hugepages).<br>[51.449995 0.042943] [   28.293533] systemd[1]: POSIX Message Queue File System was skipped because of a failed condition check (ConditionPathExists=/proc/sys/fs/mqueue).<br>[51.478059 0.028064] [   28.323738] systemd[1]: Mounting Kernel Debug File System...<br>[51.480142 0.002083]          Mounting Kernel Debug File System...<br>[51.509969 0.029828] [   28.380532] systemd[1]: Mounting Kernel Trace File System...<br>[51.539350 0.029380]          Mounting Kernel Trace File System...<br>[51.597110 0.057761] [   28.443241] systemd[1]: Mounting Temporary Directory /tmp...<br>[51.599710 0.002600]          Mounting Temporary Directory /tmp...<br>[51.629030 0.029320] [   28.496720] systemd[1]: Create List of Static Device Nodes was skipped because of a failed condition check (ConditionFileNotEmpty=/lib/modules/5.15.59-51fd11b/modules.devname).<br>[51.694985 0.065954] [   28.546605] systemd[1]: Starting Load Kernel Module configfs...<br>[51.698977 0.003992]          Starting Load Kernel Module configfs...<br>[51.772951 0.073974] [   28.625054] systemd[1]: Starting Load Kernel Module fuse...<br>[51.774767 0.001815]          Starting Load Kernel Module fuse...<br>[51.818924 0.044157] [   28.665147] systemd[1]: File System Check on Root Device was skipped because of a failed condition check (ConditionPathIsReadWrite=!/).<br>[51.891872 0.072948] [   28.743206] systemd[1]: Starting Journal Service...<br>[51.893559 0.001687]          Starting Journal Service...<br>[51.965837 0.072278] [   28.817654] systemd[1]: Load Kernel Modules was skipped because all trigger condition checks failed.<br>[51.997672 0.031836] [   28.869543] systemd[1]: Starting Generate network units from Kernel command line...<br>[52.034659 0.036987]          Starting Generate network ts from Kernel command line...<br>[52.114632 0.079973] [   28.985213] systemd[1]: Starting Remount Root and Kernel File Systems...<br>[52.136827 0.022195]          Starting Remount Root and Kernel File Systems...<br>[52.199675 0.062847] [   29.069243] systemd[1]: Starting Apply Kernel Variables...<br>[52.247646 0.047972]          Starting Apply Kernel Variables...<br>[52.343694 0.096048] [   29.215162] systemd[1]: Starting Coldplug All udev Devices...<br>[52.366999 0.023305]          Starting Coldplug All udev Devices...<br>[52.868361 0.501362] [   29.720007] systemd[1]: Mounted Kernel Debug File System.<br>[52.932199 0.063838] [  OK  ] Mounted Kernel Debug File System.<br>[52.989149 0.056950] [   29.835439] systemd[1]: Mounted Kernel Trace File System.<br>[52.991677 0.002527] [  OK  ] Mounted Kernel Trace File System.<br>[53.049128 0.057451] [   29.895548] systemd[1]: Mounted Temporary Directory /tmp.<br>[53.051853 0.002725] [  OK  ] Mounted Temporary Directory /tmp.<br>[53.077029 0.025176] [   29.929350] systemd[1]: modprobe@configfs.service: Deactivated successfully.<br>[53.107001 0.029972] [   29.953102] systemd[1]: Finished Load Kernel Module configfs.<br>[53.109846 0.002845] [  OK  ] Finished Load Kernel Module configfs.<br>[53.168076 0.058229] [   30.020412] systemd[1]: modprobe@fuse.service: Deactivated successfully.<br>[53.200062 0.031986] [   30.046159] systemd[1]: Finished Load Kernel Module fuse.<br>[53.202464 0.002403] [  OK  ] Finished Load Kernel Module fuse.<br>[53.204073 0.001608] [   30.068653] systemd[1]: Finished Generate network units from Kernel command line.<br>[53.254024 0.049951] [  OK  ] Finished Generate network units from Kernel command line.<br>[53.285877 0.031853] [   30.158111] systemd[1]: Finished Remount Root and Kernel File Systems.<br>[53.338859 0.052982] [  OK  ] Finished Remount Root and Kernel File Systems.<br>[53.370881 0.032022] [   30.241587] systemd[1]: Finished Apply Kernel Variables.<br>[53.393164 0.022284] [  OK  ] Finished Apply Kernel Variables.<br>[53.481021 0.087857] [   30.318812] systemd[1]: Reached target Preparation for Network.<br>[53.484837 0.003816] [  OK  ] Reached target Preparation for Network.<br>[53.496938 0.012101] [   30.367036] systemd[1]: FUSE Control File System was skipped because of a failed condition check (ConditionPathExists=/sys/fs/fuse/connections).<br>[53.581825 0.084887] [   30.453374] systemd[1]: Mounting Kernel Configuration File System...<br>[53.611489 0.029664]          Mounting Kernel Configuration File System...<br>[53.687846 0.076357] [   30.534063] systemd[1]: Rebuild Hardware Database was skipped because of a failed condition check (ConditionNeedsUpdate=/etc).<br>[53.703639 0.015793] [   30.574867] systemd[1]: Platform Persistent Storage Archival was skipped because of a failed condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).<br>[53.778705 0.075066] [   30.625049] systemd[1]: Create System Users was skipped because of a failed condition check (ConditionNeedsUpdate=/etc).<br>[53.847799 0.069094] [   30.699639] systemd[1]: Starting Create Static Device Nodes in /dev...<br>[53.893642 0.045844]          Starting Create Static Device Nodes in /dev...<br>[54.014563 0.120921] [   30.866554] systemd[1]: Mounted Kernel Configuration File System.<br>[54.041466 0.026903] [  OK  ] Mounted Kernel Configuration File System.<br>[54.567170 0.525704] [   31.413009] systemd[1]: Finished Create Static Device Nodes in /dev.<br>[54.569438 0.002267] [  OK  ] Finished Create Static Device Nodes in /dev.<br>[54.599150 0.029712] [   31.445086] systemd[1]: Reached target Preparation for Local File Systems.<br>[54.601663 0.002513] [  OK  ] Reached target Preparation for Local File Systems.<br>[54.647228 0.045565] [   31.508256] systemd[1]: Mounting /var/volatile...<br>[54.679114 0.031887]          Mounting /var/volatile...<br>[54.775250 0.096135] [   31.647359] systemd[1]: Starting Rule-based Manager for Device Events and Files...<br>[54.841080 0.065830]          Starting Rule-based Managefor Device Events and Files...<br>[54.933032 0.091952] [   31.784875] systemd[1]: Started Journal Service.<br>[54.935395 0.002362] [  OK  ] Started Journal Service.<br>[55.012993 0.077598] [  OK  ] Mounted /var/volatile.<br>[55.124927 0.111934]          Starting Flush Journal to Persistent Storage...<br>[55.284726 0.159799]          Starting Load/Save Random Seed...<br>[55.344767 0.060041] [  OK  ] Reached target Local File Systems.<br>[55.615663 0.270896] [   32.467582] systemd-journald[134]: Received client request to flush runtime journal.<br>[55.677563 0.061900] [  OK  ] Finished Flush Journal to Persistent Storage.<br>[55.764487 0.086923]          Starting Create Volatile Files and Directories...<br>[55.796511 0.032024] [  OK  ] Finished Load/Save Random Seed.<br>[56.578026 0.781515] [  OK  ] Finished Create Volatile Files and Directories.<br>[56.705990 0.127965]          Starting Network Name Resolution...<br>[56.833921 0.127931]          Starting Network Time Synchronization...<br>[57.247735 0.413814] [  OK  ] Started Rule-based Manager for Device Events and Files.<br>[57.375574 0.127839]          Starting Network Configuration...<br>[59.322477 1.946902] [  OK  ] Finished Coldplug All udev Devices.<br>[61.836220 0.003311] [  OK  ] Started Network Time Synchronization.<br>[66.404501 0.003257] [   44.006597] 8021q: adding VLAN 0 to HW filter on device eth0<br>[67.310624 0.906122] [  OK  ] Started Network Configuration.<br>[67.461615 0.150991] [  OK  ] Started Network Name Resolution.<br>[67.573481 0.111866] [  OK  ] Found device /sys/subsystem/net/devices/eth0.<br>[69.840189 2.266707] [  OK  ] Created slice Slice /system/xyz.openbmc_project.Hwmon.<br>[69.885086 0.044898] [  OK  ] Created slice Slice /systepenbmc_project.led.controller.<br>[69.917047 0.031961] [  OK  ] Reached target Network.<br>[69.956052 0.039005] [  OK  ] Reached target Host and Network Name Lookups.<br>[69.994986 0.038934] [  OK  ] Reached target System Time Set.<br>[70.024949 0.029963] [  OK  ] Reached target Hardware activated USB gadget.<br>[70.089049 0.064100]          Starting Load Kernel Module fuse...<br>[70.168915 0.079866]          Starting Wait for Network to be Configured...<br>[70.261885 0.092970]          Starting Wait for udev To plete Device Initialization...<br>[70.378769 0.116884] [  OK  ] Finished Load Kernel Module fuse.<br>[70.511690 0.132921] [  OK  ] Finished Wait for udev To Complete Device Initialization.<br>[70.623694 0.112004] [  OK  ] Started Hardware RNG Entropy Gatherer Daemon.<br>[70.655513 0.031819] [  OK  ] Reached target System Initialization.<br>[70.736570 0.081057] [  OK  ] Started Daily rotation of log files.<br>[70.775594 0.039024] [  OK  ] Started Daily Cleanup of Temporary Directories.<br>[70.815531 0.039937] [  OK  ] Reached target Timer Units.<br>[70.871529 0.055998] [  OK  ] Listening on Avahi mDNS/DNS-SD Stack Activation Socket.<br>[70.966407 0.094877] [  OK  ] Listening on BMC Webserver socket.<br>[71.030405 0.063998] [  OK  ] Listening on D-Bus System Message Bus Socket.<br>[71.196403 0.165998] [  OK  ] Listening on dropbear.socket.<br>[71.292238 0.095835] [   48.163528] ftgmac100 1e680000.ethernet eth1: Link is Up - 1Gbps/Full - flow control rx/tx<br>[71.320861 0.028622] [   48.171909] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready<br>[71.430178 0.109317] [  OK  ] Listening on Phosphor Hostole SSH Per-Connection socket.<br>[71.526094 0.095916] [  OK  ] Listening on phosphor-ipmi-net@eth0.socket.<br>[71.586054 0.059961] [  OK  ] Reached target Socket Units.<br>[71.666205 0.080151]          Starting D-Bus System Message Bus...<br>[72.801349 1.135144] [  OK  ] Started D-Bus System Message Bus.<br>[73.068098 0.266749] [  OK  ] Reached target Basic System.<br>[73.180175 0.112077]          Starting Avahi mDNS/DNS-SD Stack...<br>[73.242047 0.061872] [  OK  ] Started Start bmcweb server.<br>[73.385968 0.143922]          Starting Clear one time boot overrides...<br>[73.497921 0.111952] [  OK  ] Started Collectd.<br>[73.721807 0.223886]          Starting SSH Key Generation...<br>[73.833714 0.111908] [  OK  ] Started LPC Snoop Daemon.<br>[73.897783 0.064069]          Starting Name Service Cache Daemon...<br>[73.945774 0.047991]          Starting LDAP daemon...<br>[74.370455 0.424681] [  OK  ] Started ttyS2 Console Server.<br>[74.536364 0.165909] [DEPEND] Dependency failed for Host logger for ttyVUART0.<br>[74.680219 0.143855] [  OK  ] Started Phosphor Dump core monitor..<br>[75.061063 0.380844] [  OK  ] Started Phosphor certificate manager for authority.<br>[75.471731 0.410668] [  OK  ] Started Phosphor certificate manager for bmcweb.<br>[75.845591 0.373860] [  OK  ] Started Phosphor certificate manager for nslcd.<br>[76.053437 0.207846]          Starting BMC health monitoring...<br>[76.405303 0.351866] [  OK  ] Started Lightweight SLP Server.<br>[76.740922 0.335620]          Starting OpenBMC ipKVM daemon...<br>[77.044809 0.303887]          Starting Permit User Sessions...<br>[77.252684 0.207875]          Starting Enable Linux trace events in the boot loader...<br>[77.517459 0.264774]          Starting Intel Power Control for the Host 0...<br>[77.789325 0.271866]          Starting Phosphor Dump Manager...<br>[77.917117 0.127793]          Starting Entity Manager...<br>[78.077091 0.159973] [  OK  ] Started Fru Device.<br>[78.371989 0.294899] [  OK  ] Started IPMI SEL Logging Service.<br>[78.595787 0.223798]          Starting Phosphor Log Manager...<br>[79.395339 0.799552]          Starting Phosphor DBus Service Discovery Manager...<br>[79.523156 0.127818]          Starting Phosphor Settings Daemon...<br>[79.603066 0.079910]          Starting Phosphor Download Manager...<br>[79.922962 0.319896]          Starting Post code manager...<br>[80.050937 0.127975]          Starting Rsyslog config updater...<br>[80.354702 0.303764]          Starting Telemetry...<br>[80.562499 0.207797]          Starting Phosphor User Manager...<br>[80.792450 0.229951] [  OK  ] Started Phosphor sysfs LED controller.<br>[81.256206 0.463756] [  OK  ] Started Phosphor sysfs LED controller.<br>[83.070060 1.813854] [  OK  ] Finished Wait for Network to be Configured.<br>[83.507784 0.437724] [  OK  ] Finished SSH Key Generation.<br>[83.760672 0.252888] [  OK  ] Started Name Service Cache Daemon.<br>[83.851574 0.090902] [  OK  ] Started OpenBMC ipKVM daemon.<br>[83.888570 0.036996] [   60.740209] ftgmac100 1e660000.ethernet eth0: NCSI: No channel found to configure!<br>[83.967398 0.078828] [  OK  ] Finished Permit User Sessions.<br>[84.047391 0.079993] [  OK  ] Finished Enable Linux trace events in the boot loader.<br>[84.735110 0.687719] [  OK  ] Finished Clear one time boot overrides.<br>[84.894970 0.159860] [   61.762821] ftgmac100 1e660000.ethernet eth0: Wrong NCSI state 0x100 in workqueue<br>[85.549486 0.654515] [  OK  ] Started Phosphor Settings Daemon.<br>[85.765249 0.215764] [  OK  ] Started Phosphor Download Manager.<br>[85.768340 0.003091] [  OK  ] Started Post code manager.<br>[85.869289 0.100949] [  OK  ] Started Intel Power Control for the Host 0.<br>[85.901206 0.031917] [  OK  ] Started LDAP daemon.<br>[86.011219 0.110013] [  OK  ] Started BMC health monitoring.<br>[86.091021 0.079802] [  OK  ] Started Phosphor Log Manager.<br>[86.106979 0.015958] [  OK  ] Started Rsyslog config updater.<br>[86.361989 0.255010] [  OK  ] Started Phosphor DBus Service Discovery Manager.<br>[86.425885 0.063896] [  OK  ] Started Telemetry.<br>[86.553790 0.127905] [  OK  ] Started Phosphor User Manager.<br>[86.793664 0.239874] [  OK  ] Reached target Network is Online.<br>[86.899669 0.106005] [  OK  ] Reached target Phosphor Object Mapper.<br>[87.272368 0.372699]          Starting Wait for /xyz/opecontrol/host0/boot/one_time...<br>[87.640217 0.367849]          Starting Wait for /xyz/ope_project/control/host0/boot...<br>[87.894980 0.254763]          Starting Wait for /xyz/ope/host0/power_restore_policy...<br>[88.241803 0.346823]          Starting Wait for /xyz/opetrol/host0/restriction_mode...<br>[88.545633 0.303830]          Starting Wait for /xyz/opeoject/led/groups/bmc_booted...<br>[88.882431 0.336798]          Starting Wait for /xyz/opemc_project/time/sync_method...<br>[89.071213 0.188782] [  OK  ] Started phosphor systemd target monitor.<br>[89.375118 0.303905]          Starting System Logging Service...<br>[89.701887 0.326770] [  OK  ] Started Serial Getty on ttyS4.<br>[89.764756 0.062869] [  OK  ] Reached target Login Prompts.<br>[90.459415 0.694659]          Starting Phosphor LED Group Management Daemon...<br>[90.744264 0.284849]          Starting Phosphor Ldap config updater...<br>[90.920100 0.175835]          Starting Phosphor Network Manager...<br>[91.335809 0.415709]          Starting OpenBMC Software Update Manager...<br>[91.653723 0.317914]          Starting Phosphor BMC State Manager...<br>[94.032272 2.378549] [  OK  ] Started System Logging Service.<br>[94.176078 0.143806] [  OK  ] Finished Wait for /xyz/opet/control/host0/boot/one_time.<br>[94.325020 0.148942] [  OK  ] Finished Wait for /xyz/opemc_project/control/host0/boot.<br>[94.452987 0.127967] [  OK  ] Finished Wait for /xyz/opeol/host0/power_restore_policy.<br>[94.592883 0.139896] [  OK  ] Finished Wait for /xyz/opeontrol/host0/restriction_mode.<br>[94.714805 0.121922] [  OK  ] Finished Wait for /xyz/openbmc_project/time/sync_method.<br>[94.825732 0.110927] [  OK  ] Started Phosphor Dump Manager.<br>[95.438527 0.612794] <br>[95.438650 0.000123] Phosphor OpenBMC (Phosphor OpenBMC Project Reference Distro) nodistro.0 s7106 ttyS4<br>[95.442250 0.003600] <br>[95.442283 0.000033] s7106 login: root (automatic login)<br>[95.443164 0.000881]<br>```</div></div>