Make installing the current firmware version a no-op (#47)

* check desired versions at the plan stage

* instrument plan execution

* review comment cleanup

Makefile

@@ -30,7 +30,7 @@ endif
 		"-X $(LDFLAG_LOCATION).GitCommit=$(GIT_COMMIT) \
          -X $(LDFLAG_LOCATION).GitBranch=$(GIT_BRANCH) \
          -X $(LDFLAG_LOCATION).GitSummary=$(GIT_SUMMARY) \
-         -X $(LDFLAG_LOCATION).Version=$(VERSION) \
+         -X $(LDFLAG_LOCATION).AppVersion=$(VERSION) \
          -X $(LDFLAG_LOCATION).BuildDate=$(BUILD_DATE)"
 
 
@@ -44,7 +44,7 @@ endif
 		"-X $(LDFLAG_LOCATION).GitCommit=$(GIT_COMMIT) \
          -X $(LDFLAG_LOCATION).GitBranch=$(GIT_BRANCH) \
          -X $(LDFLAG_LOCATION).GitSummary=$(GIT_SUMMARY) \
-         -X $(LDFLAG_LOCATION).Version=$(VERSION) \
+         -X $(LDFLAG_LOCATION).AppVersion=$(VERSION) \
          -X $(LDFLAG_LOCATION).BuildDate=$(BUILD_DATE)"
 
 

internal/outofband/actions.go

@@ -188,7 +188,7 @@ func transitionRules() []sw.TransitionRule {
 			PostTransition:   handler.PublishStatus,
 			Documentation: sw.TransitionRuleDoc{
 				Name:        "Check installed firmware",
-				Description: "Check firmware installed on component - if its equal - returns error, unless Task.Parameters.Force=true.",
+				Description: "Check firmware installed on component",
 			},
 		},
 		{

internal/statemachine/task.go

@@ -104,9 +104,6 @@ type TaskTransitioner interface {
 	// Plan creates a set of task actions to be executed.
 	Plan(task sw.StateSwitch, args sw.TransitionArgs) error
 
-	// ValidatePlan is called before invoking Run.
-	ValidatePlan(task sw.StateSwitch, args sw.TransitionArgs) (bool, error)
-
 	// Run executes the task actions.
 	Run(task sw.StateSwitch, args sw.TransitionArgs) error
 
@@ -194,7 +191,7 @@ func NewTaskStateMachine(handler TaskTransitioner) (*TaskStateMachine, error) {
 		TransitionType:   TransitionTypeRun,
 		SourceStates:     sw.States{model.StateActive},
 		DestinationState: model.StateSucceeded,
-		Condition:        handler.ValidatePlan,
+		Condition:        nil,
 		Transition:       handler.Run,
 		PostTransition:   handler.PublishStatus,
 		Documentation: sw.TransitionRuleDoc{

internal/worker/task_handler.go

@@ -1,6 +1,7 @@
 package worker
 
 import (
+	"fmt"
 	"sort"
 	"strings"
 	"time"
@@ -22,7 +23,6 @@ var (
 	ErrTaskTypeAssertion  = errors.New("error asserting Task type")
 	errTaskQueryInventory = errors.New("error in task query inventory for installed firmware")
 	errTaskPlanActions    = errors.New("error in task action planning")
-	errTaskPlanValidate   = errors.New("error in task plan validation")
 )
 
 // taskHandler implements the taskTransitionHandler methods
@@ -44,10 +44,7 @@ func (h *taskHandler) Query(t sw.StateSwitch, args sw.TransitionArgs) error {
 		return errors.Wrap(errTaskQueryInventory, ErrTaskTypeAssertion.Error())
 	}
 
-	// asset has component inventory
-	if len(tctx.Asset.Components) > 0 {
-		return nil
-	}
+	tctx.Logger.Debug("run query step")
 
 	// attempt to fetch component inventory from the device
 	components, err := h.queryFromDevice(tctx)
@@ -76,6 +73,8 @@ func (h *taskHandler) Plan(t sw.StateSwitch, args sw.TransitionArgs) error {
 		return errors.Wrap(ErrSaveTask, ErrTaskTypeAssertion.Error())
 	}
 
+	tctx.Logger.Debug("create the plan")
+
 	switch task.FirmwarePlanMethod {
 	case model.FromFirmwareSet:
 		return h.planFromFirmwareSet(tctx, task)
@@ -86,30 +85,6 @@ func (h *taskHandler) Plan(t sw.StateSwitch, args sw.TransitionArgs) error {
 	}
 }
 
-func (h *taskHandler) ValidatePlan(t sw.StateSwitch, args sw.TransitionArgs) (bool, error) {
-	tctx, ok := args.(*sm.HandlerContext)
-	if !ok {
-		return false, sm.ErrInvalidtaskHandlerContext
-	}
-
-	task, ok := t.(*model.Task)
-	if !ok {
-		return false, errors.Wrap(ErrSaveTask, ErrTaskTypeAssertion.Error())
-	}
-
-	// validate task has action plans listed
-	if len(task.ActionsPlanned) == 0 {
-		return false, errors.Wrap(errTaskPlanValidate, "no task actions planned")
-	}
-
-	// validate task context has action statemachines for execution
-	if len(tctx.ActionStateMachines) == 0 {
-		return false, errors.Wrap(errTaskPlanValidate, "task action plan empty")
-	}
-
-	return true, nil
-}
-
 func (h *taskHandler) registerActionMetrics(startTS time.Time, action *model.Action, state string) {
 	metrics.ActionRuntimeSummary.With(
 		prometheus.Labels{
@@ -131,8 +106,13 @@ func (h *taskHandler) Run(t sw.StateSwitch, args sw.TransitionArgs) error {
 		return errors.Wrap(ErrSaveTask, ErrTaskTypeAssertion.Error())
 	}
 
+	tctx.Logger.Debug("running the plan")
+
 	// each actionSM (state machine) corresponds to a firmware to be installed
 	for _, actionSM := range tctx.ActionStateMachines {
+		tctx.Logger.WithFields(logrus.Fields{
+			"statemachineID": actionSM.ActionID(),
+		}).Debug("state machine start")
 		startTS := time.Now()
 
 		// fetch action attributes from task
@@ -160,8 +140,12 @@ func (h *taskHandler) Run(t sw.StateSwitch, args sw.TransitionArgs) error {
 		}
 
 		h.registerActionMetrics(startTS, action, string(cptypes.Succeeded))
+		tctx.Logger.WithFields(logrus.Fields{
+			"statemachineID": actionSM.ActionID(),
+		}).Debug("state machine end")
 	}
 
+	tctx.Logger.Debug("plan finished")
 	return nil
 }
 
@@ -214,7 +198,8 @@ func (h *taskHandler) planFromFirmwareSet(tctx *sm.HandlerContext, task *model.T
 	}
 
 	if len(applicable) == 0 {
-		return errors.Wrap(errTaskPlanActions, "planFromFirmwareSet(): no applicable firmware identified")
+		// XXX: why not just short-circuit success here on the GIGO theory?
+		return errors.Wrap(errTaskPlanActions, "planFromFirmwareSet(): firmware set lacks any members")
 	}
 
 	// plan actions based and update task action list
@@ -266,23 +251,34 @@ func (h *taskHandler) queryFromDevice(tctx *sm.HandlerContext) (model.Components
 // planInstall sets up the firmware install plan
 //
 // This returns a list of actions to added to the task and a list of action state machines for those actions.
-func (h *taskHandler) planInstall(_ *sm.HandlerContext, task *model.Task, firmwares []*model.Firmware) (sm.ActionStateMachines, model.Actions, error) {
+func (h *taskHandler) planInstall(hCtx *sm.HandlerContext, task *model.Task, firmwares []*model.Firmware) (sm.ActionStateMachines, model.Actions, error) {
 	actionMachines := make(sm.ActionStateMachines, 0)
 	actions := make(model.Actions, 0)
 
 	// final is set to true in the final action
 	var final bool
 
-	sortFirmwareByInstallOrder(firmwares)
+	hCtx.Logger.WithFields(logrus.Fields{
+		"condition.id":             task.ID,
+		"requested.firmware.count": fmt.Sprintf("%d", len(firmwares)),
+	}).Info("checking against current inventory")
+
+	toInstall := firmwares
+
+	if !task.Parameters.ForceInstall {
+		toInstall = removeFirmwareAlreadyAtDesiredVersion(hCtx, firmwares)
+	}
+
+	if len(toInstall) == 0 {
+		hCtx.Logger.Info("no action required for this task")
+		return actionMachines, actions, nil
+	}
 
+	sortFirmwareByInstallOrder(toInstall)
 	// each firmware applicable results in an ActionPlan and an Action
-	for idx, firmware := range firmwares {
+	for idx, firmware := range toInstall {
 		// set final bool when its the last firmware in the slice
-		if len(firmwares) > 1 {
-			final = (idx == len(firmwares)-1)
-		} else {
-			final = true
-		}
+		final = (idx == len(toInstall)-1)
 
 		// generate an action ID
 		actionID := sm.ActionID(task.ID.String(), firmware.Component, idx)
@@ -337,3 +333,41 @@ func sortFirmwareByInstallOrder(firmwares []*model.Firmware) {
 		return model.FirmwareInstallOrder[slugi] < model.FirmwareInstallOrder[slugj]
 	})
 }
+
+func removeFirmwareAlreadyAtDesiredVersion(hCtx *sm.HandlerContext, fws []*model.Firmware) []*model.Firmware {
+	var toInstall []*model.Firmware
+
+	// only iterate the inventory once
+	invMap := make(map[string]string)
+	for _, cmp := range hCtx.Asset.Components {
+		invMap[strings.ToLower(cmp.Slug)] = cmp.FirmwareInstalled
+	}
+
+	// XXX: this will drop firmware for components that are specified in
+	// the firmware set but not in the inventory. This is consistent with the
+	// desire of users to not require a force or a re-run to accomplish an
+	// attainable goal.
+	for _, fw := range fws {
+		currentVersion, ok := invMap[strings.ToLower(fw.Component)]
+
+		switch {
+		case !ok:
+			hCtx.Logger.WithFields(logrus.Fields{
+				"component": fw.Component,
+			}).Warn("inventory missing component")
+		case strings.EqualFold(currentVersion, fw.Version):
+			hCtx.Logger.WithFields(logrus.Fields{
+				"component": fw.Component,
+				"version":   fw.Version,
+			}).Debug("inventory firmware version matches set")
+		default:
+			hCtx.Logger.WithFields(logrus.Fields{
+				"component":         fw.Component,
+				"installed.version": currentVersion,
+				"mandated.version":  fw.Version,
+			}).Debug("firmware queued for install")
+			toInstall = append(toInstall, fw)
+		}
+	}
+	return toInstall
+}

internal/worker/task_handler_test.go

@@ -3,8 +3,13 @@ package worker
 import (
 	"testing"
 
+	"github.com/google/uuid"
 	"github.com/metal-toolbox/flasher/internal/model"
+	sm "github.com/metal-toolbox/flasher/internal/statemachine"
+	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"go.hollow.sh/toolbox/events/registry"
 )
 
 func Test_sortFirmwareByInstallOrde(t *testing.T) {
@@ -66,3 +71,68 @@ func Test_sortFirmwareByInstallOrde(t *testing.T) {
 
 	assert.Equal(t, expected, have)
 }
+
+func TestRemoveFirmwareAlreadyAtDesiredVersion(t *testing.T) {
+	t.Parallel()
+	fwSet := []*model.Firmware{
+		{
+			Version:   "2.6.6",
+			URL:       "https://dl.dell.com/FOLDER08105057M/1/BIOS_C4FT0_WN64_2.6.6.EXE",
+			FileName:  "BIOS_C4FT0_WN64_2.6.6.EXE",
+			Models:    []string{"r6515"},
+			Checksum:  "1ddcb3c3d0fc5925ef03a3dde768e9e245c579039dd958fc0f3a9c6368b6c5f4",
+			Component: "bios",
+		},
+		{
+			Version:   "DL6R",
+			URL:       "https://downloads.dell.com/FOLDER06303849M/1/Serial-ATA_Firmware_Y1P10_WN32_DL6R_A00.EXE",
+			FileName:  "Serial-ATA_Firmware_Y1P10_WN32_DL6R_A00.EXE",
+			Models:    []string{"r6515"},
+			Checksum:  "4189d3cb123a781d09a4f568bb686b23c6d8e6b82038eba8222b91c380a25281",
+			Component: "drive",
+		},
+		{
+			Version:   "20.5.13",
+			URL:       "https://dl.dell.com/FOLDER08105057M/1/Network_Firmware_NVXX9_WN64_20.5.13_A00.EXE",
+			FileName:  "Network_Firmware_NVXX9_WN64_20.5.13_A00.EXE",
+			Models:    []string{"r6515"},
+			Checksum:  "b445417d7869bdbdffe7bad69ce32dc19fa29adc61f8e82a324545cabb53f30a",
+			Component: "nic",
+		},
+	}
+	serverID := uuid.MustParse("fa125199-e9dd-47d4-8667-ce1d26f58c4a")
+	ctx := &sm.HandlerContext{
+		Logger: logrus.NewEntry(logrus.New()),
+		Asset: &model.Asset{
+			ID: serverID,
+			Components: model.Components{
+				{
+					Slug:              "BiOs",
+					FirmwareInstalled: "2.6.6",
+				},
+				{
+					Slug:              "nic",
+					FirmwareInstalled: "some-different-version",
+				},
+			},
+		},
+		Task: &model.Task{
+			ID: serverID, // it just needs to be a UUID
+		},
+		WorkerID: registry.GetID("test-app"),
+	}
+	expected := []*model.Firmware{
+		{
+			Version:   "20.5.13",
+			URL:       "https://dl.dell.com/FOLDER08105057M/1/Network_Firmware_NVXX9_WN64_20.5.13_A00.EXE",
+			FileName:  "Network_Firmware_NVXX9_WN64_20.5.13_A00.EXE",
+			Models:    []string{"r6515"},
+			Checksum:  "b445417d7869bdbdffe7bad69ce32dc19fa29adc61f8e82a324545cabb53f30a",
+			Component: "nic",
+		},
+	}
+
+	got := removeFirmwareAlreadyAtDesiredVersion(ctx, fwSet)
+	require.Equal(t, 1, len(got))
+	require.Equal(t, expected[0], got[0])
+}

internal/worker/worker.go

@@ -14,6 +14,7 @@ import (
 	"github.com/metal-toolbox/flasher/internal/metrics"
 	"github.com/metal-toolbox/flasher/internal/model"
 	"github.com/metal-toolbox/flasher/internal/store"
+	"github.com/metal-toolbox/flasher/internal/version"
 	"github.com/nats-io/nats.go"
 	"github.com/pkg/errors"
 	"github.com/prometheus/client_golang/prometheus"
@@ -116,8 +117,12 @@ func (o *Worker) Run(ctx context.Context) {
 
 	o.startWorkerLivenessCheckin(ctx)
 
+	v := version.Current()
 	o.logger.WithFields(
 		logrus.Fields{
+			"version":         v.AppVersion,
+			"commit":          v.GitCommit,
+			"branch":          v.GitBranch,
 			"replica-count":   o.replicaCount,
 			"concurrency":     o.concurrency,
 			"dry-run":         o.dryrun,
@@ -396,8 +401,8 @@ func (o *Worker) runTaskWithMonitor(ctx context.Context, task *model.Task, asset
 		FacilityCode: o.facilityCode,
 		Logger: l.WithFields(
 			logrus.Fields{
-				"workerID":    o.id,
-				"conditionID": task.ID,
+				"workerID":    o.id.String(),
+				"conditionID": task.ID.String(),
 				"assetID":     asset.ID.String(),
 				"bmc":         asset.BmcAddress.String(),
 			},