May 5 17:22:48 talos kern.info phosphor-network-manager[957]: Refreshing complete. May 5 17:22:48 talos kern.info phosphor-network-manager[957]: Timer expired (obmcutil poweroff) May 5 17:26:45 talos kern.info phosphor-host-state-manager[1066]: Host State transaction request May 5 17:26:45 talos daemon.info systemd[1]: Created slice system-op\x2docc\x2ddisable.slice. May 5 17:26:45 talos daemon.info systemd[1]: Stopped target Start Host0. May 5 17:26:45 talos daemon.info systemd[1]: Created slice system-op\x2dpower\x2dstop.slice. May 5 17:26:45 talos daemon.info systemd[1]: Stopped target Chassis0 (Reset Check). May 5 17:26:45 talos daemon.info systemd[1]: Stopped target Fan Control Ready. May 5 17:26:45 talos daemon.info systemd[1]: Stopping Phosphor Fan Control Daemon... May 5 17:26:45 talos daemon.info systemd[1]: Stopped target Chassis0 (Power On). May 5 17:26:45 talos daemon.info systemd[1]: Stopping Phosphor Fan Presence Tach Daemon... May 5 17:26:45 talos daemon.info systemd[1]: Stopped Enable the AVS bus on VRMs. May 5 17:26:45 talos daemon.info systemd[1]: Created slice system-op\x2dwait\x2dpower\x2doff.slice. May 5 17:26:45 talos daemon.info systemd[1]: Stopped PCIE Slot Presence Detection For Chassis0. May 5 17:26:45 talos daemon.info systemd[1]: Starting Wait for /org/openbmc/HostIpmi/1... May 5 17:26:45 talos daemon.info systemd[1]: Stopped Apply voltage overrides to VRMs. May 5 17:26:45 talos daemon.info systemd[1]: Stopping OpenPOWER OCC Active Enable for host 0... May 5 17:26:45 talos daemon.info systemd[1]: Stopping Phosphor GPIO checkstop monitor... May 5 17:26:45 talos daemon.info systemd[1]: Stopping Phosphor poweron watchdog... May 5 17:26:45 talos daemon.info systemd[1]: Stopped Disable the AVS bus on the VRMs. May 5 17:26:45 talos daemon.info systemd[1]: Stopped Perform AVS bus workaround on VRMs. May 5 17:26:45 talos daemon.info systemd[1]: Starting OpenPOWER OCC Active Disable... May 5 17:26:45 talos daemon.info systemd[1]: Stopping Phosphor Fan Monitor Daemon... May 5 17:26:46 talos daemon.info occ-active.sh[20580]: Found 2 CPU(s) May 5 17:26:46 talos daemon.info systemd[1]: Stopped target Host0 (Started). May 5 17:26:46 talos daemon.info systemd[1]: Stopped target Host0 (Starting). May 5 17:26:46 talos daemon.info systemd[1]: Stopped Start host0 SBE. May 5 17:26:46 talos daemon.info systemd[1]: Stopped target Start Host0 (Pre). May 5 17:26:46 talos daemon.info systemd[1]: Stopped Apply ASpeed VGA disable setting on host0. May 5 17:26:46 talos daemon.info systemd[1]: Stopped Scan FSI devices. May 5 17:26:46 talos daemon.info systemd[1]: Created slice system-obmc\x2dled\x2dgroup\x2dstop.slice. May 5 17:26:46 talos daemon.info systemd[1]: Starting Assert power_on LED... May 5 17:26:47 talos daemon.info systemd[1]: Stopped Phosphor poweron watchdog. May 5 17:26:47 talos daemon.info systemd[1]: Stopped Phosphor GPIO checkstop monitor. May 5 17:26:47 talos daemon.info systemd[1]: Stopped Phosphor Fan Presence Tach Daemon. May 5 17:26:47 talos daemon.info systemd[1]: Stopped Phosphor Fan Monitor Daemon. May 5 17:26:47 talos daemon.info systemd[1]: Stopped OpenPOWER OCC Active Enable for host 0. May 5 17:26:47 talos daemon.info systemd[1]: Stopped Phosphor Fan Control Daemon. May 5 17:26:47 talos daemon.info systemd[1]: xyz.openbmc_project.Hwmon@gpio\x2dfsi-cfam\x400\x2c0-sbefifo\x402400-occ\x401-occ\x2dhwmon\x401.service: Unit not needed anymore. Stopping. May 5 17:26:48 talos daemon.info occ-active.sh[20580]: /usr/bin/occ-active.sh: line 54: echo: write error: No such device May 5 17:26:48 talos daemon.info occ-active.sh[20580]: /usr/bin/occ-active.sh: line 55: echo: write error: No such device May 5 17:26:48 talos daemon.info systemd[1]: xyz.openbmc_project.Hwmon@gpio\x2dfsi-cfam\x400\x2c0-hub\x403400-cfam\x401\x2c0-sbefifo\x402400-occ\x402-occ\x2dhwmon\x402.service: Unit not needed anymore. Stopping. May 5 17:26:48 talos daemon.info systemd[1]: Stopped Phosphor Hwmon Poller. May 5 17:26:48 talos daemon.info systemd[1]: Stopped Phosphor Hwmon Poller. May 5 17:26:48 talos daemon.info systemd[1]: Stopped target Host0 IPL Complete. May 5 17:26:48 talos daemon.info systemd[1]: Stopped target Power0 (On). May 5 17:26:48 talos daemon.info systemd[1]: Stopped target Power0 On. May 5 17:26:48 talos daemon.info systemd[1]: Stopped Assert power_on LED. May 5 17:26:48 talos daemon.info systemd[1]: Stopped Wait for Power0 to turn on. May 5 17:26:48 talos daemon.info systemd[1]: Stopped Start Power0. May 5 17:26:48 talos daemon.info systemd[1]: Stopped target Power0 On (Pre). May 5 17:26:48 talos daemon.info systemd[1]: Stopped Reload mboxd during power on. May 5 17:26:48 talos daemon.info systemd[1]: Started OpenPOWER OCC Active Disable. May 5 17:26:49 talos daemon.info systemd[1]: Reached target Stop Host0 (Pre). May 5 17:26:50 talos daemon.info systemd[1]: Started Wait for /org/openbmc/HostIpmi/1. May 5 17:26:50 talos daemon.info systemd[1]: Starting Soft power off of the host... May 5 17:26:54 talos kern.info ipmid[1019]: Pushing cmd on to queue May 5 17:26:54 talos kern.info ipmid[1019]: Pushing cmd on to queue May 5 17:26:54 talos kern.info ipmid[1019]: Asserting SMS Attention May 5 17:26:54 talos daemon.info phosphor-ledmanager[871]: Asserting LEDs May 5 17:26:54 talos daemon.info systemd[1]: Started Assert power_on LED. May 5 17:26:54 talos kern.info ipmid[1019]: SMS Attention asserted May 5 17:26:57 talos kern.err ipmid[1019]: Host control timeout hit! May 5 17:26:57 talos kern.info ipmid[1019]: Timer expired May 5 17:26:57 talos kern.debug phosphor-softpoweroff[20638]: Host control signal values May 5 17:26:57 talos kern.info phosphor-softpoweroff[20638]: Timeout on host attention, continue with power down May 5 17:26:57 talos daemon.info systemd[1]: Started Soft power off of the host. May 5 17:26:57 talos daemon.info systemd[1]: Reached target Host0 (Stopping). May 5 17:26:57 talos daemon.info systemd[1]: Reached target Host0 (Stopped). May 5 17:26:57 talos daemon.info systemd[1]: Reached target Power0 Off (Pre). May 5 17:26:58 talos daemon.info systemd[1]: Started Stop Power0. May 5 17:26:58 talos daemon.info systemd[1]: Starting Wait for Power0 to turn off... May 5 17:27:00 talos daemon.info system_manager.py[962]: Running System State: HOST_POWERING_OFF May 5 17:27:00 talos daemon.info power_control.exe[1027]: PowerControl: setting power up BMC_POWER_UP to 0 May 5 17:27:00 talos user.info kernel: [ 1749.940000] ftgmac100 1e660000.ethernet eth0: NCSI: LSC AEN - channel 0 state down May 5 17:27:00 talos user.info kernel: [ 1749.960000] ftgmac100 1e660000.ethernet eth0: NCSI: suspending channel 0 May 5 17:27:00 talos user.debug kernel: [ 1749.960000] ftgmac100 1e660000.ethernet eth0: NCSI: Channel 0 added to queue (link down) May 5 17:27:00 talos user.info kernel: [ 1749.960000] ftgmac100 1e660000.ethernet eth0: NCSI: configuring channel 0 May 5 17:27:00 talos user.debug kernel: [ 1750.030000] ftgmac100 1e660000.ethernet eth0: no vlan ids left to set May 5 17:27:00 talos user.debug kernel: [ 1750.030000] ftgmac100 1e660000.ethernet eth0: NCSI: channel 0 config done May 5 17:27:00 talos user.warn kernel: [ 1750.030000] ftgmac100 1e660000.ethernet eth0: NCSI: channel 0 link down after config May 5 17:27:00 talos user.debug kernel: [ 1750.030000] ftgmac100 1e660000.ethernet eth0: NCSI: No more channels to process May 5 17:27:00 talos user.info kernel: [ 1750.030000] ftgmac100 1e660000.ethernet eth0: NCSI interface down May 5 17:27:01 talos daemon.info system_manager.py[962]: Running System State: HOST_POWERED_OFF May 5 17:27:01 talos daemon.info systemd[1]: Started Wait for Power0 to turn off. May 5 17:27:01 talos daemon.info systemd[1]: Reached target Power0 Off. May 5 17:27:01 talos daemon.info systemd[1]: Reached target Chassis0 (Power Off). May 5 17:27:01 talos daemon.info systemd[1]: Reached target Stop Host0. May 5 17:27:01 talos daemon.info systemd[1]: Reached target Power0 Host Off. May 5 17:27:01 talos kern.info phosphor-host-state-manager[1066]: Received signal that host is off May 5 17:27:01 talos kern.info phosphor-host-state-manager[1066]: Change to Host State May 5 17:27:01 talos kern.info phosphor-chassis-state-manager[1024]: Received signal that power OFF is complete May 5 17:27:01 talos kern.info phosphor-chassis-state-manager[1024]: Change to Chassis Power State May 5 17:27:01 talos kern.info phosphor-timemanager[1072]: Changing time settings allowed now May 5 17:27:04 talos user.info kernel: [ 1753.660000] ftgmac100 1e660000.ethernet eth0: NCSI: LSC AEN - channel 0 state up May 5 17:27:04 talos user.info kernel: [ 1753.660000] ftgmac100 1e660000.ethernet eth0: NCSI: configuring channel 0 May 5 17:27:04 talos user.debug kernel: [ 1753.670000] ftgmac100 1e660000.ethernet eth0: no vlan ids left to set May 5 17:27:04 talos user.debug kernel: [ 1753.690000] ftgmac100 1e660000.ethernet eth0: NCSI: channel 0 config done May 5 17:27:04 talos user.debug kernel: [ 1753.690000] ftgmac100 1e660000.ethernet eth0: NCSI: No more channels to process May 5 17:27:04 talos user.info kernel: [ 1753.690000] ftgmac100 1e660000.ethernet eth0: NCSI interface up (obmcutil poweron) May 5 17:27:46 talos kern.info phosphor-host-state-manager[1066]: Host State transaction request May 5 17:27:47 talos daemon.info systemd[1]: Starting Reload mboxd during power on... May 5 17:27:47 talos daemon.info systemd[1]: Started Phosphor poweron watchdog. May 5 17:27:47 talos daemon.info systemd[1]: Stopped target Stop Host0. May 5 17:27:47 talos daemon.info systemd[1]: Stopped target Power0 Off. May 5 17:27:47 talos daemon.info systemd[1]: Starting Wait for Power0 to turn on... May 5 17:27:47 talos daemon.info systemd[1]: Starting mapper subtree-remove /xyz/openbmc_project/software:xyz.openbmc_project.Software.ActivationBlocksTransition... May 5 17:27:47 talos daemon.info systemd[1]: Started Phosphor GPIO checkstop monitor. May 5 17:27:47 talos daemon.info systemd[1]: Stopped target Power0 Host Off. May 5 17:27:47 talos daemon.info systemd[1]: Stopped target Chassis0 (Power Off). May 5 17:27:47 talos daemon.info systemd[1]: Stopped Wait for Power0 to turn off. May 5 17:27:47 talos daemon.info systemd[1]: Stopped Stop Power0. May 5 17:27:47 talos daemon.info systemd[1]: Stopped target Power0 Off (Pre). May 5 17:27:47 talos daemon.info systemd[1]: Stopped target Host0 (Stopped). May 5 17:27:47 talos daemon.info systemd[1]: Stopped target Host0 (Stopping). May 5 17:27:47 talos daemon.info systemd[1]: Stopped target Stop Host0 (Pre). May 5 17:27:47 talos daemon.info systemd[1]: Starting Assert power_on LED... May 5 17:27:47 talos daemon.info systemd[1]: Stopped Assert power_on LED. May 5 17:27:47 talos kern.info phosphor-host-state-manager[1066]: Received signal that host is off May 5 17:27:47 talos kern.info phosphor-host-state-manager[1066]: Change to Host State May 5 17:27:47 talos kern.info phosphor-chassis-state-manager[1024]: Received signal that power OFF is complete May 5 17:27:47 talos kern.info phosphor-chassis-state-manager[1024]: Change to Chassis Power State May 5 17:27:47 talos daemon.info mboxctl[20763]: Reset: Success May 5 17:27:47 talos daemon.info systemd[1]: Started Reload mboxd during power on. May 5 17:27:47 talos daemon.info systemd[1]: Reached target Power0 On (Pre). May 5 17:27:47 talos daemon.info systemd[1]: Starting Start Power0... May 5 17:27:47 talos daemon.info systemd[1]: Started mapper subtree-remove /xyz/openbmc_project/software:xyz.openbmc_project.Software.ActivationBlocksTransition. May 5 17:27:48 talos daemon.info phosphor-ledmanager[871]: Asserting LEDs May 5 17:27:48 talos daemon.info systemd[1]: Started Assert power_on LED. May 5 17:27:48 talos daemon.info power_control.exe[1027]: PowerControl: setting power up BMC_POWER_UP to 1 May 5 17:27:48 talos daemon.info systemd[1]: Started Start Power0. May 5 17:27:48 talos daemon.info system_manager.py[962]: Running System State: HOST_POWERING_ON May 5 17:27:48 talos daemon.info systemd[1]: Starting Perform AVS bus workaround on VRMs... May 5 17:27:48 talos daemon.info systemd[1]: Started Perform AVS bus workaround on VRMs. May 5 17:27:48 talos daemon.info systemd[1]: Starting Disable the AVS bus on the VRMs... May 5 17:27:49 talos daemon.info systemd[1]: Started Disable the AVS bus on the VRMs. May 5 17:27:49 talos daemon.info systemd[1]: Starting Apply voltage overrides to VRMs... May 5 17:27:49 talos daemon.info vrm.sh[20801]: rail set read current May 5 17:27:49 talos daemon.info vrm.sh[20801]: ------- ------- ------- ------- May 5 17:27:49 talos daemon.info vrm.sh[20801]: vdna 0.898V 0.004V 0.000A May 5 17:27:49 talos daemon.info vrm.sh[20801]: vdnb 0.898V 0.004V 0.000A May 5 17:27:49 talos daemon.info systemd[1]: Started Apply voltage overrides to VRMs. May 5 17:27:49 talos daemon.info systemd[1]: Starting Enable the AVS bus on VRMs... May 5 17:27:50 talos daemon.info systemd[1]: Started Enable the AVS bus on VRMs. May 5 17:27:58 talos kern.info phosphor-network-manager[957]: Refreshing the objects. May 5 17:27:58 talos kern.err phosphor-network-manager[957]: ConfigParser: Key not found May 5 17:27:58 talos kern.err phosphor-network-manager[957]: The operation failed internally. May 5 17:27:58 talos kern.info phosphor-network-manager[957]: Exception occurred during getting of DHCP value May 5 17:27:58 talos kern.err phosphor-network-manager[957]: ConfigParser: Key not found May 5 17:27:58 talos kern.err phosphor-network-manager[957]: The operation failed internally. May 5 17:27:58 talos kern.info phosphor-network-manager[957]: Unable to find the NTP server configuration. May 5 17:27:58 talos daemon.notice dbus[882]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' May 5 17:27:58 talos daemon.info systemd[1]: Starting Hostname Service... May 5 17:27:58 talos daemon.notice dbus[882]: [system] Successfully activated service 'org.freedesktop.hostname1' May 5 17:27:58 talos daemon.info systemd[1]: Started Hostname Service. May 5 17:27:58 talos kern.info phosphor-network-manager[957]: Refreshing complete. May 5 17:27:58 talos kern.info phosphor-network-manager[957]: Timer expired May 5 17:28:01 talos daemon.info power_control.exe[1027]: ERROR PowerControl: Pgood poll timeout May 5 17:28:04 talos user.info kernel: [ 1814.160000] ftgmac100 1e660000.ethernet eth0: NCSI: LSC AEN - channel 0 state up May 5 17:28:17 talos daemon.warn systemd[1]: op-wait-power-on@0.service: Start operation timed out. Terminating. May 5 17:28:17 talos daemon.warn systemd[1]: op-wait-power-on@0.service: Main process exited, code=killed, status=15/TERM May 5 17:28:17 talos daemon.err systemd[1]: Failed to start Wait for Power0 to turn on. May 5 17:28:17 talos daemon.warn systemd[1]: Dependency failed for Chassis0 (Power On). May 5 17:28:17 talos daemon.warn systemd[1]: Dependency failed for Start Host0. May 5 17:28:17 talos daemon.notice systemd[1]: obmc-host-start@0.target: Job obmc-host-start@0.target/start failed with result 'dependency'. May 5 17:28:17 talos daemon.info systemd[1]: obmc-host-start@0.target: Triggering OnFailure= dependencies. May 5 17:28:17 talos daemon.notice systemd[1]: obmc-chassis-poweron@0.target: Job obmc-chassis-poweron@0.target/start failed with result 'dependency'. May 5 17:28:17 talos daemon.info systemd[1]: obmc-chassis-poweron@0.target: Triggering OnFailure= dependencies. May 5 17:28:17 talos daemon.notice systemd[1]: op-wait-power-on@0.service: Unit entered failed state. May 5 17:28:17 talos daemon.warn systemd[1]: op-wait-power-on@0.service: Failed with result 'timeout'. May 5 17:28:17 talos daemon.info systemd[1]: Stopped Assert power_on LED. May 5 17:28:17 talos daemon.info systemd[1]: Stopped Enable the AVS bus on VRMs. May 5 17:28:17 talos daemon.info systemd[1]: Stopped Apply voltage overrides to VRMs. May 5 17:28:17 talos daemon.info systemd[1]: Starting OpenPOWER OCC Active Disable... May 5 17:28:17 talos daemon.info systemd[1]: Stopping Phosphor GPIO checkstop monitor... May 5 17:28:17 talos daemon.info systemd[1]: Stopped Disable the AVS bus on the VRMs. May 5 17:28:17 talos daemon.info systemd[1]: Stopped Perform AVS bus workaround on VRMs. May 5 17:28:17 talos daemon.info systemd[1]: Stopped Start Power0. May 5 17:28:17 talos daemon.info systemd[1]: Stopped target Power0 On (Pre). May 5 17:28:17 talos daemon.info systemd[1]: Stopped Reload mboxd during power on. May 5 17:28:17 talos daemon.info occ-active.sh[20879]: Found 2 CPU(s) May 5 17:28:17 talos daemon.info systemd[1]: Starting Assert power_on LED... May 5 17:28:17 talos daemon.info systemd[1]: Stopping Phosphor poweron watchdog... May 5 17:28:18 talos daemon.info systemd[1]: Stopped Phosphor poweron watchdog. May 5 17:28:18 talos daemon.info systemd[1]: Stopped Phosphor GPIO checkstop monitor. May 5 17:28:18 talos daemon.info occ-active.sh[20879]: /usr/bin/occ-active.sh: line 54: echo: write error: No such device May 5 17:28:18 talos daemon.info occ-active.sh[20879]: /usr/bin/occ-active.sh: line 55: echo: write error: No such device May 5 17:28:18 talos daemon.info occ-active.sh[20879]: /usr/bin/occ-active.sh: line 56: echo: write error: No such device May 5 17:28:18 talos daemon.info occ-active.sh[20879]: /usr/bin/occ-active.sh: line 57: echo: write error: No such device May 5 17:28:18 talos daemon.info systemd[1]: Started OpenPOWER OCC Active Disable. May 5 17:28:18 talos daemon.info systemd[1]: Reached target Stop Host0 (Pre). May 5 17:28:18 talos daemon.info systemd[1]: Reached target Host0 (Stopping). May 5 17:28:18 talos daemon.info systemd[1]: Reached target Host0 (Stopped). May 5 17:28:18 talos daemon.info systemd[1]: Reached target Power0 Off (Pre). May 5 17:28:18 talos daemon.info systemd[1]: Started Stop Power0. May 5 17:28:18 talos daemon.info systemd[1]: Starting Wait for Power0 to turn off... May 5 17:28:20 talos daemon.info power_control.exe[1027]: PowerControl: setting power up BMC_POWER_UP to 0 May 5 17:28:20 talos daemon.info system_manager.py[962]: Running System State: HOST_POWERING_OFF May 5 17:28:20 talos daemon.info phosphor-ledmanager[871]: Asserting LEDs May 5 17:28:20 talos daemon.info systemd[1]: Started Assert power_on LED. May 5 17:28:20 talos daemon.info systemd[1]: Started Wait for Power0 to turn off. May 5 17:28:20 talos daemon.info systemd[1]: Reached target Power0 Off. May 5 17:28:20 talos daemon.info systemd[1]: Reached target Chassis0 (Power Off). May 5 17:28:20 talos daemon.info systemd[1]: Reached target Stop Host0. May 5 17:28:20 talos kern.info phosphor-chassis-state-manager[1024]: Received signal that power OFF is complete May 5 17:28:20 talos kern.info phosphor-chassis-state-manager[1024]: Change to Chassis Power State May 5 17:28:20 talos kern.info phosphor-host-state-manager[1066]: Received signal that host is off May 5 17:28:20 talos kern.info phosphor-host-state-manager[1066]: Change to Host State