Update status on enable

internal/hostgacommunicator/hostgacommunicator.go

@@ -18,6 +18,37 @@ import (
 const hostGaPluginPort = "32526"
 const WireProtocolAddress = "AZURE_GUEST_AGENT_WIRE_PROTOCOL_ADDRESS"
 const wireServerFallbackAddress = "http://168.63.129.16:32526"
+const HostGaMetadataErrorPrefix = "HostGaCommunicator GetVMAppInfo error"
+
+type HostGaCommunicatorError int
+
+const (
+	InitializationError HostGaCommunicatorError = iota
+	MetadataRequestFailedWithRetries
+	MetadataRequestFailedInvalidResponseBody
+)
+
+func (hostGaCommunicatorError HostGaCommunicatorError) ToString() string {
+	switch hostGaCommunicatorError {
+	case InitializationError:
+		return "InitializationError"
+	case MetadataRequestFailedWithRetries:
+		return "MetadataRequestFailedWithRetries"
+	case MetadataRequestFailedInvalidResponseBody:
+		return "MetadataRequestFailedInvalidResponseBody"
+	default:
+		return "UnknownError"
+	}
+}
+
+type HostGaCommunicatorGetVMAppInfoError struct {
+	errorMessage string
+	errorType    HostGaCommunicatorError
+}
+
+func (e *HostGaCommunicatorGetVMAppInfoError) Error() string {
+	return fmt.Sprintf("%s: %s, error type: %s", HostGaMetadataErrorPrefix, e.errorMessage, e.errorType.ToString())
+}
 
 type IHostGaCommunicator interface {
 	DownloadPackage(el *logging.ExtensionLogger, appName string, dst string) error
@@ -33,7 +64,10 @@ type HostGaCommunicator struct{}
 func (*HostGaCommunicator) GetVMAppInfo(el *logging.ExtensionLogger, appName string) (*VMAppMetadata, error) {
 	requestManager, isArc, err := getMetadataRequestManager(el, appName)
 	if err != nil {
-		return nil, errors.Wrapf(err, "Could not create the request manager")
+		return nil, &HostGaCommunicatorGetVMAppInfoError{
+			errorMessage: fmt.Sprintf("Could not create the request manager: %v", err),
+			errorType:    InitializationError,
+		}
 	}
 
 	var resp *http.Response
@@ -47,7 +81,10 @@ func (*HostGaCommunicator) GetVMAppInfo(el *logging.ExtensionLogger, appName str
 	}
 
 	if err != nil {
-		return nil, errors.Wrapf(err, "Metadata request failed with retries.")
+		return nil, &HostGaCommunicatorGetVMAppInfoError{
+			errorMessage: fmt.Sprintf("Metadata request failed after retries: %v", err),
+			errorType:    MetadataRequestFailedWithRetries,
+		}
 	}
 
 	body := resp.Body
@@ -56,7 +93,10 @@ func (*HostGaCommunicator) GetVMAppInfo(el *logging.ExtensionLogger, appName str
 	var target VMAppMetadataReceiver
 	err = json.NewDecoder(body).Decode(&target)
 	if err != nil {
-		return nil, errors.Wrapf(err, "failed to decode response body")
+		return nil, &HostGaCommunicatorGetVMAppInfoError{
+			errorMessage: fmt.Sprintf("Failed to decode response body: %v", err),
+			errorType:    MetadataRequestFailedInvalidResponseBody,
+		}
 	}
 
 	return target.MapToVMAppMetadata(), nil

internal/hostgacommunicator/hostgacommunicator_test.go

@@ -60,7 +60,7 @@ func TestGetVmAppInfo_RequestFailed(t *testing.T) {
 	hgc := &HostGaCommunicator{}
 	_, err := hgc.GetVMAppInfo(nopLog(), myAppName)
 	require.NotNil(t, err, "did not fail")
-	require.Contains(t, err.Error(), "Metadata request failed with retries.", "Wrong message for failed request")
+	require.Contains(t, err.Error(), "Metadata request failed after retries:", "Wrong message for failed request")
 }
 
 func TestGetVmAppInfo_CouldNotDecodeResponse(t *testing.T) {
@@ -75,7 +75,7 @@ func TestGetVmAppInfo_CouldNotDecodeResponse(t *testing.T) {
 	hgc := &HostGaCommunicator{}
 	_, err := hgc.GetVMAppInfo(nopLog(), myAppName)
 	require.NotNil(t, err, "did not fail")
-	require.Contains(t, err.Error(), "failed to decode response body", "Wrong message for invalid response")
+	require.Contains(t, err.Error(), "Failed to decode response body:", "Wrong message for invalid response")
 }
 
 func TestGetVmAppInfo_MissingProperties(t *testing.T) {

launcher/main.go

@@ -85,7 +85,7 @@ func main() {
 
 	if requestedSequenceNumber >= currentSequenceNumber {
 		// attempt to write a transitioning status file if it doesn't exist
-		_, getStatusError := utils.GetStatusType(handlerEnv, requestedSequenceNumber)
+		_, getStatusError := utils.GetStatus(handlerEnv, requestedSequenceNumber)
 		if getStatusError != nil {
 			// either no transitioning status file was found, or the status file was malformed
 			// either way create a new transitioning status file

main/main.go

@@ -27,7 +27,6 @@ import (
 var (
 	ExtensionName         string     // assign at compile time
 	ExtensionVersion      = "1.0.10" // should be assigned at compile time, do not edit in code
-	reportStatusFunc      = utils.ReportStatus
 	getVMExtensionFunc    = getVMExtension
 	customEnableFunc      = customEnable
 	setSequenceNumberFunc = seqno.SetSequenceNumber
@@ -95,15 +94,24 @@ func getExtensionAndRun(arguments []string) error {
 				ext.ExtensionLogger.Error(errorMessage)
 				ext.ExtensionEvents.LogErrorEvent("Enable Failed", errorMessage)
 			default:
+				if _, ok := enableError.(*hostgacommunicator.HostGaCommunicatorGetVMAppInfoError); ok {
+					// Preserve the last good status file if it exists and isn't already a
+					// HostGA network error
+					if statusObj, err := utils.GetStatus(ext.HandlerEnv, requestedSequenceNumber); err == nil {
+						msg := statusObj.FormattedMessage.Message
+						if !strings.HasPrefix(msg, hostgacommunicator.HostGaMetadataErrorPrefix) {
+							if err := utils.BackupStatusFile(ext.HandlerEnv.StatusFolder, requestedSequenceNumber); err != nil {
+								ext.ExtensionLogger.Warn("Failed to back up status file for sequence %d: %v", requestedSequenceNumber, err)
+							}
+						}
+					}
+				}
 				ext.ExtensionLogger.Error(enableError.Error())
 				ext.ExtensionEvents.LogErrorEvent("Enable Failed", enableError.Error())
 				// try to save status file
 				statusMessage := enableError.Error()
-				err := reportStatusFunc(ext.HandlerEnv, requestedSequenceNumber, status.StatusError, vmextensionhelper.EnableOperation.ToStatusName(), statusMessage)
+				err := reportStatusFunc(ext, requestedSequenceNumber, status.StatusError, vmextensionhelper.EnableOperation.ToStatusName(), statusMessage)
 				if err != nil {
-					errorMessage := fmt.Sprintf("Failed to save status file: %s", err.Error())
-					ext.ExtensionLogger.Error(errorMessage)
-					ext.ExtensionEvents.LogErrorEvent("Save Status", errorMessage)
 					return err
 				}
 			}
@@ -214,37 +222,18 @@ func customEnable(ext *vmextensionhelper.VMExtension, hostgaCommunicator hostgac
 		return errors.Wrapf(err, "Could not get package registry")
 	}
 
-	// write success status if requested sequence number is newer
-	shouldReportStatus := false
-
-	if ext.CurrentSequenceNumber == nil || requestedSequenceNumber > *ext.CurrentSequenceNumber {
-		shouldReportStatus = true
-	} else if requestedSequenceNumber == *ext.CurrentSequenceNumber {
-		statusType, err := utils.GetStatusType(ext.HandlerEnv, requestedSequenceNumber)
-		if err != nil || strings.EqualFold(string(statusType), string(status.StatusTransitioning)) {
-			// either something is wrong with the status file
-			// or its a transitioning status file
-			// overwrite it in either case
-			shouldReportStatus = true
-		}
-	}
-	if shouldReportStatus {
-		var statusResult status.StatusType
-		statusMessage := getStatusMessage(currentPackageRegistry.GetPackageCollection(), executeError, result)
-		if executeError.GetErrorIfDeploymentFailed() == nil { // treatFailureAsDeploymentFailure
-			statusResult = status.StatusSuccess
-		} else {
-			statusResult = status.StatusError
-		}
-		err := utils.ReportStatus(ext.HandlerEnv, requestedSequenceNumber, statusResult, vmextensionhelper.EnableOperation.ToStatusName(), statusMessage)
+	statusUpdated, statusResult, statusMessage := computeStatus(ext, requestedSequenceNumber, &currentPackageRegistry, executeError, result, vmAppResults)
+
+	if statusUpdated {
+		err := reportStatusFunc(ext, requestedSequenceNumber, statusResult, vmextensionhelper.EnableOperation.ToStatusName(), statusMessage)
 		if err != nil {
-			errorMessage := fmt.Sprintf("Failed to save status file: %s", err.Error())
-			ext.ExtensionLogger.Error(errorMessage)
-			ext.ExtensionEvents.LogErrorEvent("Save Status", errorMessage)
 			return err
 		}
+
 		// update the sequence number that has been executed
-		if err := setSequenceNumberFunc(ExtensionName, ExtensionVersion, requestedSequenceNumber); err != nil {
+		err = setSequenceNumberFunc(ExtensionName, ExtensionVersion, requestedSequenceNumber)
+		if err != nil {
+			// log but not return the error
 			errorMessage := fmt.Sprintf("Failed to update sequence number to %d: %s", requestedSequenceNumber, err.Error())
 			ext.ExtensionLogger.Error(errorMessage)
 			ext.ExtensionEvents.LogErrorEvent("Update Sequence Number", errorMessage)
@@ -258,7 +247,94 @@ func customEnable(ext *vmextensionhelper.VMExtension, hostgaCommunicator hostgac
 	return nil
 }
 
-// Callback indicating the extension is being removed
+func computeStatus(
+	ext *vmextensionhelper.VMExtension,
+	requestedSequenceNumber uint,
+	currentPackageRegistry *packageregistry.CurrentPackageRegistry,
+	executeError *actionplan.ExecuteError,
+	customActionResult actionplan.IResult,
+	vmAppResults *actionplan.PackageOperationResults,
+) (bool, status.StatusType, string) {
+	statusUpdated := false
+	var statusResult status.StatusType
+	var statusMessage string
+
+	if vmAppResults != nil && len(*vmAppResults) > 0 {
+		// executeError is only meaningful if there are VM App operations, otherwise
+		// it is the equivalent of no error (i.e success).
+		statusMessage = getStatusMessage(currentPackageRegistry.GetPackageCollection(), executeError, customActionResult)
+		if executeError.GetErrorIfDeploymentFailed() == nil { // treatFailureAsDeploymentFailure
+			statusResult = status.StatusSuccess
+		} else {
+			statusResult = status.StatusError
+		}
+		statusUpdated = true
+	} else {
+		// These next cases are dependent on the existing status
+		statusObj, err := utils.GetStatus(ext.HandlerEnv, requestedSequenceNumber)
+		if err != nil {
+			// Existing status file maybe corrupted or missing. The existing behavior is
+			// to write a success status.
+			statusMessage = fmt.Sprintf("Failed to read existing status file: %v. Writing success status.", err)
+			statusResult = status.StatusSuccess
+			statusUpdated = true
+		} else if strings.EqualFold(string(statusObj.Status), string(status.StatusTransitioning)) {
+			// If the status is Transitioning whenever there's a new requested sequence number,
+			// as the Transitioning status is saved by launcher program.
+			if ext.CurrentSequenceNumber == nil || requestedSequenceNumber == *ext.CurrentSequenceNumber {
+				// If this the very first time this extension is Enabled, or we're processing
+				// the same sequence number, and there is no VM App to process, save the status as Success
+				// It is also possible that a VM App cause a reboot but is not re-run again leading to
+				// no VM App operations. We should also set the status to success in this case.
+				statusMessage = "No VM App operations to perform, but current status is Transitioning. Updating status to Success."
+				statusResult = status.StatusSuccess
+			} else {
+				// If this is a new sequence number with no VM App operations, then report
+				// the same status as the last sequence number.
+				// This case can happen if the user changes the ordering inside applicationProfile
+				// without changing any app or their installation order.
+				prevStatusObj, prevStatusErr := utils.GetStatus(ext.HandlerEnv, *ext.CurrentSequenceNumber)
+				if prevStatusErr != nil {
+					// No existing status save, should record as success since there are no VM App operations
+					statusMessage = fmt.Sprintf("No existing status file found for sequence %d, and no VM App operations. Writing success status.", *ext.CurrentSequenceNumber)
+					statusResult = status.StatusSuccess
+				} else {
+					statusMessage = prevStatusObj.FormattedMessage.Message
+					statusResult = prevStatusObj.Status
+				}
+			}
+			statusUpdated = true
+		} else if strings.Contains(statusObj.FormattedMessage.Message, hostgacommunicator.HostGaMetadataErrorPrefix) {
+			// If there is no VM App operations, but the current status is a transient host GA
+			// communication error, the status should be the same as the last stable status
+			prevStatusObj, prevStatusErr := utils.GetLastStableStatus(ext.HandlerEnv, *ext.CurrentSequenceNumber)
+			if prevStatusErr != nil {
+				// No last stable status save, should record as success since the hostGA issue
+				// is gone
+				statusResult = status.StatusSuccess
+				statusMessage = "No last stable status found, and no VM App operations."
+			} else {
+				statusResult = prevStatusObj.Status
+				statusMessage = prevStatusObj.FormattedMessage.Message
+			}
+			statusUpdated = true
+		}
+	}
+
+	return statusUpdated, statusResult, statusMessage
+}
+
+// A wrapper for utils.ReportStatus to log any errors occurring in that function
+func reportStatusFunc(ext *vmextensionhelper.VMExtension, requestedSequenceNumber uint, statusType status.StatusType, operationName string, message string) error {
+	err := utils.ReportStatus(ext.HandlerEnv, requestedSequenceNumber, statusType, operationName, message)
+	if err != nil {
+		errorMessage := fmt.Sprintf("Failed to save status file: %s", err.Error())
+		ext.ExtensionLogger.Error(errorMessage)
+		ext.ExtensionEvents.LogErrorEvent("Save Status", errorMessage)
+	}
+	return err
+}
+
 func vmAppUninstallCallback(ext *vmextensionhelper.VMExtension) error {
 	ext.ExtensionEvents.LogInformationalEvent("Uninstalling", "VmApplications extension - removing all applications for uninstall")
 	hostGaCommunicator := hostgacommunicator.HostGaCommunicator{}