From 7fcbc3c46a2e0fdf55082216b8eca3f8f09eb4e0 Mon Sep 17 00:00:00 2001 From: Sebastiaan van Stijn Date: Wed, 7 May 2025 12:27:00 +0200 Subject: [PATCH] core/runtime/v2: cleanup shim-cleanup logs 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 --- core/runtime/v2/binary.go | 16 +++++++++++----- core/runtime/v2/shim.go | 2 +- 2 files changed, 12 insertions(+), 6 deletions(-) diff --git a/core/runtime/v2/binary.go b/core/runtime/v2/binary.go index 47780301e8..d04881cf85 100644 --- 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 index 0f42e984cb..e279fde2b5 100644 --- 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")