core/runtime/v2: cleanup shim-cleanup logs

thaJeztah · k8s-infra-cherrypick-robot · commit 7fcbc3c46a2e · 2025-05-10T04:01:57.000Z
I noticed that the "cleaning up after shim disconnected" was logged as a
warning, but I couldn't find a reason why it was considered a warning (
and didn't see an error attached to the log);

    INFO[2025-05-07T08:57:56.576773500Z] ignoring event                                container=589c33c88591a9936cb8fd64453e4b0c1357ae2f79d975c34645ff8f0aa10485 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
    INFO[2025-05-07T08:57:56.576938958Z] shim disconnected                             id=589c33c88591a9936cb8fd64453e4b0c1357ae2f79d975c34645ff8f0aa10485 namespace=moby
    WARN[2025-05-07T08:57:56.577356208Z] cleaning up after shim disconnected           id=589c33c88591a9936cb8fd64453e4b0c1357ae2f79d975c34645ff8f0aa10485 namespace=moby
    INFO[2025-05-07T08:57:56.577393417Z] cleaning up dead shim                         namespace=moby

I think this must've been set as a warning by acccident, so changing
this log to an "info" log as it seems part of the normal flow or operations.

While updating, also updating related logs, such as the "cleaning up dead shim"
log, to include the id, so that these logs can more easily be correlated.

Signed-off-by: Sebastiaan van Stijn &lt;github@gone.nl&gt;
diff --git a/core/runtime/v2/binary.go b/core/runtime/v2/binary.go
@@ -154,7 +154,7 @@ func (b *binary) Start(ctx context.Context, opts *types.Any, onClose func()) (_
 }
 
 func (b *binary) Delete(ctx context.Context) (*runtime.Exit, error) {
-	log.G(ctx).Info("cleaning up dead shim")
+	log.G(ctx).WithField("id", b.bundle.ID).Info("cleaning up dead shim")
 
 	// On Windows and FreeBSD, the current working directory of the shim should
 	// not be the bundle path during the delete operation. Instead, we invoke
@@ -195,12 +195,18 @@ func (b *binary) Delete(ctx context.Context) (*runtime.Exit, error) {
 	cmd.Stdout = out
 	cmd.Stderr = errb
 	if err := cmd.Run(); err != nil {
-		log.G(ctx).WithField("cmd", cmd.String()).WithError(err).Error("failed to delete")
+		log.G(ctx).WithFields(log.Fields{
+			"cmd":   cmd.String(),
+			"error": err,
+			"id":    b.bundle.ID,
+		}).Error("failed to delete dead shim")
 		return nil, fmt.Errorf("%s: %w", errb.String(), err)
 	}
-	s := errb.String()
-	if s != "" {
-		log.G(ctx).Warnf("cleanup warnings %s", s)
+	if s := errb.String(); s != "" {
+		log.G(ctx).WithFields(log.Fields{
+			"id":       b.bundle.ID,
+			"warnings": s,
+		}).Warn("warnings while cleaning up dead shim")
 	}
 	var response task.DeleteResponse
 	if err := proto.Unmarshal(out.Bytes(), &response); err != nil {
diff --git a/core/runtime/v2/shim.go b/core/runtime/v2/shim.go
@@ -138,7 +138,7 @@ func cleanupAfterDeadShim(ctx context.Context, id string, rt *runtime.NSMap[Shim
 	ctx, cancel := timeout.WithContext(ctx, cleanupTimeout)
 	defer cancel()
 
-	log.G(ctx).WithField("id", id).Warn("cleaning up after shim disconnected")
+	log.G(ctx).WithField("id", id).Info("cleaning up after shim disconnected")
 	response, err := binaryCall.Delete(ctx)
 	if err != nil {
 		log.G(ctx).WithError(err).WithField("id", id).Warn("failed to clean up after shim disconnected")
