From 9ff4c67e05df2d3396f47588385301de2cdc3e92 Mon Sep 17 00:00:00 2001 From: Drew Walters Date: Wed, 22 Apr 2020 18:50:16 +0000 Subject: [PATCH] Add additional debug logging to Redfish calls When tracking down issues on baremetal nodes using remotedirect, it has been difficult to pinpoint which Redfish calls fail. This change adds additional debug logging to make the troubleshooting process simpler during pre-alpha development. Change-Id: Ic32d34d010c44b2e7e2a4dfe2b623a451ad94019 Signed-off-by: Drew Walters --- cmd/baremetal/ejectmedia.go | 2 +- cmd/baremetal/poweroff.go | 2 +- cmd/baremetal/poweron.go | 2 +- cmd/baremetal/powerstatus.go | 4 +-- cmd/baremetal/reboot.go | 2 +- pkg/remote/redfish/client.go | 25 +++++++++++++++++-- pkg/remote/redfish/utils.go | 7 +++++- pkg/remote/redfish/vendors/dell/client.go | 3 +++ pkg/remote/remote_direct.go | 8 +++--- .../tasks/main.yaml | 2 +- 10 files changed, 42 insertions(+), 15 deletions(-) diff --git a/cmd/baremetal/ejectmedia.go b/cmd/baremetal/ejectmedia.go index 578bdc9d6..f51c92654 100644 --- a/cmd/baremetal/ejectmedia.go +++ b/cmd/baremetal/ejectmedia.go @@ -45,7 +45,7 @@ func NewEjectMediaCommand(rootSettings *environment.AirshipCTLSettings) *cobra.C return err } - fmt.Fprintf(cmd.OutOrStdout(), "All media ejected from host %s\n", host.HostName) + fmt.Fprintf(cmd.OutOrStdout(), "All media ejected from host '%s'.\n", host.HostName) } return nil diff --git a/cmd/baremetal/poweroff.go b/cmd/baremetal/poweroff.go index 9c1f652d8..72a21d195 100644 --- a/cmd/baremetal/poweroff.go +++ b/cmd/baremetal/poweroff.go @@ -45,7 +45,7 @@ func NewPowerOffCommand(rootSettings *environment.AirshipCTLSettings) *cobra.Com return err } - fmt.Fprintf(cmd.OutOrStdout(), "Remote host %s powered off\n", host.HostName) + fmt.Fprintf(cmd.OutOrStdout(), "Powered off host '%s'.\n", host.HostName) } return nil diff --git a/cmd/baremetal/poweron.go b/cmd/baremetal/poweron.go index 3a4ec5335..4e040e719 100644 --- a/cmd/baremetal/poweron.go +++ b/cmd/baremetal/poweron.go @@ -45,7 +45,7 @@ func NewPowerOnCommand(rootSettings *environment.AirshipCTLSettings) *cobra.Comm return err } - fmt.Fprintf(cmd.OutOrStdout(), "Powered on remote host %s\n", host.HostName) + fmt.Fprintf(cmd.OutOrStdout(), "Powered on host '%s'.\n", host.HostName) } return nil diff --git a/cmd/baremetal/powerstatus.go b/cmd/baremetal/powerstatus.go index ae12e3958..09ae3eba1 100644 --- a/cmd/baremetal/powerstatus.go +++ b/cmd/baremetal/powerstatus.go @@ -46,8 +46,8 @@ func NewPowerStatusCommand(rootSettings *environment.AirshipCTLSettings) *cobra. return err } - fmt.Fprintf(cmd.OutOrStdout(), "Remote host %s has power status: %s\n", host.HostName, - powerStatus) + fmt.Fprintf(cmd.OutOrStdout(), "Host '%s' has power status: '%s'\n", + host.HostName, powerStatus) } return nil diff --git a/cmd/baremetal/reboot.go b/cmd/baremetal/reboot.go index b5395cc09..f647cc3de 100644 --- a/cmd/baremetal/reboot.go +++ b/cmd/baremetal/reboot.go @@ -45,7 +45,7 @@ func NewRebootCommand(rootSettings *environment.AirshipCTLSettings) *cobra.Comma return err } - fmt.Fprintf(cmd.OutOrStdout(), "Rebooted remote host at %s\n", host.HostName) + fmt.Fprintf(cmd.OutOrStdout(), "Rebooted host '%s'.\n", host.HostName) } return nil diff --git a/pkg/remote/redfish/client.go b/pkg/remote/redfish/client.go index 514e735e7..b4675918a 100644 --- a/pkg/remote/redfish/client.go +++ b/pkg/remote/redfish/client.go @@ -94,6 +94,8 @@ func (c *Client) EjectVirtualMedia(ctx context.Context) error { } if *vMediaMgr.Inserted == true { + log.Debugf("'%s' has virtual media inserted. Attempting to eject.", vMediaMgr.Name) + var emptyBody map[string]interface{} _, httpResp, err = c.RedfishAPI.EjectVirtualMedia(ctx, managerID, mediaID, emptyBody) if err = ScreenRedfishError(httpResp, err); err != nil { @@ -124,6 +126,7 @@ func (c *Client) RebootSystem(ctx context.Context) error { return err } if system.PowerState == desiredState { + log.Debugf("Node '%s' reached power state '%s'.", c.nodeID, desiredState) return nil } time.Sleep(systemRebootDelay) @@ -134,12 +137,14 @@ func (c *Client) RebootSystem(ctx context.Context) error { } } + log.Debugf("Rebooting node '%s': powering off.", c.nodeID) resetReq := redfishClient.ResetRequestBody{} // Send PowerOff request resetReq.ResetType = redfishClient.RESETTYPE_FORCE_OFF _, httpResp, err := c.RedfishAPI.ResetSystem(ctx, c.nodeID, resetReq) if err = ScreenRedfishError(httpResp, err); err != nil { + log.Debugf("Failed to reboot node '%s': shutdown failure.", c.nodeID) return err } @@ -148,10 +153,13 @@ func (c *Client) RebootSystem(ctx context.Context) error { return err } + log.Debugf("Rebooting node '%s': powering on.", c.nodeID) + // Send PowerOn request resetReq.ResetType = redfishClient.RESETTYPE_ON _, httpResp, err = c.RedfishAPI.ResetSystem(ctx, c.nodeID, resetReq) if err = ScreenRedfishError(httpResp, err); err != nil { + log.Debugf("Failed to reboot node '%s': startup failure.", c.nodeID) return err } @@ -167,6 +175,8 @@ func (c *Client) SetBootSourceByType(ctx context.Context) error { return err } + log.Debugf("Setting boot device to '%s'.", vMediaType) + // Retrieve system information, containing available boot sources system, _, err := c.RedfishAPI.GetSystem(ctx, c.nodeID) if err != nil { @@ -180,7 +190,12 @@ func (c *Client) SetBootSourceByType(ctx context.Context) error { systemReq := redfishClient.ComputerSystem{} systemReq.Boot.BootSourceOverrideTarget = bootSource _, httpResp, err := c.RedfishAPI.SetSystem(ctx, c.nodeID, systemReq) - return ScreenRedfishError(httpResp, err) + if err = ScreenRedfishError(httpResp, err); err != nil { + return err + } + + log.Debug("Successfully set boot device.") + return nil } } @@ -190,6 +205,7 @@ func (c *Client) SetBootSourceByType(ctx context.Context) error { // SetVirtualMedia injects a virtual media device to an established virtual media ID. This assumes that isoPath is // accessible to the redfish server and virtualMedia device is either of type CD or DVD. func (c *Client) SetVirtualMedia(ctx context.Context, isoPath string) error { + log.Debugf("Inserting virtual media '%s'.", isoPath) // Eject all previously-inserted media if err := c.EjectVirtualMedia(ctx); err != nil { return err @@ -212,7 +228,12 @@ func (c *Client) SetVirtualMedia(ctx context.Context, isoPath string) error { vMediaReq.Inserted = true _, httpResp, err := c.RedfishAPI.InsertVirtualMedia(ctx, managerID, vMediaID, vMediaReq) - return ScreenRedfishError(httpResp, err) + if err = ScreenRedfishError(httpResp, err); err != nil { + return err + } + + log.Debug("Successfully set virtual media.") + return nil } // SystemPowerOff shuts down a host. diff --git a/pkg/remote/redfish/utils.go b/pkg/remote/redfish/utils.go index 469f22c33..03ac6139e 100644 --- a/pkg/remote/redfish/utils.go +++ b/pkg/remote/redfish/utils.go @@ -110,6 +110,7 @@ func DecodeRawError(rawResponse []byte) (string, error) { func GetManagerID(ctx context.Context, api redfishAPI.RedfishAPI, systemID string) (string, error) { system, httpResp, err := api.GetSystem(ctx, systemID) if err = ScreenRedfishError(httpResp, err); err != nil { + log.Debugf("Unable to find manager for node '%s'.", systemID) return "", err } @@ -144,6 +145,7 @@ func IsIDInList(idRefList []redfishClient.IdRef, id string) bool { // GetVirtualMediaID retrieves the ID of a Redfish virtual media resource if it supports type "CD" or "DVD". func GetVirtualMediaID(ctx context.Context, api redfishAPI.RedfishAPI, systemID string) (string, string, error) { + log.Debug("Searching for compatible media types.") managerID, err := GetManagerID(ctx, api, systemID) if err != nil { return "", "", err @@ -165,12 +167,15 @@ func GetVirtualMediaID(ctx context.Context, api redfishAPI.RedfishAPI, systemID for _, mediaType := range vMedia.MediaTypes { if mediaType == "CD" || mediaType == "DVD" { + log.Debugf("Found virtual media type '%s' with ID '%s' on manager '%s'.", mediaType, + mediaID, managerID) return mediaID, mediaType, nil } } } - return "", "", ErrRedfishClient{Message: "Unable to find virtual media with type CD or DVD"} + return "", "", ErrRedfishClient{Message: fmt.Sprintf("Manager '%s' does not have virtual media type CD or DVD.", + managerID)} } // ScreenRedfishError provides a detailed error message for end user consumption by inspecting all Redfish client diff --git a/pkg/remote/redfish/vendors/dell/client.go b/pkg/remote/redfish/vendors/dell/client.go index 18ecd13af..a8c5fae62 100644 --- a/pkg/remote/redfish/vendors/dell/client.go +++ b/pkg/remote/redfish/vendors/dell/client.go @@ -71,8 +71,10 @@ type iDRACAPIExtendedInfo struct { // SetBootSourceByType sets the boot source of the ephemeral node to a virtual CD, "VCD-DVD". func (c *Client) SetBootSourceByType(ctx context.Context) error { + log.Debug("Setting boot device to 'VCD-DVD'.") managerID, err := redfish.GetManagerID(ctx, c.RedfishAPI, c.NodeID()) if err != nil { + log.Debugf("Failed to retrieve manager ID for node '%s'.", c.NodeID()) return err } @@ -114,6 +116,7 @@ func (c *Client) SetBootSourceByType(ctx context.Context) error { return redfish.ErrRedfishClient{Message: fmt.Sprintf("Unable to set boot device. %v", err)} } + log.Debug("Successfully set boot device.") defer httpResp.Body.Close() return nil diff --git a/pkg/remote/remote_direct.go b/pkg/remote/remote_direct.go index 699217d5e..fd05b3ea1 100644 --- a/pkg/remote/remote_direct.go +++ b/pkg/remote/remote_direct.go @@ -33,9 +33,9 @@ func (b baremetalHost) DoRemoteDirect(settings *environment.AirshipCTLSettings) return config.ErrMissingConfig{What: "RemoteDirect options not defined in bootstrap config"} } - log.Debugf("Using ephemeral node %s with BMC Address %s", b.NodeID(), b.BMCAddress) + log.Debugf("Bootstrapping ephemeral host '%s' with ID '%s' and BMC Address '%s'.", b.HostName, b.NodeID(), + b.BMCAddress) - // Perform remote direct operations if remoteConfig.IsoURL == "" { return ErrMissingBootstrapInfoOption{What: "isoURL"} } @@ -45,8 +45,6 @@ func (b baremetalHost) DoRemoteDirect(settings *environment.AirshipCTLSettings) return err } - log.Debugf("Successfully loaded virtual media: %q", remoteConfig.IsoURL) - err = b.SetBootSourceByType(b.Context) if err != nil { return err @@ -57,7 +55,7 @@ func (b baremetalHost) DoRemoteDirect(settings *environment.AirshipCTLSettings) return err } - log.Debugf("Restarted ephemeral host %s", b.NodeID()) + log.Printf("Successfully bootstrapped ephemeral host '%s'.", b.HostName) return nil } diff --git a/roles/airshipctl-deploy-ephemeral-node/tasks/main.yaml b/roles/airshipctl-deploy-ephemeral-node/tasks/main.yaml index feece43ae..ee887978b 100644 --- a/roles/airshipctl-deploy-ephemeral-node/tasks/main.yaml +++ b/roles/airshipctl-deploy-ephemeral-node/tasks/main.yaml @@ -12,7 +12,7 @@ - name: deploy ephemeral node using redfish command: >- - airshipctl baremetal remotedirect + airshipctl baremetal remotedirect --debug - name: check kubectl version command: >-