Skip to content
Snippets Groups Projects

AIMS detailed logging

Merged AIMS detailed logging
logging into master
Merged Daniel Juarez Gonzalez requested to merge logging into master
Compare
and
3 files
+ 203
− 0
Compare changes
  • Side-by-side
  • Inline
Files
3
docs/aims2/logging.md 0 → 100644
+ 200
− 0
# Detailed logging
[TOC]
Bear in mind all the logs ommit the DB logging, which is also recorded but only useful when debugging if something went wrong, for example a real world example would be cross checking that the node is using on MAC address which then does not appear on AIMS or LANDB databases.
## Registration of a new machine in LANDB
This is the log workflow for a machine that is not yet present in LANDB (i.e. <https://network.cern.ch>), basically when they come to CERN for the first time and need to be enrolled for later usage by Ironic.
``` mermaid
graph LR
A[PXE boot] --> B{Registered on LANDB?};
B -->|No, so HWREG| C[DHCP];
B -->|Yes| F[Different workflow, see next sections];
C --> |Hardcoded bootfile| D[TFTP download bootloader];
D --> E[Hardcoded PXE config on AIMS];
E --> f[Boot procurement image];
```
Note: The procurement image is maintained by them and is responsible for registering all the machine details in LANDB. If it fails, the machine will have to go through this very same process again.
In this case, logs a pretty straight forward as there is not much interaction apart from the bootfile download:
```
# As a summary, node will try to download the specified bootloader hardcoded on the DHCP conf
Jul 7, 2022 @ 04:40:21.000 RRQ from ::ffff:10.41.160.53 filename hwreg/loader/uefi/bootx64.efi.0
Jul 7, 2022 @ 04:40:23.000 Client ::ffff:10.41.160.53 File not found hwreg/loader/uefi/grub.cfg-0A29A0
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename /aims/loader/uefi/grub.cfg/x86_64-efi/crypto.lst
Jul 7, 2022 @ 04:40:23.000 Client ::ffff:10.41.160.53 finished hwreg/loader/uefi/bootx64.efi.0
Jul 7, 2022 @ 04:40:23.000 Client ::ffff:10.41.160.53 File not found hwreg/loader/uefi/grub.cfg-0A
Jul 7, 2022 @ 04:40:23.000 Client ::ffff:10.41.160.53 File not found hwreg/loader/uefi/grub.cfg-0A29A
# Apart from the bootloader it also downloads the involved binaries GRUB needs for our configuration
Jul 7, 2022 @ 04:40:23.000 Client ::ffff:10.41.160.53 finished /aims/loader/uefi/grub.cfg/x86_64-efi/crypto.lst
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename hwreg/loader/uefi/grub.cfg-0A29A03
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename /aims/loader/uefi/grub.cfg/x86_64-efi/command.lst
Jul 7, 2022 @ 04:40:23.000 Client ::ffff:10.41.160.53 File not found hwreg/loader/uefi/grub.cfg-0A29A03
Jul 7, 2022 @ 04:40:23.000 Client ::ffff:10.41.160.53 finished /aims/loader/uefi/grub.cfg/x86_64-efi/command.lst
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename hwreg/loader/uefi/grub.cfg-0A29A035
Jul 7, 2022 @ 04:40:23.000 Client ::ffff:10.41.160.53 finished hwreg/loader/uefi/grub.cfg
# You may see this because by default clients try to download different pathnames that could match the MAC address of the interface it is PXE booting with
# but in this case there is none, we just expect it to fallback to the default PXE HWREG conf file, in this case hwreg/loader/uefi/grub.cfg
Jul 7, 2022 @ 04:40:23.000 Client ::ffff:10.41.160.53 File not found hwreg/loader/uefi/grub.cfg-01-3c-ec-ef-fa-36-46
Jul 7, 2022 @ 04:40:23.000 Client ::ffff:10.41.160.53 File not found hwreg/loader/uefi/grub.cfg-0
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename hwreg/loader/uefi/grub.cfg-0A29
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename /aims/loader/uefi/grub.cfg/x86_64-efi/terminal.lst
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename hwreg/loader/uefi/grub.cfg-0A2
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename hwreg/loader/uefi/grub.cfg
Jul 7, 2022 @ 04:40:23.000 Client ::ffff:10.41.160.53 File not found hwreg/loader/uefi/grub.cfg-0A29
Jul 7, 2022 @ 04:40:23.000 Client ::ffff:10.41.160.53 finished /aims/loader/uefi/grub.cfg/x86_64-efi/terminal.lst
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename hwreg/loader/uefi/grub.cfg-0A29A0
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename /aims/loader/uefi/grub.cfg/x86_64-efi/fs.lst
Jul 7, 2022 @ 04:40:23.000C lient ::ffff:10.41.160.53 File not found hwreg/loader/uefi/grub.cfg-0A2
Jul 7, 2022 @ 04:40:23.000 Client ::ffff:10.41.160.53 finished hwreg/loader/uefi/grub.cfg
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename hwreg/loader/uefi/grub.cfg-01-3c-ec-ef-fa-36-46
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename hwreg/loader/uefi/bootx64.efi.0
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename hwreg/loader/uefi/grub.cfg-0A
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename hwreg/loader/uefi/grub.cfg-0A29A
Jul 7, 2022 @ 04:40:23.000C lient ::ffff:10.41.160.53 finished /aims/loader/uefi/grub.cfg/x86_64-efi/fs.lst
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename hwreg/loader/uefi/grub.cfg-0
Jul 7, 2022 @ 04:40:23.000 Client ::ffff:10.41.160.53 File not found hwreg/loader/uefi/grub.cfg-0A29A035
Jul 7, 2022 @ 04:40:23.000 RRQ from ::ffff:10.41.160.53 filename hwreg/loader/uefi/grub.cfg
# Progress GRUB mod to show download progress
Jul 7, 2022 @ 04:40:34.000 Client ::ffff:10.41.160.53 finished /aims/loader/uefi/grub.cfg/x86_64-efi/progress.mod
Jul 7, 2022 @ 04:40:34.000 RRQ from ::ffff:10.41.160.53 filename /aims/loader/uefi/grub.cfg/x86_64-efi/progress.mod
# Finally TFTP download the registration PXE image from AIMS before letting it do its magic and make it appear on LANDB
Jul 7, 2022 @ 04:40:34.000 RRQ from ::ffff:10.41.160.53 filename /aims/boot/OPENSTACK-IRONIC-IPA/vmlinuz
Jul 7, 2022 @ 04:40:36.000 Client ::ffff:10.41.160.53 finished /aims/boot/OPENSTACK-IRONIC-IPA/vmlinuz
Jul 7, 2022 @ 04:40:37.000 RRQ from ::ffff:10.41.160.53 filename /aims/boot/OPENSTACK-IRONIC-IPA/initrd
Jul 7, 2022 @ 04:41:55.000 Client ::ffff:10.41.160.53 finished /aims/boot/OPENSTACK-IRONIC-IPA/initrd
# After this you lose trace of this node as AIMS does not know the node name on LANDB
```
## Ironic workflow
This is the log workflow for a machine that needs to go through the usual cleanup after machine deletion.
I cannot provide a proper flowchart for this, please ask Arne for one :).
Relevant log samples:
```
# aims2client adds the host, in this case the call comes from Ironic home-made patches
Jun 27, 2022 @ 21:11:35.000 188.185.88.43 - [server/AddHost] Host CITEST-4152767-CXTKS registered with aims.
Jun 27, 2022 @ 21:11:35.000 188.185.88.43 - [host/add] Host record for CITEST-4152767-CXTKS has been inserted
Jun 27, 2022 @ 21:11:35.000 188.185.88.43 - [server/AddHost] Starting CITEST-4152767-CXTKS host addition.
Jun 27, 2022 @ 21:11:35.000 188.185.88.43 - [host/add] Hardware records for CITEST-4152767-CXTKS have been inserted
# AIMS will go fetch addresses from LANDB to generate the corresponding SYSLINUX or GRUB configuration files for booting up the specified image
Jun 27, 2022 @ 21:11:36.000 188.185.88.43 - ADD pxe conf for 01-3c:ec:ef:74:06:31 / MAC 3c:ec:ef:74:06:31 (CITEST-4152767-CXTKS) [uefi]
Jun 27, 2022 @ 21:11:36.000 188.185.88.43 - ADD pxe conf for 01-3c:ec:ef:0d:e9:f4 / MAC 3c:ec:ef:0d:e9:f4 (CITEST-4152767-CXTKS) [uefi]
# The previous configuration files will then specify the image to boot, in this case OPENSTACK-IPA-WALLABY-3E2674CB-WALLABY-03_MAY_2022
Jun 27, 2022 @ 21:11:36.000 188.185.88.43 - [server/EnablePXE] Host CITEST-4152767-CXTKS enabled for OPENSTACK-IPA-WALLABY-3E2674CB-WALLABY-03_MAY_2022 (uefi). Warning: Non UEFI target selected for UEFI boot
# Once done with the image, it will unregister the machine from AIMS
Jun 27, 2022 @ 21:38:29.000 188.184.49.161 - [reboot.cgi] CITEST-4152767-CXTKS installed by AIMS2 at Mon Jun 27 20:38:29 2022. Device set to localboot.
# Unregistering it will then remove the PXE configuration files we created before, therefore next boot will fallback to default conf files, which after a timeout will boot from disk
Jun 29, 2022 @ 21:38:29.000 localhost - REM pxe conf for 01-3c-ec-ef-0d-e9-f4 (CITEST-4152767-CXTKS) [uefi]
Jun 29, 2022 @ 21:38:29.000 localhost - REM pxe conf for 01-3c-ec-ef-74-06-31 (CITEST-4152767-CXTKS) [uefi]
```
## PXE installation of a non-Ironic machine
This is the use case of a machine that wants to PXE install an image, i.e. a non-Ironic machine, even a simple desktop. For this example we are using the manual procedure, but if you are running `aims2client addhost ... -pxe --uefi`, the only single difference would be that instead of falling back to a default PXE conf file, it will download a specific one setting up which image to boot from.
```mermaid
graph LR
A[PXE boot] --> B{Registered on LANDB?};
B --> |Yes| C[DHCP conf];
B --> |No| F[Different workflow, see first section];
C --> |Delegate to AIMS dnsmasq the bootfile decision| D[TFTP download matching bootloader];
D --> E{Try all possible MACs looking for PXE conf files};
E --> |PXE conf file for this MAC exists| G[Download it and boot its specified PXE image];
E --> |No custom PXE conf file| H[Fallback to default conf file, manual selection];
```
### Manual install
```
# dnsmasq will determine that this machine is BIOS instead of UEFI and download the corresponding bootloader through TFTP
Jul 7, 2022 @ 16:11:59.0002053731026 PXE(eth0) 10.16.129.72 0c:c4:7a:69:72:d2 /aims/loader/bios/lpxelinux.0
Jul 7, 2022 @ 16:12:00.000Client ::ffff:10.16.129.72 finished /aims/loader/bios/lpxelinux.0
Jul 7, 2022 @ 16:12:00.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/lpxelinux.0
Jul 7, 2022 @ 16:12:00.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/lpxelinux.0
# Once again, the machine will try to download any PXE conf file matching its MAC address
# A matching file will only exist if there was a previous 'aims2client addhost ... --pxe --uefi' call specifying an image to boot
# If not, for this use case you can see it is downloading aims/loader/bios/pxelinux.cfg/default
# Workflow is identical for both use cases
Jul 7, 2022 @ 16:12:01.000Client ::ffff:10.16.129.72 File not found /aims/loader/bios/pxelinux.cfg/0A108
Jul 7, 2022 @ 16:12:01.000Client ::ffff:10.16.129.72 File not found /aims/loader/bios/pxelinux.cfg/0A10
Jul 7, 2022 @ 16:12:01.000Client ::ffff:10.16.129.72 File not found /aims/loader/bios/pxelinux.cfg/0A108148
Jul 7, 2022 @ 16:12:01.000Client ::ffff:10.16.129.72 File not found /aims/loader/bios/pxelinux.cfg/0A1
Jul 7, 2022 @ 16:12:01.000Client ::ffff:10.16.129.72 File not found /aims/loader/bios/pxelinux.cfg/0A1081
Jul 7, 2022 @ 16:12:01.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/pxelinux.cfg/0A10
Jul 7, 2022 @ 16:12:01.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/pxelinux.cfg/0A10814
Jul 7, 2022 @ 16:12:01.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/pxelinux.cfg/0A108
# Download all the required binaries to work
Jul 7, 2022 @ 16:12:01.000Client ::ffff:10.16.129.72 finished /aims/loader/bios/ldlinux.c32
Jul 7, 2022 @ 16:12:01.000Client ::ffff:10.16.129.72 File not found /aims/loader/bios/pxelinux.cfg/0A
Jul 7, 2022 @ 16:12:01.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/pxelinux.cfg/0A1
Jul 7, 2022 @ 16:12:01.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/pxelinux.cfg/0A1081
Jul 7, 2022 @ 16:12:01.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/pxelinux.cfg/01-0c-c4-7a-69-72-d2
Jul 7, 2022 @ 16:12:01.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/pxelinux.cfg/0
Jul 7, 2022 @ 16:12:01.000Client ::ffff:10.16.129.72 File not found /aims/loader/bios/pxelinux.cfg/0A10814
Jul 7, 2022 @ 16:12:01.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/pxelinux.cfg/0A108148
Jul 7, 2022 @ 16:12:01.000Client ::ffff:10.16.129.72 File not found /aims/loader/bios/pxelinux.cfg/01-0c-c4-7a-69-72-d2
Jul 7, 2022 @ 16:12:01.000Client ::ffff:10.16.129.72 File not found /aims/loader/bios/pxelinux.cfg/0
# Download the default PXE conf file as it did not find a custom conf file for its MAC address.
# For comparison, for a x86_64 UEFI machine, it will fallback to /aims/loader/uefi/grub.cfg/grub.cfg
Jul 7, 2022 @ 16:12:01.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/pxelinux.cfg/default
Jul 7, 2022 @ 16:12:01.000Client ::ffff:10.16.129.72 finished /aims/loader/bios/pxelinux.cfg/default
Jul 7, 2022 @ 16:12:01.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/ldlinux.c32
Jul 7, 2022 @ 16:12:01.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/pxelinux.cfg/0A
Jul 7, 2022 @ 16:12:03.000Client ::ffff:10.16.129.72 finished /aims/loader/bios/libutil.c32
# On BIOS mode certain files are downloaded through HTTP, not TFTP, like on UEFI mode
Jul 7, 2022 @ 16:12:03.00010.16.129.72 - - [07/Jul/2022:16:12:03 +0200] "GET /aims/config/bios/main.conf HTTP/1.0" 200 3281 288 "-" "Syslinux/6.03"
Jul 7, 2022 @ 16:12:03.00010.16.129.72 - - [07/Jul/2022:16:12:03 +0200] "GET /aims/config/bios/graphics.conf HTTP/1.0" 200 479 162 "-" "Syslinux/6.03"
Jul 7, 2022 @ 16:12:03.00010.16.129.72 - - [07/Jul/2022:16:12:03 +0200] "GET /aims/loader/bios/vesamenu.c32 HTTP/1.0" 200 27104 445 "-" "Syslinux/6.03"
Jul 7, 2022 @ 16:12:03.00010.16.129.72 - - [07/Jul/2022:16:12:03 +0200] "GET /aims/loader/bios/unibackgrnd.png HTTP/1.0" 200 15795 317 "-" "Syslinux/6.03"
Jul 7, 2022 @ 16:12:03.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/libutil.c32
Jul 7, 2022 @ 16:12:03.000Client ::ffff:10.16.129.72 finished /aims/loader/bios/libcom32.c32
Jul 7, 2022 @ 16:12:03.000RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/libcom32.c32
# Depending on the PXE configuration, which is different between BIOS and UEFI modes, images can be downloaded through HTTP like this case or just TFTP
Jul 7, 2022 @ 16:12:07.00010.16.129.72 - - [07/Jul/2022:16:12:07 +0200] "GET /aims/boot/CC7_X86_64/vmlinuz HTTP/1.0" 200 6769256 116917 "-" "Syslinux/6.03"
Jul 7, 2022 @ 16:12:08.00010.16.129.72 - - [07/Jul/2022:16:12:07 +0200] "GET /aims/boot/CC7_X86_64/initrd HTTP/1.0" 200 55129656 944119 "-" "Syslinux/6.03"
```
### Automated install
This presumes the user or tool ran `aims2client` to specify which image to download, for example `aims2client addhost testbioscc7 --name CC79_X86_64 --pxe`
```
# Traces of the aims2client interaction registering the node info on AIMS
Jul 7, 2022 @ 16:26:29.000 188.184.21.197 - [server/AddHost] Starting testbios6cc7 host addition.
Jul 7, 2022 @ 16:26:29.000 188.184.21.197 - [server/AddHost] Host TESTBIOS6CC7 registered with aims.
Jul 7, 2022 @ 16:26:29.000 188.184.21.197 - [host/add] Hardware records for TESTBIOS6CC7 have been inserted
Jul 7, 2022 @ 16:26:29.000 188.184.21.197 - [host/add] Host record for TESTBIOS6CC7 has been inserted
# Create the custom PXE conf files
Jul 7, 2022 @ 16:26:30.000 188.184.21.197 - ADD pxe conf for 01-0c:c4:7a:37:8d:f5 / MAC 0c:c4:7a:37:8d:f5 (TESTBIOS6CC7) [bios]
Jul 7, 2022 @ 16:26:30.000 188.184.21.197 - ADD pxe conf for 01-0c:c4:7a:69:72:d2 / MAC 0c:c4:7a:69:72:d2 (TESTBIOS6CC7) [bios]
Jul 7, 2022 @ 16:26:30.000 188.184.21.197 - [server/EnablePXE] Host TESTBIOS6CC7 enabled for CC79_X86_64 (bios). .
# dnsmasq will determine that this machine is BIOS instead of UEFI and download the corresponding bootloader through TFTP
Jul 7, 2022 @ 16:29:04.000 2053731026 PXE(eth0) 10.16.129.72 0c:c4:7a:69:72:d2 /aims/loader/bios/lpxelinux.0
Jul 7, 2022 @ 16:29:05.000 Client ::ffff:10.16.129.72 finished /aims/loader/bios/lpxelinux.0
Jul 7, 2022 @ 16:29:05.000 RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/lpxelinux.0
Jul 7, 2022 @ 16:29:05.000 RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/lpxelinux.0
Jul 7, 2022 @ 16:29:06.000 RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/pxelinux.cfg/01-0c-c4-7a-69-72-d2
# Download all the required binaries to work
Jul 7, 2022 @ 16:29:06.000 RRQ from ::ffff:10.16.129.72 filename /aims/loader/bios/ldlinux.c32
# There is a matching PXE conf for this address the machine is booting from, download it
# It will specify to boot from CC79_X86_64
Jul 7, 2022 @ 16:29:06.000 Client ::ffff:10.16.129.72 finished /aims/loader/bios/pxelinux.cfg/01-0c-c4-7a-69-72-d2
Jul 7, 2022 @ 16:29:06.000 Client ::ffff:10.16.129.72 finished /aims/loader/bios/ldlinux.c32
# Download the CC79_X86_64 image through HTTP
Jul 7, 2022 @ 16:29:06.000 10.16.129.72 - - [07/Jul/2022:16:29:06 +0200] "GET /aims/boot/CC79_X86_64/vmlinuz HTTP/1.0" 200 6769256 130801 "-" "Syslinux/6.03"
Jul 7, 2022 @ 16:29:07.000 10.16.129.72 - - [07/Jul/2022:16:29:06 +0200] "GET /aims/boot/CC79_X86_64/initrd HTTP/1.0" 200 55129656 1082525 "-" "Syslinux/6.03"
# We did not specify any Kickstart file on the command line, but you can it to the command line
Jul 7, 2022 @ 16:29:27.000 10.16.129.72 - [ks.cgi] Error: kickstart for TESTBIOS6CC7 not found.
Jul 7, 2022 @ 16:29:27.000 10.16.129.72 - - [07/Jul/2022:16:29:26 +0200] "GET /aims/ks HTTP/1.1" 200 60 532145 "-" "curl/7.29.0"
```