Solved

AOS Installation failed with error

  • 8 March 2021
  • 1 reply
  • 5149 views

Badge

Hello All,

I tried to install AOS 5.19.2 with foundation 4.6.0 and nutanix but I faced from some issues.

 

please find the below logs for referensce

 

2021-03-08 11:37:42,286Z DEBUG Setting state of <ImagingStepValidation(<NodeConfig(172.21.10.65) @8170>) @8450> from PENDING to RUNNING
2021-03-08 11:37:42,292Z INFO Running <ImagingStepValidation(<NodeConfig(172.21.10.65) @8170>) @8450>
2021-03-08 11:37:42,296Z DEBUG Cache MISS: key(<function common_validations at 0x03A09FB0>_()_{'global_config': <foundation.config_manager.GlobalConfig object at 0x04CB1070>})
2021-03-08 11:37:42,298Z INFO Validating parameters. This may take few minutes
2021-03-08 11:37:42,299Z INFO Validating parameters. This may take few minutes
2021-03-08 11:37:42,299Z INFO Validating parameters. This may take few minutes
2021-03-08 11:39:02,743Z DEBUG Validating hyperv: C:\Program Files (x86)\Nutanix\Portable Foundation\isos\hypervisor\hyperv\SW_DVD9_Win_Server_STD_CORE_2019_1809.1_64Bit_English_DC_STD_MLF_X22-02970.ISO
2021-03-08 11:39:02,743Z DEBUG Starting whitelist_check
2021-03-08 11:39:02,743Z DEBUG in_memory iso_whitelist version: 1612759261
2021-03-08 11:39:02,743Z DEBUG Cache HIT: key(<function get_nos_version_from_tarball at 0x03111F70>_()_{'nos_package_path': u'C:\\Program Files (x86)\\Nutanix\\Portable Foundation\\nos\\nutanix_installer_package-release-euphrates-5.19.1-stable-x86_64.tar.gz'})
2021-03-08 11:39:02,743Z DEBUG Finished whitelist_check
2021-03-08 11:39:02,743Z INFO metadata update: {"iso_entry": {"min_foundation": "4.5.2", "deprecated": null, "min_nos": "5.17", "friendly_name": "Windows 2019 VL (SW_DVD9_Win_Server_STD_CORE_2019_1809.1_64Bit_English_DC_STD_MLF_X22-02970.ISO)", "compatible_versions": {"hyperv": [".*2019.*"]}, "version": "2019", "filesize": 5099231232, "hypervisor": "hyperv", "unsupported_hardware": [], "skus": ["datacenter", "standard", "standard_gui", "datacenter_gui"]}}
2021-03-08 11:39:02,743Z INFO Ensuring there is no Haswell, Broadwell mix in the same chassis for cluster UAEAUHSIHVCLS00
2021-03-08 11:39:02,836Z WARNING tmap was called <function read_hardware_config_from_any at 0x033B87B0> with empty args and kwargs, ignoring
2021-03-08 11:39:02,836Z INFO Running one and two node validations
2021-03-08 11:39:44,934Z INFO Checking whether hypervisor-specific drivers are present inside Foundation
2021-03-08 11:39:44,934Z DEBUG Setting state of <ImagingStepValidation(<NodeConfig(172.21.10.65) @8170>) @8450> from RUNNING to FINISHED
2021-03-08 11:39:44,934Z INFO Completed <ImagingStepValidation(<NodeConfig(172.21.10.65) @8170>) @8450>
2021-03-08 11:39:44,944Z DEBUG Setting state of <GetNosVersion(<NodeConfig(172.21.10.65) @8170>) @80d0> from PENDING to RUNNING
2021-03-08 11:39:44,946Z INFO Running <GetNosVersion(<NodeConfig(172.21.10.65) @8170>) @80d0>
2021-03-08 11:39:44,947Z INFO Node IP: CVM(172.21.10.65) HOST(172.21.10.61) IPMI(172.21.10.71)
2021-03-08 11:39:44,948Z DEBUG Cache HIT: key(<function get_nos_version_from_tarball at 0x03111F70>_(u'C:\\Program Files (x86)\\Nutanix\\Portable Foundation\\nos\\nutanix_installer_package-release-euphrates-5.19.1-stable-x86_64.tar.gz',)_{})
2021-03-08 11:39:44,950Z INFO NOS Version is: 5.19.1
2021-03-08 11:39:44,950Z INFO metadata update: {"nos_version": "5.19.1"}
2021-03-08 11:39:44,950Z DEBUG Setting state of <GetNosVersion(<NodeConfig(172.21.10.65) @8170>) @80d0> from RUNNING to FINISHED
2021-03-08 11:39:44,950Z INFO Completed <GetNosVersion(<NodeConfig(172.21.10.65) @8170>) @80d0>
2021-03-08 11:39:44,950Z DEBUG Setting state of <ImagingStepTypeDetection(<NodeConfig(172.21.10.65) @8170>) @8570> from PENDING to RUNNING
2021-03-08 11:39:44,966Z INFO Running <ImagingStepTypeDetection(<NodeConfig(172.21.10.65) @8170>) @8570>
2021-03-08 11:39:44,966Z INFO Attempting to detect device type on 172.21.10.71
2021-03-08 11:39:44,966Z INFO Factory mode is False
2021-03-08 11:39:45,426Z INFO Manufacturer ID = 10876
2021-03-08 11:39:45,973Z DEBUG Executed command get iDrac.Info.Type with stdout: 
stderr:404 Client Error: Not Found for url: https://172.21.10.71/cgi-bin/login
2021-03-08 11:39:48,032Z ERROR Could not execute '<obfuscated_command>'
Traceback (most recent call last):
  File "bmc_utils\tools.py", line 78, in system
  File "site-packages\subprocess32.py", line 617, in __init__
  File "site-packages\subprocess32.py", line 922, in _execute_child
WindowsError: [Error 2] The system cannot find the file specified
2021-03-08 11:39:48,032Z ERROR Command '<obfuscated_command>' returned error code -1
stdout:

stderr:

2021-03-08 11:39:48,079Z DEBUG SMC: X11DPT-B-G7-NI22
2021-03-08 11:39:48,079Z INFO Detected class smc_cgi for node with IPMI IP 172.21.10.71
2021-03-08 11:39:48,095Z ERROR Could not execute '<obfuscated_command>'
Traceback (most recent call last):
  File "bmc_utils\tools.py", line 78, in system
  File "site-packages\subprocess32.py", line 617, in __init__
  File "site-packages\subprocess32.py", line 922, in _execute_child
WindowsError: [Error 2] The system cannot find the file specified
2021-03-08 11:39:48,095Z ERROR Command '<obfuscated_command>' returned error code -1
stdout:

stderr:

2021-03-08 11:39:48,095Z DEBUG Setting state of <ImagingStepTypeDetection(<NodeConfig(172.21.10.65) @8170>) @8570> from RUNNING to FINISHED
2021-03-08 11:39:48,095Z INFO Completed <ImagingStepTypeDetection(<NodeConfig(172.21.10.65) @8170>) @8570>
2021-03-08 11:39:48,095Z DEBUG Setting state of <ImagingStepPrepareVendor(<NodeConfig(172.21.10.65) @8170>) @80b0> from PENDING to RUNNING
2021-03-08 11:39:48,095Z INFO Running <ImagingStepPrepareVendor(<NodeConfig(172.21.10.65) @8170>) @80b0>
2021-03-08 11:39:48,095Z DEBUG Setting state of <ImagingStepPrepareVendor(<NodeConfig(172.21.10.65) @8170>) @80b0> from RUNNING to FINISHED
2021-03-08 11:39:48,095Z INFO Completed <ImagingStepPrepareVendor(<NodeConfig(172.21.10.65) @8170>) @80b0>
2021-03-08 11:39:48,095Z DEBUG Setting state of <ImagingStepInitIPMI(<NodeConfig(172.21.10.65) @8170>) @8190> from PENDING to RUNNING
2021-03-08 11:39:48,111Z DEBUG Setting state of <ImagingStepInitCVM(<NodeConfig(172.21.10.65) @8170>) @8070> from PENDING to RUNNING
2021-03-08 11:39:48,111Z INFO Running <ImagingStepInitIPMI(<NodeConfig(172.21.10.65) @8170>) @8190>
2021-03-08 11:39:48,111Z INFO Running <ImagingStepInitCVM(<NodeConfig(172.21.10.65) @8170>) @8070>
2021-03-08 11:39:48,111Z INFO Making node specific Phoenix image
2021-03-08 11:39:48,111Z DEBUG skipped, this node will be imaged via IPMI
2021-03-08 11:39:48,111Z DEBUG Setting state of <ImagingStepInitCVM(<NodeConfig(172.21.10.65) @8170>) @8070> from RUNNING to FINISHED
2021-03-08 11:39:48,111Z INFO Completed <ImagingStepInitCVM(<NodeConfig(172.21.10.65) @8170>) @8070>
2021-03-08 11:39:49,415Z INFO Using C:\Program Files (x86)\Nutanix\Portable Foundation\lib/foundation-platforms\aurora-1.4.0-7954202.tar.gz
2021-03-08 11:39:49,415Z DEBUG Cache HIT: key(<function get_md5sum at 0x033B1D30>_('C:\\Program Files (x86)\\Nutanix\\Portable Foundation\\lib\\foundation-platforms\\aurora-1.4.0-7954202.tar.gz',)_{})
2021-03-08 11:39:49,415Z INFO Using C:\Program Files (x86)\Nutanix\Portable Foundation\lib/foundation-platforms\tartarus-1.0.1-39d983b3.tar.gz
2021-03-08 11:39:49,415Z DEBUG Cache HIT: key(<function get_md5sum at 0x033B1D30>_('C:\\Program Files (x86)\\Nutanix\\Portable Foundation\\lib\\foundation-platforms\\tartarus-1.0.1-39d983b3.tar.gz',)_{})
2021-03-08 11:39:49,415Z INFO Using C:\Program Files (x86)\Nutanix\Portable Foundation\tmp\sessions\20210308-153739-4\files\features_node_172.21.10.65.json
2021-03-08 11:39:49,415Z DEBUG Cache MISS: key(<function get_md5sum at 0x033B1D30>_('C:\\Program Files (x86)\\Nutanix\\Portable Foundation\\tmp\\sessions\\20210308-153739-4\\files\\features_node_172.21.10.65.json',)_{})
2021-03-08 11:39:49,415Z INFO Using C:\Program Files (x86)\Nutanix\Portable Foundation\lib/foundation-platforms/hcl.json
2021-03-08 11:39:49,415Z DEBUG Cache HIT: key(<function get_md5sum at 0x033B1D30>_('C:\\Program Files (x86)\\Nutanix\\Portable Foundation\\lib\\foundation-platforms\\hcl.json',)_{})
2021-03-08 11:39:49,430Z INFO Using c:\program files (x86)\nutanix\portable foundation\lib\foundation-platforms\foundation_layout-2.2+r.1328.8638019-py2.7.egg
2021-03-08 11:39:49,430Z DEBUG Cache HIT: key(<function get_md5sum at 0x033B1D30>_('c:\\program files (x86)\\nutanix\\portable foundation\\lib\\foundation-platforms\\foundation_layout-2.2+r.1328.8638019-py2.7.egg',)_{})
2021-03-08 11:39:49,447Z DEBUG Generating updates config json C:\Program Files (x86)\Nutanix\Portable Foundation\tmp\sessions\20210308-153739-4\files\updates_config_node_172.21.10.65.json
2021-03-08 11:39:49,447Z DEBUG Cache MISS: key(<function get_md5sum at 0x033B1D30>_('C:\\Program Files (x86)\\Nutanix\\Portable Foundation\\tmp\\sessions\\20210308-153739-4\\files\\updates_config_node_172.21.10.65.json',)_{})
2021-03-08 11:39:49,447Z DEBUG Cache HIT: key(<function get_md5sum at 0x033B1D30>_('C:\\Program Files (x86)\\Nutanix\\Portable Foundation\\lib\\phoenix\\x86_64\\squashfs.img',)_{})
2021-03-08 11:39:49,461Z DEBUG Cache HIT: key(<function get_md5sum at 0x033B1D30>_('C:\\Program Files (x86)\\Nutanix\\Portable Foundation\\lib\\phoenix\\x86_64\\squashfs.img',)_{})
2021-03-08 11:39:49,461Z DEBUG using C:\Program Files (x86)\Nutanix\Portable Foundation\lib\bin\cygwin\mkisofs.exe for mkisofs
2021-03-08 11:39:49,900Z DEBUG Cache MISS: key(<function get_md5sum at 0x033B1D30>_('C:\\Program Files (x86)\\Nutanix\\Portable Foundation\\tmp\\sessions\\20210308-153739-4\\phoenix_node_isos\\foundation.node_172.21.10.65.iso',)_{})
2021-03-08 11:39:50,009Z INFO Setting boot mode
2021-03-08 11:39:50,009Z DEBUG No implementation found for setting boot mode to BootMode.LEGACY. Skipping
2021-03-08 11:39:50,009Z INFO Powering off node
2021-03-08 11:39:50,039Z INFO current power state is on
2021-03-08 11:39:50,039Z DEBUG changing power state to off, attempt 1/4
2021-03-08 11:39:59,210Z INFO changed power state to off
2021-03-08 11:40:04,226Z INFO Mounting phoenix iso image
2021-03-08 11:40:04,226Z INFO Starting SMCGI Virtual CDROM
2021-03-08 11:40:04,226Z INFO Detecting power status
2021-03-08 11:40:08,415Z INFO current power state is off
2021-03-08 11:40:08,415Z INFO Attaching virtual media: http://172.21.10.111:8000/files/tmp/sessions/20210308-153739-4/phoenix_node_isos/foundation.node_172.21.10.65.iso
2021-03-08 11:40:08,937Z WARNING Req: cgi=op, op=config_iso, args={'path': '/files/tmp/sessions/20210308-153739-4/phoenix_node_isos/foundation.node_172.21.10.65.iso', 'host': 'http://172.21.10.111:8000', 'pwd': '', 'user': ''}
2021-03-08 11:40:09,160Z WARNING Resp: text=ok
2021-03-08 11:40:09,160Z WARNING Req: cgi=op, op=mount_iso, args={}
2021-03-08 11:40:09,355Z WARNING Resp: text=VMCOMCODE=001
2021-03-08 11:40:09,355Z WARNING Req: cgi=op, op=vm_status, args={}
2021-03-08 11:40:09,677Z WARNING Resp: text=<?xml version="1.0" ?>
<VM>
<CODE NO="1" STATUS="1"/>
<DEVICE ID="0" STATUS="255"/>
<DEVICE ID="1" STATUS="255"/>
<DEVICE ID="2" STATUS="255"/>
</VM>
2021-03-08 11:40:10,694Z WARNING Req: cgi=op, op=vm_status, args={}
2021-03-08 11:40:10,865Z WARNING Resp: text=<?xml version="1.0" ?>
<VM>
<CODE NO="1" STATUS="1"/>
<DEVICE ID="0" STATUS="4"/>
<DEVICE ID="1" STATUS="255"/>
<DEVICE ID="2" STATUS="255"/>
</VM>
2021-03-08 11:40:10,865Z INFO Setting cdrom as boot device for next boot
2021-03-08 11:40:10,897Z INFO Next boot device is set to optical
2021-03-08 11:40:10,927Z INFO Power status is off
2021-03-08 11:40:10,927Z INFO Powering up node
2021-03-08 11:40:17,052Z INFO Sleeping for 40 seconds
2021-03-08 11:40:57,084Z INFO Power status is on
2021-03-08 11:40:57,099Z INFO BMC should be booting into phoenix
2021-03-08 11:40:57,099Z INFO Waiting for remote node to boot into phoenix, this may take 20 minutes
2021-03-08 11:59:10,971Z INFO Umounting Virtual CDROM using SMCGI
2021-03-08 11:59:10,974Z WARNING Req: cgi=op, op=umount_iso, args={}
2021-03-08 11:59:11,552Z WARNING Resp: text=VMCOMCODE=001
2021-03-08 11:59:11,555Z WARNING Req: cgi=op, op=vm_status, args={}
2021-03-08 11:59:11,825Z WARNING Resp: text=<?xml version="1.0" ?>
<VM>
<CODE NO="1" STATUS="0"/>
<DEVICE ID="0" STATUS="255"/>
<DEVICE ID="1" STATUS="255"/>
<DEVICE ID="2" STATUS="255"/>
</VM>
2021-03-08 11:59:11,825Z ERROR Exception in <ImagingStepInitIPMI(<NodeConfig(172.21.10.65) @8170>) @8190>
Traceback (most recent call last):
  File "foundation\decorators.py", line 77, in wrap_method
  File "foundation\imaging_step_init_ipmi.py", line 269, in run
  File "foundation\imaging_step_init_ipmi.py", line 147, in boot_phoenix
  File "foundation\imaging_step.py", line 350, in wait_for_event
StandardError: Received "fatal" in waiting for event "phoenix_callback": Aborted from API
2021-03-08 11:59:11,832Z ERROR Exception in running <ImagingStepInitIPMI(<NodeConfig(172.21.10.65) @8170>) @8190>
Traceback (most recent call last):
  File "foundation\imaging_step.py", line 161, in _run
  File "foundation\decorators.py", line 77, in wrap_method
  File "foundation\imaging_step_init_ipmi.py", line 269, in run
  File "foundation\imaging_step_init_ipmi.py", line 147, in boot_phoenix
  File "foundation\imaging_step.py", line 350, in wait_for_event
StandardError: Received "fatal" in waiting for event "phoenix_callback": Aborted from API
2021-03-08 11:59:11,832Z DEBUG Setting state of <ImagingStepInitIPMI(<NodeConfig(172.21.10.65) @8170>) @8190> from RUNNING to FAILED
 

icon

Best answer by Sudhir9 15 March 2021, 18:24

View original

This topic has been closed for comments

1 reply

Userlevel 2
Badge +4

Hello @Muhammed Ashraf 

From the logs you have shared 

2021-03-08 11:40:57,084Z INFO Power status is on
2021-03-08 11:40:57,099Z INFO BMC should be booting into phoenix
2021-03-08 11:40:57,099Z INFO Waiting for remote node to boot into phoenix, this may take 20 minutes
2021-03-08 11:59:10,971Z INFO Umounting Virtual CDROM using SMCGI
2021-03-08 11:59:10,974Z WARNING Req: cgi=op, op=umount_iso, args={}
2021-03-08 11:59:11,552Z WARNING Resp: text=VMCOMCODE=001
2021-03-08 11:59:11,555Z WARNING Req: cgi=op, op=vm_status, args={}
2021-03-08 11:59:11,825Z WARNING Resp: text=<?xml version="1.0" ?>
<VM>

Looks like after booting to VMs Foundation wasn’t able to reach the node on the network, even after waiting for 20 minutes, it will indicate 2 things. 

  1. Node failed to boot or waiting for some keyboard input. ( Check from IPMI Console) 
  2. Node booted to phoenix but phoenix couldn’t communicate to foundation IP using the CVM IP provided in process. ( Different Subnet / Vlan / Switch port configuration issue )

For 1st issue you can check the console and should be able to get an idea of how to resolve it.

For 2nd issue recommendation is to use a flat switch with no vlan / custom configuration to finish the foundation installation, and connect your laptop / PC running foundation VM / Software to same switch. 

 

Our Field Installation Guide have all the best practices, issues noticed in field and related solutions.