Nutanix AHV Foundation Process Logs Analysis

Nutanix foundation appliance is the way to install/ image / re-image the Nutanix HCI nodes aside foundation appliance generate logs to determine the foundation process status, error to help in troubleshooting with any supported hypervisor e.g AHV, VMware Esxi, Microsoft Hyper-V or Citrix Xen server.

Nutanix statadalone foundation VM has many versions e.g 3.x and 4.x is latest to do foundation of supported OEM partners node e.g Dell, Lenovo, HPE DX Appliance, Cisco UCS etc.

Nutanix Foundation Logs Analysis

Nutanix foundation appliance tool generates logs to help to understand:
How Nutanix Foundation appliance works while installing Nutanix AHV hypervisor.

Lets explorer the foundation process steps, installation status, Errors, Warnings and in Troubleshooting as well.

I have complete foundation process logs of Nutanix AHV hypervisor installation, lets do logs analysis and will explain logs in detailed.

Stage 1 : Started Nuatnix foundation process

20190721 00:27:25 INFO Validating parameters. This may take few minutes
20190721 00:27:28 INFO Running ) @74d0>
20190721 00:27:28 INFO Validating parameters. This may take few minutes
20190721 00:29:51 ERROR Node with ip 10.x.x.x. is not in cvm or is not reachable
20190721 00:29:54 ERROR Node with ip 10.x.x.x is not in phoenix or is not reachable
20190721 00:29:57 ERROR Node with ip 10.x.x.x is not in cvm or is not reachable
20190721 00:30:00 ERROR Node with ip 10.x.x.x is not in phoenix or is not reachable

Analysis : When foundation process starts it validate the Nutanix AOS and Hypervisor binary image’s M5 Check-Sum for any corruption.
After then Nutanix Foundation initiate ping command to validate the Nutanix CVM IP address existence on network, hence CVM IP must be not reachable to proceed.

Troubleshooting : If any Nutanix CVM IP address conflict then process will be failed.

Stage 2 : Foundation process mapping CVM, Host and IPMI IP address to the node

 20190721 00:30:00 INFO Completed ) @74d0>  
20190721 00:30:00 INFO Running ) @75d0>
20190721 00:30:00 INFO Node IP: CVM(10.238.154.190) HOST(10.238.154.90) IPMI(10.238.154.81)
20190721 00:32:37 INFO NOS Version is: 99.0
20190721 00:32:37 INFO Completed ) @75d0>

Analysis : Foundation process required to map the specified IP address for Controller VM: CVM, Host and IPMI to proceed further.

Read more : Nutanix IPMI Interface Default Credential and IP Address

Stage 3 : Determine the Hardware through BMC interface

20190721 00:32:37 INFO Running ) @76d0>
20190721 00:32:37 INFO Attempting to detect device type on 10.x.x.x  20190721 00:32:37 DEBUG factory mode is False  20190721 00:32:37 INFO Checking if this is Quanta
20190721 00:32:37 INFO Checking if this is an Ironwood system.
20190721 00:32:38 INFO Checking if this is a Lenovo system.
20190721 00:32:38 INFO Checking if this is UCS standalone node  
20190721 00:32:38 INFO Checking if this is Dell  
20190721 00:32:38 DEBUG /opt/dell/srvadmin/sbin/racadm -r 10.x.x.x -u ADMIN -p ADMIN get iDrac.Info.Type  
20190721 00:32:39 ERROR Command '/opt/dell/srvadmin/sbin/racadm -r 10.x.x.x -u ADMIN -p ADMIN get iDrac.Info.Type' returned error code 1  stdout:  
Security Alert: Certificate is invalid - self signed certificate  Continuing execution. Use -S option for racadm to stop execution on certificate-related errors. 
stderr:  /opt/dell/srvadmin/sbin/racadm: line 13: printf: 0x: invalid hex number  ERROR: Unable to connect to RAC at specified IP address. 20190721 00:32:40 INFO Checking if this is HPE or NEC or HITACHI  20190721 00:32:41 INFO Checking if this is Inspur  
20190721 00:32:42 INFO Checking if this is SMC  
20190721 00:32:48 INFO Detected class smc_wa for node with IPMI IP 10.x.x.x  20190721 00:32:48 INFO Completed ) @76d0>

Analysis : Foundation Process check the all supported hardware e.g Dell, HPE, Lenovo, Quanta, Cisco UCS etc. to send applicable packet match.

Finally Foundation process detected the Nutanix Supermicro hardware in last lines.

Read more : Nutanix IPMI Security Rules in Data center

Stage 4 : Foundation preparing AOS package


20190721 00:32:48 INFO Running ) @77d0>
20190721 00:32:48 INFO ImagingStepPrepareDell skipped
20190721 00:32:48 INFO Completed ) @77d0>
20190721 00:32:48 INFO Running ) @78d0>
20190721 00:32:48 INFO Completed ) @78d0>
20190721 00:32:48 INFO Running ) @79d0>
20190721 00:32:48 INFO NOS version is 99.0
20190721 00:32:48 INFO Preparing NOS package

20190721 00:32:48 INFO Running ) @7ad0>
20190721 00:32:48 DEBUG skipped, this node will be imaged via IPMI
20190721 00:32:48 INFO Completed ) @7ad0>

Analysis : Foundation process is preparing AOS package to use it to image the node.

Read more : Nutanix AOS Release STS Vs LTS

Stage 5 : Making Phoenix Image


20190721 00:34:37 INFO Making node specific Phoenix image
20190721 00:34:46 INFO Powering off node
20190721 00:35:03 INFO current power state is on
20190721 00:35:03 DEBUG changing power state to off, attempt 1/4
20190721 00:35:11 INFO changed power state to off

Analysis : Foundation process creating a Phonenix image for each node going to be image along-with changing power state of node(s).

Stage 6 : Mounting created Phoenix Image to Node


20190721 00:35:16 INFO Mounting phoenix iso image
20190721 00:35:16 INFO Starting SMCIPMITool
20190721 00:35:20 INFO current power state is off
20190721 00:35:20 INFO Disconnecting virtual media
20190721 00:35:20 INFO Attaching virtual media: /home/nutanix/foundation/tmp/sessions/20190721-002725-2/phoenix_node_isos/foundation.node_10.x.x.x.iso
20190721 00:35:26 DEBUG [1/3] Checking virtual media: /home/nutanix/foundation/tmp/sessions/20190721-002725-2/phoenix_node_isos/foundation.node_10.x.x.x.iso
20190721 00:35:26 DEBUG vmwa status: vmwa status
Device 1: None
Device 2: ISO File [/home/nutanix/foundation/tmp/sessions/20190721-002725-2/phoenix_node_isos/foundation.node_10.x.x.x.iso]
, ASPD_T>, ASPD_T>
20190721 00:35:26 DEBUG Virtual media is mounted successfully: /home/nutanix/foundation/tmp/sessions/20190721-002725-2/phoenix_node_isos/foundation.node_10.x.x.x.iso

Analysis : Foundation proceess mount the Phoenix ISO image to each node on virtaul media ( CD-ROM ) using port number TCP-623. See Nutanix CVM Port Number list here.

Troubleshooting : If Nutanix Phoenix ISO image failed to mount on virutal media ( CD-ROM ) then there is possibilty that your laptop / desktop OS: Windows or Linux firewall is blocking the port number TCP-623 port.

I would suggest to disable the laptop/desktop OS: Windows or Linux firewall till foundation process running to image th node(s).

Stage 7 : Setting up first boot device


20190721 00:35:26 INFO Setting cdrom as boot device for next boot
20190721 00:35:27 INFO Next boot device is set to optical
20190721 00:35:27 INFO Power status is off
20190721 00:35:27 DEBUG changing power state to on, attempt 1/4
20190721 00:35:37 INFO changed power state to on
20190721 00:35:37 INFO Sleeping for 40 seconds
20190721 00:36:17 DEBUG [1/3] Checking virtual media: /home/nutanix/foundation/tmp/sessions/20190721-002725-2/phoenix_node_isos/foundation.node_10.238.154.190.iso
20190721 00:36:17 DEBUG vmwa status: vmwa status
Device 1: None
Device 2: ISO File [/home/nutanix/foundation/tmp/sessions/20190721-002725-2/phoenix_node_isos/foundation.node_10.238.154.190.iso]
, ASPD_T>, ASPD_T>

20190721 00:36:17 DEBUG Virtual media is mounted successfully: /home/nutanix/foundation/tmp/sessions/20190721-002725-2/phoenix_node_isos/foundation.node_10.238.154.190.iso

Analysis : Foundation process set the first boot device to virtual media CD-ROM which is already mounted the Phoenix ISO Image.

Stage 8 : Change node power state


20190721 00:36:17 INFO Power status is on
20190721 00:36:17 INFO BMC should be booting into phoenix
20190721 00:36:17 INFO Waiting for remote node to boot into phoenix, this may take 20 minutes
20190721 00:39:19 INFO phoenix_callback: greetings from phoenix
20190721 00:39:20 INFO Rebooted into Phoenix successfully
20190721 00:39:20 INFO Exiting SMCIPMITool
20190721 00:39:21 INFO Completed ) @79d0>

Analysis : Foundation will change the power state to ON and boot node from Virtual Media CD-ROM with Phoenix ISO Image.

Read more : How to Shutdown Nutanix AHV Host and Nutanix CVM

Stage 9 : Collecting hardware information

 20190721 00:39:21 INFO Running ) @7bd0>
20190721 00:39:21 INFO Rebooting into staging environment
20190721 00:40:58 INFO Node with ip 10.x.x.x is in phoenix. Generating hardware_config.json
20190721 00:41:03 INFO Boot device WWN: 524693f2ca21cxxx
20190721 00:41:04 INFO Boot device serial: BCA11708300xxxyyy
20190721 00:41:06 INFO Copied /home/nutanix/foundation/templates/crystal_plat_reference.json to phoenix at ip 10.x.x.x
20190721 00:41:10 INFO NIC with PCI address 03:00:0 will be used for NIC teaming if default teaming fails
20190721 00:41:10 INFO This node is not a gold node
20190721 00:41:11 INFO The backplane gave chassis serial 17SMxxxxxxxx, which we will use to replace parameter 19NXSWxxxxx. This is okay.
20190721 00:41:12 INFO Node position is A
20190721 00:41:12 INFO Completed ) @7bd0>
20190721 00:41:12 INFO Running ) @7cd0>
20190721 00:41:12 INFO Running ) @7d50>
20190721 00:41:12 INFO Making node specific Phoenix json. This may take few minutes
20190721 00:41:50 ERROR Command 'test -f /tmp/fatal_marker' returned error code 1

Analysis : Foundation process collect the hardware information like chassis number, Node position, network teaming, WWN number, PCI address etc.

Read more : Top 10 Nutanix IPMI Commands Part 1

Stage 10 : Downloading AOS and Hypervisor binary

20190721 00:42:00 INFO Start downloading resources, this may take several minutes
20190721 00:42:01 INFO Waiting for Phoenix to finish downloading resources
20190721 00:42:03 INFO Model detected: NX-30xx-G5
20190721 00:42:05 INFO Using node_serial from FRU
20190721 00:42:05 INFO Using block_id from IPMICFG
20190721 00:42:05 INFO Using cluster_id from FRU
20190721 00:42:05 INFO Using node_position from IPMICFG
20190721 00:42:05 INFO node_serial = ZM17xxxxxxxx, node_uuid = 04d2axxx-074a-xxx2-94bf-22xxxxxxxxxx, block_id = 17SMxxxxxxxx, cluster_id = 100xxx, model = USE_LAYOUT, model_string = NX-30xx-G5, node_position = A
20190721 00:42:05 INFO Running updated Phoenix
20190721 00:42:05 INFO Downloading AOS tarball
20190721 00:42:05 INFO Downloading AOS tarball: Downloading AOS tarball
20190721 00:42:05 INFO Downloading file 'nutanix_installer_package-release-euphrates-5.10.4-stable.tar' with size: 4895365120 bytes.
20190721 00:42:20 INFO Downloaded 263 / 4668 MB
20190721 00:42:35 INFO Downloaded 534 / 4668 MB
20190721 00:42:50 INFO Downloaded 806 / 4668 MB
20190721 00:43:10 INFO Downloaded 969 / 4668 MB
20190721 00:43:25 INFO Downloaded 1207 / 4668 MB
20190721 00:43:40 INFO Downloaded 1449 / 4668 MB
20190721 00:43:55 INFO Downloaded 1692 / 4668 MB
20190721 00:44:10 INFO Downloaded 1937 / 4668 MB
20190721 00:44:25 INFO Downloaded 2180 / 4668 MB
20190721 00:44:40 INFO Downloaded 2422 / 4668 MB
20190721 00:44:55 INFO Downloaded 2660 / 4668 MB
20190721 00:45:10 INFO Downloaded 2903 / 4668 MB
20190721 00:45:25 INFO Downloaded 3143 / 4668 MB
20190721 00:45:40 INFO Downloaded 3390 / 4668 MB
20190721 00:45:55 INFO Downloaded 3634 / 4668 MB
20190721 00:46:10 INFO Downloaded 3879 / 4668 MB
20190721 00:46:25 INFO Downloaded 4123 / 4668 MB
20190721 00:46:40 INFO Downloaded 4366 / 4668 MB
20190721 00:46:55 INFO Downloaded 4609 / 4668 MB
20190721 00:46:59 INFO Downloading Anaconda bits
20190721 00:46:59 INFO Downloading file 'anaconda.tar.gz' with size: 263700099 bytes.
20190721 00:47:14 INFO Downloaded 245 / 251 MB
20190721 00:47:15 INFO Downloading hypervisor iso
20190721 00:47:15 INFO Downloading hypervisor iso: Downloading hypervisor iso
20190721 00:47:15 INFO Downloading file 'host-bundle-el6.nutanix.20170830.270.tar.gz' with size: 198188985 bytes.
20190721 00:47:26 INFO Downloading AHV OEM RPMs
20190721 00:47:26 INFO Downloading file 'DellPTAgent-1.8.0-0.112.x86_64.rpm' with size: 5463508 bytes.
20190721 00:47:27 INFO Downloading file 'OM-iSM-Dell-Web-LX-330-1290_A00.tar.gz' with size: 4696608 bytes.

Analysis : Foundation process will download the Nutanix AOS and Hypervisor binary to initiate the installation process and push the collected hardware information into AOS and hypevisor.

Stage 11 : Starts Installation process

 20190721 00:47:29 INFO Running CVM Installer: Running CVM Installer
20190721 00:47:29 INFO Running CVM Installer
20190721 00:47:30 INFO Generating unique SSH identity for this Hypervisor-CVM pair.
20190721 00:47:30 INFO Generating SSL certificate for this Hypervisor-CVM pair.
20190721 00:47:30 INFO Extracting the SVM installer into memory. This will take some time…
20190721 00:47:32 INFO Injecting SSH keys into SVM installer.
20190721 00:47:32 INFO Checking if a newer HCL exists on CVM
20190721 00:47:32 INFO Getting NOS version from the CVM

Analysis : Foundation extract the CVM installer into memory to proceed hypervisor installation.

Stage 12 : Scanning storage controller and media

20190721 00:47:34 INFO Scanning devices to assemble RAID. This may take few minutes
20190721 00:47:34 INFO Scanning devices: ['sda', 'sdb']
20190721 00:47:34 INFO Updating HCL with newer one from CVM
20190721 00:47:34 INFO Using hcl from /mnt/svm_installer/install/config/hcl.json with last_edit 1552457147
20190721 00:47:35 INFO Imaging the SVM
20190721 00:47:35 INFO Formatting all data disks ['sdd', 'sde', 'sdf', 'sda', 'sdb', 'sdc']

Analysis : Foundation scans the storage controller card and media to install the hypervisor and Nutanix AOS operating system.

Stage 13 : Installing AHV Hypervisor

 20190721 00:47:36 INFO Executing /mnt/svm_installer/install/bin/svm_rescue with arg_list [u'-i', u'/mnt/svm_installer/install', u'--factory_deploy', u'--node_name=17SMxxxxxxx-A', u'--node_serial=ZM17xxxxxxxx', u'--node_model=USE_LAYOUT', u'--cluster_id=100xxx', u'--node_uuid=04d2xxxx-074a-45xx-94bf-224dxxxxxxx']
20190721 00:47:37 INFO AHV iso created in /tmp/kvm.iso
20190721 00:47:38 INFO kvm iso unpacked in /tmp/tmpblAorD
20190721 00:47:38 INFO Kickstart file created
20190721 00:47:38 DEBUG Bootloader config created for AHV-el6
20190721 00:47:38 INFO KVM iso packed
20190721 00:47:38 INFO Installation Device = /dev/sdg
20190721 00:47:38 INFO Executing /usr/bin/qemu-system-x86_64 -m 4096 -machine q35 -enable-kvm -drive file=/dev/sdg,cache=writethrough,format=raw -cdrom /phoenix/imaging_helper/installer.iso -netdev user,id=net0,net=192.168.5.0/24 -device e1000,netdev=net0,id=net0,mac=ac:1f:6b:60:38:04 -vnc :1 -boot order=d -pidfile installer_vm.pid -daemonize -smp 4
20190721 00:47:38 INFO Installer VM is now running the installation
20190721 00:47:38 INFO Installer VM running with PID = 3032
20190721 00:48:08 INFO Installing AHV: Installing AHV
20190721 00:48:08 INFO [30/1230] Hypervisor installation in progress
20190721 00:48:38 INFO [60/1230] Hypervisor installation in progress
20190721 00:49:08 INFO [90/1230] Hypervisor installation in progress
20190721 00:49:38 INFO [120/1230] Hypervisor installation in progress
20190721 00:50:08 INFO [150/1230] Hypervisor installation in progress
20190721 00:50:38 INFO [180/1230] Hypervisor installation in progress
20190721 00:50:43 INFO touching .autorelabel
20190721 00:50:43 INFO Creating layout file for NX-30xx-G5 in position A
20190721 00:50:43 INFO Running firmware detection: Running firmware detection
20190721 00:50:43 INFO Detected Supermicro platform. Performing firmware detection..
20190721 00:50:44 INFO Using SUM tool version 1.6
20190721 00:50:51 ERROR Config file /mnt/nutanix_boot/etc/nutanix/firmware_config.json does not exist
20190721 00:50:51 INFO Creating firmware_config.json..
20190721 00:50:51 INFO Populating firmware information for device bmc..
20190721 00:50:53 INFO Using SUM tool version 1.6
20190721 00:51:09 INFO [210/1230] Hypervisor installation in progress
20190721 00:51:11 INFO Populating firmware information for device bios..
20190721 00:51:16 INFO Populating firmware information for device host boot disk..
20190721 00:51:17 ERROR Failed to mount /dev/md
20190721 00:51:17 INFO Imaging of SVM has completed successfully!

Analysis : We can install any support hypervisor in Nuanix HCI node but right now foundation process installing the AHV hypervisor in SATADOM device.

Stage 14 : Phoenix detects the storage media again to format

20190721 00:51:17 DEBUG 2019-07-21 07:47:34 INFO svm_rescue:635 Will image ['/dev/sda', '/dev/sdb'] from /mnt/svm_installer/install/images/svm.tar.xz.
2019-07-21 07:47:34 INFO svm_rescue:102 exec_cmd: mdadm --stop --scan
2019-07-21 07:47:34 INFO svm_rescue:471 Disks detected from Phoenix: ['/dev/sdd', '/dev/sde', '/dev/sdf', '/dev/sda', '/dev/sdb', '/dev/sdc']
2019-07-21 07:47:34 INFO svm_rescue:493 Repartitioning disk /dev/sdd
2019-07-21 07:47:34 INFO svm_rescue:102 exec_cmd: /mnt/cdrom/bin/repartition_disks -d /dev/sdd
2019-07-21 07:47:36 INFO svm_rescue:493 Repartitioning disk /dev/sde
2019-07-21 07:47:36 INFO svm_rescue:102 exec_cmd: /mnt/cdrom/bin/repartition_disks -d /dev/sde
2019-07-21 07:47:38 INFO svm_rescue:493 Repartitioning disk /dev/sdf
2019-07-21 07:47:38 INFO svm_rescue:102 exec_cmd: /mnt/cdrom/bin/repartition_disks -d /dev/sdf
2019-07-21 07:47:40 INFO svm_rescue:493 Repartitioning disk /dev/sda
2019-07-21 07:47:40 INFO svm_rescue:102 exec_cmd: parted -s /dev/sda unit s print
2019-07-21 07:47:40 INFO svm_rescue:154 No partition table present on disk /dev/sda
2019-07-21 07:47:40 INFO svm_rescue:445 Need to repartition and format blank boot drive /dev/sda
2019-07-21 07:47:40 INFO svm_rescue:102 exec_cmd: /mnt/cdrom/bin/repartition_disks -b /dev/sda
2019-07-21 07:47:41 INFO svm_rescue:493 Repartitioning disk /dev/sdb
2019-07-21 07:47:41 INFO svm_rescue:102 exec_cmd: parted -s /dev/sdb unit s print
2019-07-21 07:47:41 INFO svm_rescue:154 No partition table present on disk /dev/sdb
2019-07-21 07:47:41 INFO svm_rescue:445 Need to repartition and format blank boot drive /dev/sdb
2019-07-21 07:47:41 INFO svm_rescue:102 exec_cmd: /mnt/cdrom/bin/repartition_disks -b /dev/sdb
2019-07-21 07:47:41 INFO svm_rescue:493 Repartitioning disk /dev/sdc
2019-07-21 07:47:41 INFO svm_rescue:102 exec_cmd: /mnt/cdrom/bin/repartition_disks -d /dev/sdc
2019-07-21 07:47:43 INFO svm_rescue:432 Formatting disks ['/dev/sda4', '/dev/sdb4', '/dev/sdc1', '/dev/sdd1', '/dev/sde1', '/dev/sdf1']
2019-07-21 07:47:43 INFO svm_rescue:102 exec_cmd: /mnt/cdrom/bin/clean_disks -p /dev/sda4,/dev/sdb4,/dev/sdc1,/dev/sdd1,/dev/sde1,/dev/sdf1
2019-07-21 07:48:46 INFO svm_rescue:432 Formatting disks ['/dev/sda1', '/dev/sda2', '/dev/sda3']
2019-07-21 07:48:46 INFO svm_rescue:102 exec_cmd: /mnt/cdrom/bin/clean_disks -p /dev/sda1,/dev/sda2,/dev/sda3
2019-07-21 07:48:48 INFO svm_rescue:432 Formatting disks ['/dev/sdb1', '/dev/sdb2', '/dev/sdb3']
2019-07-21 07:48:48 INFO svm_rescue:102 exec_cmd: /mnt/cdrom/bin/clean_disks -p /dev/sdb1,/dev/sdb2,/dev/sdb3

Analysis : Phoenix detects the storage media and format it proceed the installation.

Stage 15 : Creating RAID 1 with first 2 SSD


2019-07-21 07:48:51 INFO disk_utils.py:78 Creating RAID1 volume /dev/md0 from ('/dev/sda1', '/dev/sdb1')
2019-07-21 07:48:51 INFO disk_utils.py:78 Creating RAID1 volume /dev/md1 from ('/dev/sda2', '/dev/sdb2')
2019-07-21 07:48:51 INFO disk_utils.py:78 Creating RAID1 volume /dev/md2 from ('/dev/sda3', '/dev/sdb3')
2019-07-21 07:48:51 INFO svm_rescue:432 Formatting disks ['/dev/md0', '/dev/md1', '/dev/md2']
2019-07-21 07:48:51 INFO svm_rescue:102 exec_cmd: /mnt/cdrom/bin/clean_disks -p /dev/md0,/dev/md1,/dev/md2
2019-07-21 07:48:53 INFO svm_rescue:102 exec_cmd: mount /dev/md0 /mnt/disk

Analysis : Creating RAID with first 2 SSD those will use to install Nutanix Controlle-VM: CVM and will be redundant in case one SSD goes nonoperational ( down, failure, corrupt, pop out ).

Stage 16 : Starting AOS installation over AHV Hypervisor


2019-07-21 07:48:53 INFO svm_rescue:102 exec_cmd: cd /mnt/disk; tar -xJpvf /mnt/svm_installer/install/images/svm.tar.xz

2019-07-21 07:49:26 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf
/mnt/svm_installer/install/pkg/nutanix-bootstrap-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:49:27 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-core-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:49:42 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-pe-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:49:42 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-diagnostics-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:49:45 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-infrastructure-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:49:46 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-lcm-2.1.4139.tar.gz'

2019-07-21 07:49:46 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-serviceability-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:49:46 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-ncc-el7.3-release-ncc-3.7.1-x86_64-latest.tar.gz'

2019-07-21 07:49:51 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-minervacvm-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:49:51 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-perftools-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:49:51 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-syscheck-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:49:52 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/srv/; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-salt-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:49:52 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-intentgateway-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:50:03 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-clusterconfig-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:50:03 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-zkcore-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:50:03 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-athena-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:50:03 INFO svm_rescue:102 exec_cmd: bash -c 'cd /mnt/disk/usr/local/nutanix; tar -xvzf /mnt/svm_installer/install/pkg/nutanix-xtrim-el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910.tar.gz'

2019-07-21 07:50:03 INFO svm_rescue:677 Making post deployment modifications on /dev/md0

Analysis : Phoenix installing AOS operating system and components like nutanix-pe, nutanix-diagnostics, nutanix-infrastructure, nutanix-lcm, nutanix-serviceability, nutanix-ncc, nutanix-minervacvm, nutanix-syscheck, nutanix-intentgateway, nutanix-clusterconfig, nutanix-zkcore, nutanix-athena, nutanix-xtrim etc.

Read more : Nutanix Acropolis AHV Core Architecture Explained

Stage 17 : Preparing CVM boot-loader

2019-07-21 07:50:04 INFO svm_rescue:102 exec_cmd: blkid -c /dev/null /dev/md0
2019-07-21 07:50:04 INFO svm_rescue:400 Root filesystem (on /dev/md0) UUID is 715473a0-2f76-4aba-9563-3890835104d4 instead of ad6af956-f77d-45dd-8d44-9c006cbaddd5.
2019-07-21 07:50:04 INFO svm_rescue:603 Injecting mdadm.conf into boot partition.
2019-07-21 07:50:04 INFO svm_rescue:608 Injecting mdadm.conf into initrd /mnt/disk/boot/initramfs-3.10.0-862.14.4.el7.nutanix.20190207.cvm.x86_64.img
2019-07-21 07:50:04 INFO svm_rescue:102 exec_cmd: cd /tmp/tmpshSqDR; gunzip -c /mnt/disk/boot/initramfs-3.10.0-862.14.4.el7.nutanix.20190207.cvm.x86_64.img | cpio -id
2019-07-21 07:50:05 INFO svm_rescue:102 exec_cmd: cd /tmp/tmpshSqDR; find . | cpio -o -H newc | gzip > /mnt/disk/boot/initramfs-3.10.0-862.14.4.el7.nutanix.20190207.cvm.x86_64.img
2019-07-21 07:50:07 INFO svm_rescue:180 Creating Nutanix boot marker file from grub.conf …
2019-07-21 07:50:07 INFO svm_rescue:207 Wrote marker file, contents:
KERNEL=/boot/vmlinuz-3.10.0-862.14.4.el7.nutanix.20190207.cvm.x86_64
CMDLINE='ro root=UUID=715473a0-2f76-4aba-9563-3890835104d4 rd_NO_LUKS rd_NO_LVM rd_MD_UUID=bd4ca97d:5df90a4c:688cd2d6:90e37d0f rd_NO_DM LANG=en_US.UTF-8 SYSFONT=latarcyrheb-sun16 rhgb crashkernel=no KEYBOARDTYPE=pc KEYTABLE=us audit=1 nousb fips=1 nomodeset biosdevname=0 net.ifnames=0 scsi_mod.use_blk_mq=y panic=30 console=ttyS0,115200n8 console=tty0 clocksource=tsc kvm_nopvspin=1 xen_nopvspin=1 hv_netvsc.ring_size=512 panic=30 console=ttyS0,115200n8 console=tty0 mpt2sas.prot_mask=1 mpt3sas.prot_mask=1 spectre_v2=off nopti'
INITRD=/boot/initramfs-3.10.0-862.14.4.el7.nutanix.20190207.cvm.x86_64.img

Analysis : Nutanix Controller-VM: CVM is preparing boot-loader and grub.config to boot the CVM.

Read more : Nutanix CVM Kernel Panic Issue

Stage 18 : Nutanix CVM adding storage media


2019-07-21 07:50:07 INFO svm_rescue:238 Adding /dev/md2 to /etc/fstab to be mounted at /home…
2019-07-21 07:50:07 INFO svm_rescue:102 exec_cmd: blkid -c /dev/null /dev/md2
2019-07-21 07:50:07 INFO svm_rescue:102 exec_cmd: mount /dev/md2 /mnt/data
2019-07-21 07:50:07 INFO svm_rescue:726 Fixing permissions on /home.
2019-07-21 07:50:07 INFO svm_rescue:726 Fixing permissions on /home./nutanix

Analysis : Nutanix CVM adding storage media to fstab file for permanent mounting disk to CVM and fixing permission as well.

Stage 19 : Backing up all required binary images

 2019-07-21 07:50:07 INFO svm_rescue:751 Copying installer to /mnt/data/nutanix/data/installer/el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910
2019-07-21 07:50:07 INFO svm_rescue:102 exec_cmd: tar -C '/mnt/svm_installer/install' -cf - . | tar -C '/mnt/data/nutanix/data/installer/el7.3-release-euphrates-5.10.4-stable-b5654b18fc3273784edab3c3028acb81cc49b910' -xvf -
2019-07-21 07:50:11 INFO svm_rescue:102 exec_cmd: tar -xvzf /mnt/svm_installer/install/pkg/nutanix-foundation-4.3.4-20190501-da37825c.tar.gz -C /mnt/data/nutanix

Analysis : Backing up AOS and foundation binary file to /home/nutanix/data/installer/* directory for later use.

Read more : Top 5 Nutanix Backup Solutions

Stage 20 : Finalizing AOS installation

 2019-07-21 07:50:21 INFO svm_rescue:797 Setting up SSH configuration
2019-07-21 07:50:21 INFO svm_rescue:803 Writing out rc.nutanix
2019-07-21 07:50:21 INFO svm_rescue:885 Running setfiles.sh on the chroot: /mnt/disk
2019-07-21 07:50:38 INFO svm_rescue:102 exec_cmd: sync; sync; sync
2019-07-21 07:50:38 INFO svm_rescue:102 exec_cmd: umount /mnt/disk
2019-07-21 07:50:39 INFO svm_rescue:102 exec_cmd: umount /mnt/data
20190721 00:51:17 INFO Imaging thread 'svm' has completed successfully

Analysis : Finalized the AOS installation on the AHV hypervisor.

Read more : Nutanix Acropolis AOS Vs AHV

Stage 21 : Finalizing AHV installation

 20190721 00:51:39 INFO [240/1230] Hypervisor installation in progress
20190721 00:52:09 INFO [270/1230] Hypervisor installation in progress
20190721 00:52:39 INFO [300/1230] Hypervisor installation in progress
20190721 00:53:09 INFO [330/1230] Hypervisor installation in progress
20190721 00:53:35 INFO Rebooting AHV: Rebooting AHV
20190721 00:53:35 INFO Completed ) @7cd0>
20190721 00:53:39 INFO [360/1230] Hypervisor installation in progress
20190721 00:54:09 INFO [390/1230] Hypervisor installation in progress
20190721 00:54:09 INFO Installer VM finished in 390.681511879s.
20190721 00:54:09 INFO Hypervisor installation is done
20190721 00:54:09 INFO Re-reading partition table for /dev/sdg
20190721 00:54:12 INFO Customizing KVM instance
20190721 00:54:12 INFO Setting hostname to 'INTIKNTXHSTI01'

Analysis : Finalizing the AHV hypervisor installation to configure the Storage media, host-name and rebooting the node once.

Read more : Nutanix AHV Infected By OVS Packet Looping Issue

Stage 22 : Creating Nutanix CVM template

 20190721 00:54:12 INFO Copying SVM template files
20190721 00:54:12 INFO Configuring SVM resources
20190721 00:54:12 INFO Setting CVM memory to 32GB
20190721 00:54:12 INFO Setting vCPUs to 12
20190721 00:54:12 INFO Setting cpuset to 0,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,36,37,38,39,40,41,42,43,44,45,46,47,48,49,50,51,52,53
20190721 00:54:12 INFO Fetching the list of HBAs and nics from layout
20190721 00:54:12 INFO Adding device with bus 01:00.0, vendor 1000 and device 0097 to passthrough devices
20190721 00:54:12 INFO Regenerating initramfs
20190721 00:54:34 INFO Setting up authorized_keys
20190721 00:54:34 INFO Copying firstboot scripts into /mnt/stage/root/firstboot
20190721 00:54:34 INFO Copying SSH keys
20190721 00:54:34 INFO Copying network configuration crashcart scripts into /mnt/stage/root/nutanix-network-crashcart
20190721 00:54:34 INFO Installing firstboot marker file
20190721 00:54:34 INFO Cleaning up

Analysis : Create Nutanix CVM template for later use.

Read more : How To Change Nutanix CVM, AHV and IPMI Passwords

Stage 23 : Validating the installation

 20190721 00:54:34 INFO Imaging thread 'hypervisor' has completed successfully
20190721 00:54:34 INFO Imaging process completed successfully!
20190721 00:54:34 INFO Installation of Acropolis base software successful: Installation successful.
20190721 00:54:34 INFO Rebooting node. This may take several minutes: Rebooting node. This may take several minutes
20190721 00:54:35 INFO Rebooting node. This may take several minutes

Analysis : System validating the installation and taking node reboot.

Stage 24 : Nutanix AHV validating network configuration

 20190721 00:59:54 INFO Running cmd ['ovs-appctl bond/list']
20190721 00:59:54 INFO Running cmd [u'ovs-appctl bond/set-active-slave br0-up eth0']
20190721 00:59:54 INFO Running cmd [u'ping -c 1 10.238.154.2']
20190721 00:59:54 INFO Using eth0 as the active slave in bond br0-up
20190721 00:59:54 INFO Running firstboot scripts: Running firstboot scripts
20190721 00:59:54 INFO Expanding boot partition. This may take some time.

Analysis : Nutanix AHV hypervisor validationg the network configuration, teaming configuration and bond configuration.

Stage 25 : Validating CVM network

 20190721 00:59:54 INFO Running cmd ['/usr/bin/nohup /sbin/resize2fs /dev/sda1 &>/dev/null &']
20190721 00:59:54 INFO Running cmd ['touch /root/firstboot/phases/expand_boot_partition']
20190721 00:59:54 INFO Running cmd ['virsh net-list --all']
20190721 00:59:55 INFO Running cmd ['virsh net-list --all']
20190721 00:59:55 INFO Running cmd ['virsh net-define /root/net-VM-Network.xml']
20190721 00:59:55 INFO Running cmd ['virsh net-start VM-Network']
20190721 00:59:55 INFO Running cmd ['virsh net-autostart VM-Network']
20190721 00:59:55 INFO Running cmd ['virsh net-list --all']
20190721 00:59:55 INFO Running cmd ['virsh net-define /root/net-NTNX-Local-Network.xml']
20190721 00:59:55 INFO Running cmd ['virsh net-start NTNX-Local-Network']
20190721 00:59:55 INFO Running cmd ['virsh net-autostart NTNX-Local-Network']
20190721 00:59:55 INFO Running cmd ['touch /root/firstboot/phases/create_libvirt_networks']

Analysis : Validating the Nutanix Controller-VM: CVM network.

Read more : Nutanix CVM Network Port List for Communication

Stage 26 : Creating new Controller-VM: CVM

 20190721 00:59:55 INFO Creating a new CVM: Creating a new CVM
20190721 00:59:55 INFO Running cmd ['echo "$(hostname)-CVM"']
20190721 00:59:55 INFO Running cmd [u'sed -i "s/NTNX-CVM/NTNX-INTIKNTXHSTI01-CVM/" /root/NTNX-CVM.xml']
20190721 00:59:55 INFO Running cmd ['sed -i "//d" /root/NTNX-CVM.xml']
20190721 00:59:55 INFO Running cmd ['chmod 644 /var/lib/libvirt/NTNX-CVM/svmboot.iso']
20190721 00:59:55 INFO Running cmd ['chown qemu:qemu /var/lib/libvirt/NTNX-CVM/svmboot.iso']
20190721 00:59:55 INFO Running cmd ['virsh define /root/NTNX-CVM.xml']
20190721 00:59:55 INFO Running cmd ['service libvirtd restart']
20190721 00:59:55 INFO Running cmd [u'virsh start "NTNX-INTIKNTXHSTI01-CVM"']
20190721 01:00:01 INFO Running cmd [u'virsh autostart "NTNX-INTIKNTXHSTI01-CVM"']
20190721 01:00:01 INFO Running cmd ['touch /root/firstboot/phases/create_cvm']
20190721 01:00:25 INFO [1/160] Waiting for CVM to initialize network
20190721 01:00:49 INFO [2/160] Waiting for CVM to initialize network
20190721 01:01:13 INFO [3/160] Waiting for CVM to initialize network
20190721 01:01:35 INFO [4/160] Waiting for CVM first boot to create /tmp/svm_boot_succeeded
20190721 01:01:51 INFO [5/160] Waiting for CVM first boot to create /tmp/svm_boot_succeeded
20190721 01:02:06 INFO [6/160] Waiting for CVM first boot to create /tmp/svm_boot_succeeded
20190721 01:02:22 INFO [7/160] Waiting for CVM first boot to create /tmp/svm_boot_succeeded
20190721 01:02:38 INFO [8/160] Waiting for CVM first boot to create /tmp/svm_boot_succeeded
20190721 01:02:53 INFO [9/160] Waiting for CVM first boot to create /tmp/svm_boot_succeeded
20190721 01:03:10 INFO [10/160] Waiting for CVM to finish first boot
20190721 01:03:26 INFO [11/160] Waiting for CVM to finish first boot
20190721 01:03:43 INFO [12/160] Waiting for CVM to finish first boot
20190721 01:03:59 INFO [13/160] Waiting for CVM to finish first boot
20190721 01:04:16 INFO [14/160] Waiting for CVM to finish first boot
20190721 01:05:25 INFO CVM booted up successfully: CVM booted up successfully

Analysis : Creating New CVM with previous created CVM template.

Stage 27 : Nutanix CVM changing power state

 20190721 01:05:25 INFO Running cmd ['touch /root/firstboot/phases/cvm_firstboot']
20190721 01:05:25 INFO Last reboot complete: Firstboot successful
20190721 01:05:25 INFO Running cmd ['touch /root/.firstboot_success']

Analysis : Nutanix CVM take first boot after created successfully.

Stage 28 : Starts NTP service on Nutanix CVM

 20190721 01:05:25 INFO Running cmd ['service ntpd start']
20190721 01:05:25 INFO Running cmd ['/sbin/chkconfig ntpd on']
20190721 01:05:26 INFO Completed ) @7d50>

Analysis : Nutanix CVM starts the NTPD service and set it ON to CVM startup.

Finally Nutanix node is ready with AHV Hypervisor and running healthy CVM on it. Now you can proceed to create acropolis cluster.

Read more : How To Shutdown And Start Nutanix AHV Cluster

Conclusion

Nutanix foundation appliance is designed very well and user friendly also. Nutanix release lastest version of foundation standalone appliance to fixed up the issue, improve the hardware compatibility and robust re-imaging the node experience.

Hope, I shared the something new to knowledge to gain more.
Thanks to being with HyperHCI Tech Blog to stay tuned.!