improve logging for eni attachment issues

aws · Nov 4, 2020 · 55100e4 · 55100e4
1 parent 006b065
commit 55100e4
Show file tree

Hide file tree

Showing 4 changed files with 13 additions and 10 deletions.
diff --git a/agent/acs/handler/attach_eni_handler_common.go b/agent/acs/handler/attach_eni_handler_common.go
@@ -39,11 +39,11 @@ type ackTimeoutHandler struct {
 func (handler *ackTimeoutHandler) handle() {
 	eniAttachment, ok := handler.state.ENIByMac(handler.mac)
 	if !ok {
-		seelog.Warnf("Ignoring unmanaged ENI attachment with MAC address: %s", handler.mac)
+		seelog.Warnf("Ignoring unmanaged ENI attachment mac=%s", handler.mac)
 		return
 	}
 	if !eniAttachment.IsSent() {
-		seelog.Warnf("Timed out waiting for ENI ack; removing ENI attachment record with MAC address: %s", handler.mac)
+		seelog.Warnf("Timed out waiting for ENI ack; removing ENI attachment record %s", eniAttachment.String())
 		handler.removeENIAttachmentData(handler.mac)
 		handler.state.RemoveENIAttachment(handler.mac)
 	}
@@ -89,12 +89,14 @@ func handleENIAttachment(attachmentType, attachmentARN, taskARN, mac string,
 	seelog.Infof("Handling ENI attachment: %s", attachmentARN)
 
 	if eniAttachment, ok := state.ENIByMac(mac); ok {
-		seelog.Infof("Duplicate %s attachment message for ENI with MAC address: %s", attachmentType, mac)
+		seelog.Infof("Duplicate %s attachment message for ENI mac=%s taskARN=%s attachmentARN=%s",
+			attachmentType, mac, taskARN, attachmentARN)
 		eniAckTimeoutHandler := ackTimeoutHandler{mac: mac, state: state, dataClient: dataClient}
 		return eniAttachment.StartTimer(eniAckTimeoutHandler.handle)
 	}
 	if err := addENIAttachmentToState(attachmentType, attachmentARN, taskARN, mac, expiresAt, state, dataClient); err != nil {
-		return errors.Wrapf(err, fmt.Sprintf("attach %s message handler: unable to add eni attachment to engine state", attachmentType))
+		return errors.Wrapf(err, fmt.Sprintf("attach %s message handler: unable to add eni attachment to engine state mac=%s taskARN=%s attachmentARN=%s",
+			attachmentType, mac, taskARN, attachmentARN))
 	}
 	return nil
 }

diff --git a/agent/api/eni/eniattachment.go b/agent/api/eni/eniattachment.go
@@ -143,11 +143,11 @@ func (eni *ENIAttachment) stringUnsafe() string {
 	// skip TaskArn field for instance level eni attachment since it won't have a task arn
 	if eni.AttachmentType == ENIAttachmentTypeInstanceENI {
 		return fmt.Sprintf(
-			"ENI Attachment: attachment=%s;attachmentType=%s;attachmentSent=%t;mac=%s;status=%s;expiresAt=%s",
-			eni.AttachmentARN, eni.AttachmentType, eni.AttachStatusSent, eni.MACAddress, eni.Status.String(), eni.ExpiresAt.String())
+			"ENI Attachment: attachment=%s attachmentType=%s attachmentSent=%t mac=%s status=%s expiresAt=%s",
+			eni.AttachmentARN, eni.AttachmentType, eni.AttachStatusSent, eni.MACAddress, eni.Status.String(), eni.ExpiresAt.Format(time.RFC3339))
 	}
 
 	return fmt.Sprintf(
-		"ENI Attachment: task=%s;attachment=%s;attachmentType=%s;attachmentSent=%t;mac=%s;status=%s;expiresAt=%s",
-		eni.TaskARN, eni.AttachmentARN, eni.AttachmentType, eni.AttachStatusSent, eni.MACAddress, eni.Status.String(), eni.ExpiresAt.String())
+		"ENI Attachment: task=%s attachment=%s attachmentType=%s attachmentSent=%t mac=%s status=%s expiresAt=%s",
+		eni.TaskARN, eni.AttachmentARN, eni.AttachmentType, eni.AttachStatusSent, eni.MACAddress, eni.Status.String(), eni.ExpiresAt.Format(time.RFC3339))
 }
diff --git a/agent/engine/docker_task_engine.go b/agent/engine/docker_task_engine.go
@@ -321,7 +321,7 @@ func (engine *DockerTaskEngine) synchronizeState() {
 				return
 			}
 			if !eniAttachment.IsSent() {
-				seelog.Warnf("Timed out waiting for ENI ack; removing ENI attachment record with MAC address: %s", eniAttachment.MACAddress)
+				seelog.Warnf("Timed out waiting for ENI ack; removing ENI attachment record %s", eniAttachment.String())
 				engine.removeENIAttachmentData(eniAttachment.MACAddress)
 				engine.state.RemoveENIAttachment(eniAttachment.MACAddress)
 			}
@@ -330,7 +330,7 @@ func (engine *DockerTaskEngine) synchronizeState() {
 		if err != nil {
 			// The only case where we get an error from Initialize is that the attachment has expired. In that case, remove the expired
 			// attachment from state.
-			seelog.Warnf("ENI attachment with mac address %s has expired. Removing it from state.", eniAttachment.MACAddress)
+			seelog.Warnf("ENI attachment has expired. Removing it from state. %s", eniAttachment.String())
 			engine.removeENIAttachmentData(eniAttachment.MACAddress)
 			engine.state.RemoveENIAttachment(eniAttachment.MACAddress)
 		}

diff --git a/agent/engine/docker_task_engine_test.go b/agent/engine/docker_task_engine_test.go
@@ -1872,6 +1872,7 @@ func TestNewTaskTransitionOnRestart(t *testing.T) {
 	defer ctrl.Finish()
 
 	mockTime.EXPECT().Now().AnyTimes()
+	mockTime.EXPECT().After(gomock.Any()).AnyTimes()
 	client.EXPECT().Version(gomock.Any(), gomock.Any()).MaxTimes(1)
 	client.EXPECT().ContainerEvents(gomock.Any()).MaxTimes(1)