Surface MPS control-daemon impairment reason as StatusReason

agent/doctor/docker_runtime_healthcheck.go

@@ -68,12 +68,13 @@ func (dhc *dockerRuntimeHealthcheck) RunCheck() ecstcs.InstanceHealthCheckStatus
 		seelog.Infof("[DockerRuntimeHealthcheck] Docker Ping failed with error: %v", res.Error)
 		resultStatus = ecstcs.InstanceHealthCheckStatusImpaired
 	}
-	dhc.SetHealthcheckStatus(resultStatus)
+	dhc.SetHealthcheckStatus(resultStatus, "")
 	return resultStatus
 }
 
-// SetHealthcheckStatus updates the health check status and timestamps.
-func (dhc *dockerRuntimeHealthcheck) SetHealthcheckStatus(healthStatus ecstcs.InstanceHealthCheckStatus) {
+// SetHealthcheckStatus updates the health check status and timestamps. The
+// Docker runtime check carries no status reason, so reason is ignored.
+func (dhc *dockerRuntimeHealthcheck) SetHealthcheckStatus(healthStatus ecstcs.InstanceHealthCheckStatus, reason string) {
 	dhc.lock.Lock()
 	defer dhc.lock.Unlock()
 	nowTime := time.Now()
@@ -90,6 +91,12 @@ func (dhc *dockerRuntimeHealthcheck) SetHealthcheckStatus(healthStatus ecstcs.In
 	dhc.TimeStamp = nowTime
 }
 
+// GetStatusReason returns a human-readable reason for the current status. The
+// Docker runtime health check does not carry one.
+func (dhc *dockerRuntimeHealthcheck) GetStatusReason() string {
+	return ""
+}
+
 // GetHealthcheckType returns the type of this health check.
 func (dhc *dockerRuntimeHealthcheck) GetHealthcheckType() string {
 	dhc.lock.RLock()

agent/doctor/docker_runtime_healthcheck_test.go

@@ -86,7 +86,7 @@ func TestSetHealthCheckStatus(t *testing.T) {
 	dockerClient := mock_dockerapi.NewMockDockerClient(ctrl)
 	dockerRuntimeHealthCheck := NewDockerRuntimeHealthcheck(dockerClient)
 	healthCheckStatus := ecstcs.InstanceHealthCheckStatusOk
-	dockerRuntimeHealthCheck.SetHealthcheckStatus(healthCheckStatus)
+	dockerRuntimeHealthCheck.SetHealthcheckStatus(healthCheckStatus, "")
 	assert.Equal(t, ecstcs.InstanceHealthCheckStatusOk, dockerRuntimeHealthCheck.Status)
 }
 
@@ -101,7 +101,7 @@ func TestSetHealthcheckStatusChange(t *testing.T) {
 	initializationChangeTime := dockerRuntimeHealthcheck.GetStatusChangeTime()
 
 	// We update to initializing again; our StatusChangeTime remains the same.
-	dockerRuntimeHealthcheck.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusInitializing)
+	dockerRuntimeHealthcheck.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusInitializing, "")
 	updateChangeTime := dockerRuntimeHealthcheck.GetStatusChangeTime()
 	assert.Equal(t, ecstcs.InstanceHealthCheckStatusInitializing, dockerRuntimeHealthcheck.Status)
 	assert.Equal(t, initializationChangeTime, updateChangeTime)
@@ -110,7 +110,7 @@ func TestSetHealthcheckStatusChange(t *testing.T) {
 	time.Sleep(1 * time.Millisecond)
 
 	// Change status. This should change the update time too.
-	dockerRuntimeHealthcheck.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusOk)
+	dockerRuntimeHealthcheck.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusOk, "")
 	assert.Equal(t, ecstcs.InstanceHealthCheckStatusOk, dockerRuntimeHealthcheck.Status)
 	okChangeTime := dockerRuntimeHealthcheck.GetStatusChangeTime()
 	// Have we updated our change time?

agent/doctor/ebs_csi_runtime_healthcheck.go

@@ -57,12 +57,12 @@ func (e *ebsCSIDaemonHealthcheck) RunCheck() ecstcs.InstanceHealthCheckStatus {
 	resp, err := e.csiClient.NodeGetCapabilities(ctx)
 	if err != nil {
 		logger.Error("EBS CSI Daemon health check failed", logger.Fields{field.Error: err})
-		e.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusImpaired)
+		e.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusImpaired, "")
 		return e.GetHealthcheckStatus()
 	}
 
 	logger.Info("EBS CSI Driver is healthy", logger.Fields{"nodeCapabilities": resp})
-	e.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusOk)
+	e.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusOk, "")
 	return e.GetHealthcheckStatus()
 }
 

agent/doctor/mps_daemon_healthcheck.go

@@ -33,6 +33,8 @@ import (
 // instance is reported ACCELERATED_COMPUTE=IMPAIRED
 const mpsDaemonImpairedThreshold = 3
 
+const maxStatusReasonLen = 1024
+
 type mpsDaemonHealthcheck struct {
 	*statustracker.HealthCheckStatusTracker
 
@@ -95,10 +97,28 @@ func (m *mpsDaemonHealthcheck) RunCheck() ecstcs.InstanceHealthCheckStatus {
 		logger.Debug("MPS control daemon is serving")
 	}
 
-	m.SetHealthcheckStatus(status)
+	// Surface the probe error as the status reason only on IMPAIRED, so the
+	// reason clears on recovery.
+	reason := ""
+	if status == ecstcs.InstanceHealthCheckStatusImpaired && res.Err != nil {
+		reason = boundStatusReason(res.Err.Error())
+	}
+
+	m.SetHealthcheckStatus(status, reason)
 	return m.GetHealthcheckStatus()
 }
 
+func boundStatusReason(reason string) string {
+	if len(reason) <= maxStatusReasonLen {
+		return reason
+	}
+	r := []rune(reason)
+	if len(r) <= maxStatusReasonLen {
+		return reason
+	}
+	return string(r[:maxStatusReasonLen])
+}
+
 // probe runs the pipe-directory pre-check and, if it passes, a single control-daemon
 // probe. The daemon is serving when the returned result has a nil Err. An unusable
 // pipe directory counts as this tick's failure and skips the exec; it can recover on a

agent/doctor/mps_daemon_healthcheck_test.go

@@ -21,8 +21,10 @@ import (
 	"errors"
 	"os"
 	"os/exec"
+	"strings"
 	"testing"
 	"time"
+	"unicode/utf8"
 
 	"github.com/aws/amazon-ecs-agent/ecs-agent/tcs/model/ecstcs"
 	mock_execwrapper "github.com/aws/amazon-ecs-agent/ecs-agent/utils/execwrapper/mocks"
@@ -101,17 +103,22 @@ const (
 	tickPipeMissing                 // pipe directory absent; the exec is skipped
 )
 
-// tick pairs a probe outcome with the instance status the check must report after it.
+// tick pairs a probe outcome with the instance status the check must report after it,
+// and the substring the impaired reason must contain (empty while Ok, since the reason
+// is set only on IMPAIRED and cleared on recovery).
 type tick struct {
-	kind tickKind
-	want ecstcs.InstanceHealthCheckStatus
+	kind       tickKind
+	want       ecstcs.InstanceHealthCheckStatus
+	wantReason string
 }
 
 // TestMpsRunCheckSequences drives RunCheck through sequences of probe outcomes and
-// asserts the reported status after every tick. Because a serving tick zeroes the
-// counter, a status-only assertion still proves the reset semantics: a failure that
-// follows a success reports Ok where an unbroken streak of the same length would be
-// Impaired.
+// asserts the reported status and status reason after every tick. Because a serving
+// tick zeroes the counter, a status-only assertion still proves the reset semantics: a
+// failure that follows a success reports Ok where an unbroken streak of the same length
+// would be Impaired. The reason is populated from the probe error only while Impaired
+// and clears on recovery, mirroring the wire StatusReason (set on IMPAIRED, null
+// otherwise).
 func TestMpsRunCheckSequences(t *testing.T) {
 	const (
 		ok       = ecstcs.InstanceHealthCheckStatusOk
@@ -125,43 +132,45 @@ func TestMpsRunCheckSequences(t *testing.T) {
 			// Anti-flap: below the threshold a failing probe must not report IMPAIRED,
 			// so a short restart that lands on a tick is absorbed.
 			name:  "below threshold stays ok",
-			ticks: []tick{{tickFailure, ok}, {tickFailure, ok}},
+			ticks: []tick{{tickFailure, ok, ""}, {tickFailure, ok, ""}},
 		},
 		{
 			name:  "third consecutive failure impaired",
-			ticks: []tick{{tickFailure, ok}, {tickFailure, ok}, {tickFailure, impaired}},
+			ticks: []tick{{tickFailure, ok, ""}, {tickFailure, ok, ""}, {tickFailure, impaired, "probe failed"}},
 		},
 		{
 			// The fourth tick is Ok only because the success zeroed the counter; an
 			// unbroken streak of four failures would have been Impaired by tick three.
 			name:  "success resets counter",
-			ticks: []tick{{tickFailure, ok}, {tickFailure, ok}, {tickServing, ok}, {tickFailure, ok}},
+			ticks: []tick{{tickFailure, ok, ""}, {tickFailure, ok, ""}, {tickServing, ok, ""}, {tickFailure, ok, ""}},
 		},
 		{
 			// A single success mid-streak keeps the count from ever reaching the
 			// threshold, so the instance never reports Impaired.
 			name: "single success mid streak resets",
-			ticks: []tick{{tickFailure, ok}, {tickFailure, ok}, {tickServing, ok},
-				{tickFailure, ok}, {tickFailure, ok}},
+			ticks: []tick{{tickFailure, ok, ""}, {tickFailure, ok, ""}, {tickServing, ok, ""},
+				{tickFailure, ok, ""}, {tickFailure, ok, ""}},
 		},
 		{
-			// A timeout is a failure like any other, and three in a row cross the threshold.
+			// A timeout is a failure like any other, and three in a row cross the
+			// threshold; the impaired reason reports the wedged daemon.
 			name:  "timeout counts as failure",
-			ticks: []tick{{tickTimeout, ok}, {tickTimeout, ok}, {tickTimeout, impaired}},
+			ticks: []tick{{tickTimeout, ok, ""}, {tickTimeout, ok, ""}, {tickTimeout, impaired, "timed out"}},
 		},
 		{
 			// A missing pipe directory skips the exec and counts as one failure. Unlike
 			// the task gate this is not fail-closed, so three such ticks report Impaired
-			// and a later serving probe resets to Ok.
+			// (with the stat error as the reason) and a later serving probe resets to Ok.
 			name: "pipe directory missing counts as failure then recovers",
-			ticks: []tick{{tickPipeMissing, ok}, {tickPipeMissing, ok},
-				{tickPipeMissing, impaired}, {tickServing, ok}},
+			ticks: []tick{{tickPipeMissing, ok, ""}, {tickPipeMissing, ok, ""},
+				{tickPipeMissing, impaired, "no such file"}, {tickServing, ok, ""}},
 		},
 		{
-			// Recovery: once past the threshold a serving probe returns the instance to Ok.
+			// Recovery: once past the threshold a serving probe returns the instance to
+			// Ok and clears the reason.
 			name: "recovery returns to ok",
-			ticks: []tick{{tickFailure, ok}, {tickFailure, ok}, {tickFailure, impaired},
-				{tickServing, ok}},
+			ticks: []tick{{tickFailure, ok, ""}, {tickFailure, ok, ""}, {tickFailure, impaired, "probe failed"},
+				{tickServing, ok, ""}},
 		},
 	}
 
@@ -193,7 +202,16 @@ func TestMpsRunCheckSequences(t *testing.T) {
 				case tickPipeMissing:
 					// probe short-circuits on the stat error; no exec is expected.
 				}
-				assert.Equalf(t, tk.want, hc.RunCheck(), "tick %d", i)
+				assert.Equalf(t, tk.want, hc.RunCheck(), "tick %d status", i)
+				if tk.want == impaired {
+					// The impaired reason carries the probe error and stays within the MHS limit.
+					reason := hc.GetStatusReason()
+					assert.Containsf(t, reason, tk.wantReason, "tick %d reason", i)
+					assert.LessOrEqualf(t, len(reason), maxStatusReasonLen, "tick %d reason bounded", i)
+				} else {
+					// Below the threshold, and on recovery, no reason is reported.
+					assert.Emptyf(t, hc.GetStatusReason(), "tick %d reason cleared while ok", i)
+				}
 			}
 		})
 	}
@@ -226,3 +244,18 @@ func TestMpsRecoveryTransitionAdvancesStatusChangeTime(t *testing.T) {
 		"recovery is a status change and must advance GetStatusChangeTime")
 	assert.Equal(t, ecstcs.InstanceHealthCheckStatusImpaired, hc.GetLastHealthcheckStatus())
 }
+
+// A reason longer than the MHS limit is truncated on a rune boundary.
+func TestBoundStatusReason(t *testing.T) {
+	assert.Equal(t, "short", boundStatusReason("short"))
+
+	long := strings.Repeat("a", maxStatusReasonLen+50)
+	assert.Equal(t, maxStatusReasonLen, len(boundStatusReason(long)))
+
+	// Multibyte runes must not be split, so the byte length can exceed the limit
+	// while the rune count does not.
+	multibyte := strings.Repeat("é", maxStatusReasonLen+50)
+	bounded := boundStatusReason(multibyte)
+	assert.Equal(t, maxStatusReasonLen, len([]rune(bounded)))
+	assert.True(t, utf8.ValidString(bounded), "truncation keeps the string valid UTF-8")
+}

agent/doctor/statustracker/statustracker.go

@@ -22,6 +22,7 @@ import (
 // HealthCheckStatusTracker is a helper for keeping track of current and last health check status.
 type HealthCheckStatusTracker struct {
 	status           ecstcs.InstanceHealthCheckStatus
+	statusReason     string
 	timeStamp        time.Time
 	statusChangeTime time.Time
 	lastStatus       ecstcs.InstanceHealthCheckStatus
@@ -65,8 +66,17 @@ func (e *HealthCheckStatusTracker) GetLastHealthcheckTime() time.Time {
 	return e.lastTimeStamp
 }
 
-// SetHealthcheckStatus updates the health check status and timestamps.
-func (e *HealthCheckStatusTracker) SetHealthcheckStatus(healthStatus ecstcs.InstanceHealthCheckStatus) {
+// GetStatusReason returns the human-readable reason for the current status, or the
+// empty string when there is none.
+func (e *HealthCheckStatusTracker) GetStatusReason() string {
+	e.lock.RLock()
+	defer e.lock.RUnlock()
+	return e.statusReason
+}
+
+// SetHealthcheckStatus updates the status, its reason, and the timestamps together
+// under the write lock. Pass an empty reason when there is none.
+func (e *HealthCheckStatusTracker) SetHealthcheckStatus(healthStatus ecstcs.InstanceHealthCheckStatus, reason string) {
 	e.lock.Lock()
 	defer e.lock.Unlock()
 	nowTime := e.now()
@@ -80,8 +90,9 @@ func (e *HealthCheckStatusTracker) SetHealthcheckStatus(healthStatus ecstcs.Inst
 	e.lastStatus = e.status
 	e.lastTimeStamp = e.timeStamp
 
-	// Update latest status.
+	// Update latest status and its reason.
 	e.status = healthStatus
+	e.statusReason = reason
 	e.timeStamp = nowTime
 }
 

agent/doctor/statustracker/statustracker_test.go

@@ -33,7 +33,7 @@ func TestHealthCheckStatusTracker(t *testing.T) {
 	})
 	t.Run("last status and timestamp is captured", func(t *testing.T) {
 		tracker := newHealthCheckStatusTrackerWithTimeFn(incrementalTime())
-		tracker.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusOk)
+		tracker.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusOk, "")
 
 		assert.Equal(t, ecstcs.InstanceHealthCheckStatusOk, tracker.GetHealthcheckStatus())
 		assert.Equal(t, ecstcs.InstanceHealthCheckStatusInitializing, tracker.GetLastHealthcheckStatus())
@@ -45,7 +45,7 @@ func TestHealthCheckStatusTracker(t *testing.T) {
 		tracker := newHealthCheckStatusTrackerWithTimeFn(incrementalTime())
 		// Update (but not change) status a bunch of times.
 		for i := 0; i < 10; i++ {
-			tracker.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusOk)
+			tracker.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusOk, "")
 		}
 
 		assert.Equal(t, ecstcs.InstanceHealthCheckStatusOk, tracker.GetHealthcheckStatus())
@@ -56,15 +56,30 @@ func TestHealthCheckStatusTracker(t *testing.T) {
 	})
 	t.Run("multiple updates", func(t *testing.T) {
 		tracker := newHealthCheckStatusTrackerWithTimeFn(incrementalTime())
-		tracker.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusOk)
-		tracker.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusImpaired)
+		tracker.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusOk, "")
+		tracker.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusImpaired, "")
 
 		assert.Equal(t, ecstcs.InstanceHealthCheckStatusImpaired, tracker.GetHealthcheckStatus())
 		assert.Equal(t, ecstcs.InstanceHealthCheckStatusOk, tracker.GetLastHealthcheckStatus())
 		assert.Equal(t, int64(2), tracker.GetLastHealthcheckTime().Unix())
 		assert.Equal(t, int64(3), tracker.GetHealthcheckTime().Unix())
 		assert.Equal(t, int64(3), tracker.GetStatusChangeTime().Unix())
 	})
+	t.Run("status reason is set and cleared with status", func(t *testing.T) {
+		tracker := newHealthCheckStatusTrackerWithTimeFn(incrementalTime())
+		// Default: no reason.
+		assert.Equal(t, "", tracker.GetStatusReason())
+
+		// IMPAIRED with a reason.
+		tracker.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusImpaired, "probe failed")
+		assert.Equal(t, ecstcs.InstanceHealthCheckStatusImpaired, tracker.GetHealthcheckStatus())
+		assert.Equal(t, "probe failed", tracker.GetStatusReason())
+
+		// Recovering to OK clears the reason.
+		tracker.SetHealthcheckStatus(ecstcs.InstanceHealthCheckStatusOk, "")
+		assert.Equal(t, ecstcs.InstanceHealthCheckStatusOk, tracker.GetHealthcheckStatus())
+		assert.Equal(t, "", tracker.GetStatusReason())
+	})
 }
 
 // Returns a replacement function for time.Now() for testing.

ecs-agent/doctor/doctor_test.go

@@ -34,7 +34,8 @@ type trueHealthcheck struct{}
 func (tc *trueHealthcheck) RunCheck() ecstcs.InstanceHealthCheckStatus {
 	return ecstcs.InstanceHealthCheckStatusOk
 }
-func (tc *trueHealthcheck) SetHealthcheckStatus(status ecstcs.InstanceHealthCheckStatus) {}
+func (tc *trueHealthcheck) SetHealthcheckStatus(status ecstcs.InstanceHealthCheckStatus, reason string) {
+}
 func (tc *trueHealthcheck) GetHealthcheckType() string {
 	return ecstcs.InstanceHealthCheckTypeAgent
 }
@@ -53,13 +54,17 @@ func (tc *trueHealthcheck) GetStatusChangeTime() time.Time {
 func (tc *trueHealthcheck) GetLastHealthcheckTime() time.Time {
 	return time.Date(1974, time.May, 19, 1, 2, 3, 4, time.UTC)
 }
+func (tc *trueHealthcheck) GetStatusReason() string {
+	return ""
+}
 
 type falseHealthcheck struct{}
 
 func (fc *falseHealthcheck) RunCheck() ecstcs.InstanceHealthCheckStatus {
 	return ecstcs.InstanceHealthCheckStatusImpaired
 }
-func (fc *falseHealthcheck) SetHealthcheckStatus(status ecstcs.InstanceHealthCheckStatus) {}
+func (fc *falseHealthcheck) SetHealthcheckStatus(status ecstcs.InstanceHealthCheckStatus, reason string) {
+}
 func (fc *falseHealthcheck) GetHealthcheckType() string {
 	return ecstcs.InstanceHealthCheckTypeAgent
 }
@@ -78,6 +83,9 @@ func (fc *falseHealthcheck) GetStatusChangeTime() time.Time {
 func (fc *falseHealthcheck) GetLastHealthcheckTime() time.Time {
 	return time.Date(1974, time.May, 19, 1, 2, 3, 4, time.UTC)
 }
+func (fc *falseHealthcheck) GetStatusReason() string {
+	return ""
+}
 
 func TestNewDoctor(t *testing.T) {
 	trueCheck := &trueHealthcheck{}