From ad5204c1868ac8847414eb6deda2f1a3d4c90c99 Mon Sep 17 00:00:00 2001 From: Hamza El-Saawy Date: Tue, 17 Feb 2026 12:13:03 -0500 Subject: [PATCH 1/3] Minor code cleanup and doc fixes. Clarify docs. Fix spelling. Remove newline from comments. Don't serialize `OptionsWCOW.OutputHandlerCreator` to JSON. Consolidate redundant `internal/winapi/winapi.go` with `internal/winapi/doc.go`. Use `"internal/log".(*Hook)` to format logs and add span information in functional/gcs tests. Add testing `nil`-checks and logs to uVM/container/process testing operations. Signed-off-by: Hamza El-Saawy --- internal/hvsocket/hvsocket.go | 2 +- internal/log/hook.go | 2 ++ internal/uvm/create_wcow.go | 2 +- internal/uvm/start.go | 4 +-- internal/winapi/doc.go | 2 ++ internal/winapi/winapi.go | 3 -- test/functional/main_test.go | 1 + test/gcs/main_test.go | 2 ++ test/internal/cmd/cmd.go | 42 +++++++++++++++++++--------- test/internal/container/container.go | 9 ++++++ test/pkg/uvm/lcow.go | 7 +++++ test/pkg/uvm/uvm.go | 10 +++++-- test/pkg/uvm/wcow.go | 8 +++++- 13 files changed, 71 insertions(+), 23 deletions(-) delete mode 100644 internal/winapi/winapi.go diff --git a/internal/hvsocket/hvsocket.go b/internal/hvsocket/hvsocket.go index 595834f7c1..8bab750935 100644 --- a/internal/hvsocket/hvsocket.go +++ b/internal/hvsocket/hvsocket.go @@ -6,12 +6,12 @@ package hvsocket import ( "context" "fmt" - "github.com/Microsoft/hcsshim/internal/log" "unsafe" "github.com/Microsoft/go-winio/pkg/guid" "golang.org/x/sys/windows" + "github.com/Microsoft/hcsshim/internal/log" "github.com/Microsoft/hcsshim/internal/resources" ) diff --git a/internal/log/hook.go b/internal/log/hook.go index da81023b65..6ee833b7cd 100644 --- a/internal/log/hook.go +++ b/internal/log/hook.go @@ -41,6 +41,8 @@ type Hook struct { // AddSpanContext adds [logfields.TraceID] and [logfields.SpanID] fields to // the entry from the span context stored in [logrus.Entry.Context], if it exists. + // + // Default is true. AddSpanContext bool } diff --git a/internal/uvm/create_wcow.go b/internal/uvm/create_wcow.go index f922017b44..e1551cac5e 100644 --- a/internal/uvm/create_wcow.go +++ b/internal/uvm/create_wcow.go @@ -69,7 +69,7 @@ type OptionsWCOW struct { // AdditionalRegistryKeys are Registry keys and their values to additionally add to the uVM. AdditionalRegistryKeys []hcsschema.RegistryValue - OutputHandlerCreator OutputHandlerCreator // Creates an [OutputHandler] that controls how output received over HVSocket from the UVM is handled. Defaults to parsing output as ETW Log events + OutputHandlerCreator OutputHandlerCreator `json:"-"` // Creates an [OutputHandler] that controls how output received over HVSocket from the UVM is handled. Defaults to parsing output as ETW Log events LogSources string // ETW providers to be set for the logging service ForwardLogs bool // Whether to forward logs to the host or not } diff --git a/internal/uvm/start.go b/internal/uvm/start.go index 781bc3c417..d51185e294 100644 --- a/internal/uvm/start.go +++ b/internal/uvm/start.go @@ -172,7 +172,7 @@ func (uvm *UtilityVM) Start(ctx context.Context) (err error) { // save parent context, without timeout to use in terminate pCtx := ctx ctx, cancel := context.WithTimeout(pCtx, timeout.GCSConnectionTimeout) - log.G(ctx).Debugf("using gcs connection timeout: %s\n", timeout.GCSConnectionTimeout) + log.G(ctx).Debugf("using gcs connection timeout: %s", timeout.GCSConnectionTimeout) g, gctx := errgroup.WithContext(ctx) defer func() { @@ -215,7 +215,7 @@ func (uvm *UtilityVM) Start(ctx context.Context) (err error) { switch uvm.operatingSystem { case "windows": // Windows specific handling - // For windows, the Listener can recieve a connection later, so we + // For windows, the Listener can receive a connection later, so we // start the output handler in a goroutine with a non-timeout context. // This allows the output handler to run independently of the UVM Create's // lifecycle. The approach potentially allows to wait for reconnections too, diff --git a/internal/winapi/doc.go b/internal/winapi/doc.go index 9acc0bfc17..0bfaf47a33 100644 --- a/internal/winapi/doc.go +++ b/internal/winapi/doc.go @@ -1,3 +1,5 @@ // Package winapi contains various low-level bindings to Windows APIs. It can // be thought of as an extension to golang.org/x/sys/windows. package winapi + +//go:generate go tool github.com/Microsoft/go-winio/tools/mkwinsyscall -output zsyscall_windows.go ./*.go diff --git a/internal/winapi/winapi.go b/internal/winapi/winapi.go deleted file mode 100644 index 009e70ab19..0000000000 --- a/internal/winapi/winapi.go +++ /dev/null @@ -1,3 +0,0 @@ -package winapi - -//go:generate go tool github.com/Microsoft/go-winio/tools/mkwinsyscall -output zsyscall_windows.go ./*.go diff --git a/test/functional/main_test.go b/test/functional/main_test.go index 18bd6a72f4..4360487c06 100644 --- a/test/functional/main_test.go +++ b/test/functional/main_test.go @@ -164,6 +164,7 @@ func runTests(m *testing.M) error { return fmt.Errorf("tests must be run in an elevated context") } + logrus.AddHook(log.NewHook()) trace.ApplyConfig(trace.Config{DefaultSampler: oc.DefaultSampler}) trace.RegisterExporter(&oc.LogrusExporter{}) diff --git a/test/gcs/main_test.go b/test/gcs/main_test.go index ce399e0767..4832494781 100644 --- a/test/gcs/main_test.go +++ b/test/gcs/main_test.go @@ -21,6 +21,7 @@ import ( "github.com/Microsoft/hcsshim/internal/guest/runtime/runc" "github.com/Microsoft/hcsshim/internal/guest/transport" "github.com/Microsoft/hcsshim/internal/guestpath" + "github.com/Microsoft/hcsshim/internal/log" "github.com/Microsoft/hcsshim/internal/oc" "github.com/Microsoft/hcsshim/pkg/securitypolicy" @@ -109,6 +110,7 @@ func TestMain(m *testing.M) { func setup() (err error) { _ = os.MkdirAll(guestpath.LCOWRootPrefixInUVM, 0755) + logrus.AddHook(log.NewHook()) trace.ApplyConfig(trace.Config{DefaultSampler: oc.DefaultSampler}) trace.RegisterExporter(&oc.LogrusExporter{}) diff --git a/test/internal/cmd/cmd.go b/test/internal/cmd/cmd.go index d7bcc78a38..cdf7aea195 100644 --- a/test/internal/cmd/cmd.go +++ b/test/internal/cmd/cmd.go @@ -23,16 +23,17 @@ const CopyAfterExitTimeout = time.Second const ForcedKilledExitCode = 137 func desc(c *cmd.Cmd) string { - desc := "init command" - if c.Spec != nil { - if c.Spec.CommandLine != "" { - desc = c.Spec.CommandLine - } else { - desc = strings.Join(c.Spec.Args, " ") - } + switch { + case c == nil: + return "" + case c.Spec == nil: + return "init command" + case c.Spec.CommandLine != "": + return c.Spec.CommandLine + default: } - return desc + return strings.Join(c.Spec.Args, " ") } func Create(ctx context.Context, _ testing.TB, c cow.ProcessHost, p *specs.Process, io *BufferedIO) *cmd.Cmd { @@ -51,8 +52,12 @@ func Create(ctx context.Context, _ testing.TB, c cow.ProcessHost, p *specs.Proce func Start(_ context.Context, tb testing.TB, c *cmd.Cmd) { tb.Helper() + + d := desc(c) + tb.Logf("starting command: %q", d) + if err := c.Start(); err != nil { - tb.Fatalf("failed to start %q: %v", desc(c), err) + tb.Fatalf("failed to start %q: %v", d, err) } } @@ -64,14 +69,21 @@ func Run(ctx context.Context, tb testing.TB, c *cmd.Cmd) int { func Wait(_ context.Context, tb testing.TB, c *cmd.Cmd) int { tb.Helper() + + d := desc(c) + tb.Logf("waiting on process: %q", d) + // todo, wait on context.Done if err := c.Wait(); err != nil { ee := &cmd.ExitError{} if errors.As(err, &ee) { - return ee.ExitCode() + ec := ee.ExitCode() + tb.Logf("process exit code: %d", ec) + return ec } - tb.Fatalf("failed to wait on %q: %v", desc(c), err) + tb.Fatalf("failed to wait on %q: %v", d, err) } + return 0 } @@ -84,10 +96,14 @@ func WaitExitCode(ctx context.Context, tb testing.TB, c *cmd.Cmd, e int) { func Kill(ctx context.Context, tb testing.TB, c *cmd.Cmd) { tb.Helper() + + d := desc(c) + tb.Logf("kill process: %q", d) + ok, err := c.Process.Kill(ctx) if !ok { - tb.Fatalf("could not deliver kill to %q", desc(c)) + tb.Fatalf("could not deliver kill to %q", d) } else if err != nil { - tb.Fatalf("could not kill %q: %v", desc(c), err) + tb.Fatalf("could not kill %q: %v", d, err) } } diff --git a/test/internal/container/container.go b/test/internal/container/container.go index 0d3a9a0a5b..e1236feb68 100644 --- a/test/internal/container/container.go +++ b/test/internal/container/container.go @@ -31,6 +31,7 @@ func Create( name, owner string, ) (c cow.Container, r *resources.Resources, _ func()) { tb.Helper() + tb.Logf("creating container: %q", name) if spec.Windows == nil || spec.Windows.Network == nil || spec.Windows.LayerFolders == nil { tb.Fatalf("improperly configured windows spec for container %q: %#+v", name, spec.Windows) @@ -72,6 +73,8 @@ func Create( } f := func() { + tb.Logf("cleaning up container: %q", name) + if err := resources.ReleaseResources(ctx, r, vm, true); err != nil { tb.Errorf("failed to release container resources: %v", err) } @@ -99,6 +102,8 @@ func Start(ctx context.Context, tb testing.TB, c cow.Container, io *testcmd.Buff func StartWithSpec(ctx context.Context, tb testing.TB, c cow.Container, p *specs.Process, io *testcmd.BufferedIO) *cmd.Cmd { tb.Helper() + tb.Logf("starting container: %q", c.ID()) + if err := c.Start(ctx); err != nil { tb.Fatalf("could not start %q: %v", c.ID(), err) } @@ -111,6 +116,8 @@ func StartWithSpec(ctx context.Context, tb testing.TB, c cow.Container, p *specs func Wait(_ context.Context, tb testing.TB, c cow.Container) { tb.Helper() + tb.Logf("waiting on container: %q", c.ID()) + // todo: add wait on ctx.Done if err := c.Wait(); err != nil { tb.Fatalf("could not wait on container %q: %v", c.ID(), err) @@ -119,6 +126,8 @@ func Wait(_ context.Context, tb testing.TB, c cow.Container) { func Kill(ctx context.Context, tb testing.TB, c cow.Container) { tb.Helper() + tb.Logf("kill container: %q", c.ID()) + if err := c.Shutdown(ctx); err != nil { tb.Fatalf("could not terminate container %q: %v", c.ID(), err) } diff --git a/test/pkg/uvm/lcow.go b/test/pkg/uvm/lcow.go index 4e17122349..5a16ea06a6 100644 --- a/test/pkg/uvm/lcow.go +++ b/test/pkg/uvm/lcow.go @@ -77,6 +77,13 @@ func CreateAndStartLCOWFromOpts(ctx context.Context, tb testing.TB, opts *uvm.Op func CreateLCOW(ctx context.Context, tb testing.TB, opts *uvm.OptionsLCOW) (*uvm.UtilityVM, CleanupFn) { tb.Helper() + + if opts == nil { + tb.Fatalf("opts cannot be nil bet set with BootFiles") + } + + tb.Logf("create LCOW uVM: %q", opts.ID) + vm, err := uvm.CreateLCOW(ctx, opts) if err != nil { tb.Fatalf("could not create LCOW UVM: %v", err) diff --git a/test/pkg/uvm/uvm.go b/test/pkg/uvm/uvm.go index 84c6fbf030..45e35aa2a0 100644 --- a/test/pkg/uvm/uvm.go +++ b/test/pkg/uvm/uvm.go @@ -60,15 +60,17 @@ func CreateAndStart(ctx context.Context, tb testing.TB, opts any) *uvm.UtilityVM func Start(ctx context.Context, tb testing.TB, vm *uvm.UtilityVM) { tb.Helper() - err := vm.Start(ctx) + tb.Logf("start uVM: %q", vm.ID()) - if err != nil { + if err := vm.Start(ctx); err != nil { tb.Fatalf("could not start UVM: %v", err) } } func Wait(ctx context.Context, tb testing.TB, vm *uvm.UtilityVM) { tb.Helper() + tb.Logf("waiting on container: %q", vm.ID()) + if err := vm.WaitCtx(ctx); err != nil { tb.Fatalf("could not wait for uvm %q: %v", vm.ID(), err) } @@ -76,6 +78,8 @@ func Wait(ctx context.Context, tb testing.TB, vm *uvm.UtilityVM) { func Kill(ctx context.Context, tb testing.TB, vm *uvm.UtilityVM) { tb.Helper() + tb.Logf("kill uVM: %q", vm.ID()) + if err := vm.Terminate(ctx); err != nil { tb.Fatalf("could not kill uvm %q: %v", vm.ID(), err) } @@ -83,6 +87,8 @@ func Kill(ctx context.Context, tb testing.TB, vm *uvm.UtilityVM) { func Close(ctx context.Context, tb testing.TB, vm *uvm.UtilityVM) { tb.Helper() + tb.Logf("close uVM: %q", vm.ID()) + if err := vm.CloseCtx(ctx); err != nil { tb.Fatalf("could not close uvm %q: %v", vm.ID(), err) } diff --git a/test/pkg/uvm/wcow.go b/test/pkg/uvm/wcow.go index 2f4644cae8..2060bd13c8 100644 --- a/test/pkg/uvm/wcow.go +++ b/test/pkg/uvm/wcow.go @@ -37,7 +37,13 @@ func CreateWCOWUVM(ctx context.Context, tb testing.TB, id, image string) (*uvm.U func CreateWCOW(ctx context.Context, tb testing.TB, opts *uvm.OptionsWCOW) (*uvm.UtilityVM, CleanupFn) { tb.Helper() - if opts == nil || opts.BootFiles == nil { + if opts == nil { + tb.Fatalf("opts cannot be nil bet set with BootFiles") + } + + tb.Logf("create WCOW uVM: %q", opts.ID) + + if opts.BootFiles == nil { tb.Fatalf("opts must bet set with BootFiles") } From a9bc27b24aa875b1031fc3e28d6789efe3a1ff97 Mon Sep 17 00:00:00 2001 From: Hamza El-Saawy Date: Tue, 17 Feb 2026 12:31:16 -0500 Subject: [PATCH 2/3] Invalid Handle check; log field names Add `"internal/winapi".IsInvalidHandle` function to valid `Handle`s are neither `0` nor Invalid. Standardize system and process ID log/span field names. Use `"system-id"` for system ID rather than `"cid"`, which can be interpreted as "container ID". Add `(*Process).CloseCtx(context.Context)` and use that, along with `(*System).CloseCtx` where appropriate. Suppress lint issues (skipped error checks for `Close()` calls are ignored automatically, but not for `CloseCtx(ctx)`). Update CI lint version. Signed-off-by: Hamza El-Saawy --- .github/workflows/ci.yml | 2 +- internal/hcs/process.go | 80 +++++++++++++++++++++++------------- internal/hcs/system.go | 56 ++++++++++++++----------- internal/hcs/utils.go | 10 +++-- internal/logfields/fields.go | 3 ++ internal/winapi/utils.go | 5 +++ test/pkg/uvm/lcow.go | 1 + test/pkg/uvm/wcow.go | 2 + 8 files changed, 101 insertions(+), 58 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index c6a599ad20..11da447395 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -36,7 +36,7 @@ jobs: - name: Run golangci-lint uses: golangci/golangci-lint-action@v9 with: - version: v2.1 + version: v2.4 args: >- --verbose --max-issues-per-linter=0 diff --git a/internal/hcs/process.go b/internal/hcs/process.go index fef2bf546c..17ef1a208a 100644 --- a/internal/hcs/process.go +++ b/internal/hcs/process.go @@ -12,14 +12,17 @@ import ( "syscall" "time" + "github.com/sirupsen/logrus" "go.opencensus.io/trace" "github.com/Microsoft/hcsshim/internal/cow" hcsschema "github.com/Microsoft/hcsshim/internal/hcs/schema2" "github.com/Microsoft/hcsshim/internal/log" + "github.com/Microsoft/hcsshim/internal/logfields" "github.com/Microsoft/hcsshim/internal/oc" "github.com/Microsoft/hcsshim/internal/protocol/guestrequest" "github.com/Microsoft/hcsshim/internal/vmcompute" + "github.com/Microsoft/hcsshim/internal/winapi" ) type Process struct { @@ -97,7 +100,7 @@ func (process *Process) Signal(ctx context.Context, options interface{}) (bool, operation := "hcs::Process::Signal" - if process.handle == 0 { + if winapi.IsInvalidHandle(process.handle) { return false, makeProcessError(process, operation, ErrAlreadyClosed, nil) } @@ -116,13 +119,21 @@ func (process *Process) Signal(ctx context.Context, options interface{}) (bool, } // Kill signals the process to terminate but does not wait for it to finish terminating. -func (process *Process) Kill(ctx context.Context) (bool, error) { +func (process *Process) Kill(ctx context.Context) (_ bool, err error) { + operation := "hcs::Process::Kill" + ctx, span := oc.StartSpan(ctx, operation) + defer span.End() + defer func() { oc.SetSpanStatus(span, err) }() + span.AddAttributes( + trace.StringAttribute(logfields.SystemID, process.SystemID()), + trace.Int64Attribute(logfields.ProcessID, int64(process.processID))) + + ctxNoCancel := context.WithoutCancel(ctx) + process.handleLock.RLock() defer process.handleLock.RUnlock() - operation := "hcs::Process::Kill" - - if process.handle == 0 { + if winapi.IsInvalidHandle(process.handle) { return false, makeProcessError(process, operation, ErrAlreadyClosed, nil) } @@ -139,6 +150,9 @@ func (process *Process) Kill(ctx context.Context) (bool, error) { return true, nil } + // NOTE: this re-registers callbacks for the same underlying compute system and process, + // but with a different handle, which is ... excessive. + // HCS serializes the signals sent to a target pid per compute system handle. // To avoid SIGKILL being serialized behind other signals, we open a new compute // system handle to deliver the kill signal. @@ -154,10 +168,10 @@ func (process *Process) Kill(ctx context.Context) (bool, error) { log.G(ctx).WithField("err", err).Error("Terminate() call failed") return false, err } - process.system.Close() + process.system.CloseCtx(ctxNoCancel) //nolint:errcheck return true, nil } - defer hcsSystem.Close() + defer hcsSystem.CloseCtx(ctxNoCancel) //nolint:errcheck newProcessHandle, err := hcsSystem.OpenProcess(ctx, process.Pid()) if err != nil { @@ -169,7 +183,7 @@ func (process *Process) Kill(ctx context.Context) (bool, error) { return false, err } } - defer newProcessHandle.Close() + defer newProcessHandle.CloseCtx(ctxNoCancel) //nolint:errcheck resultJSON, err := vmcompute.HcsTerminateProcess(ctx, newProcessHandle.handle) if err != nil { @@ -214,8 +228,8 @@ func (process *Process) waitBackground() { ctx, span := oc.StartSpan(context.Background(), operation) defer span.End() span.AddAttributes( - trace.StringAttribute("cid", process.SystemID()), - trace.Int64Attribute("pid", int64(process.processID))) + trace.StringAttribute(logfields.SystemID, process.SystemID()), + trace.Int64Attribute(logfields.ProcessID, int64(process.processID))) var ( err error @@ -287,7 +301,7 @@ func (process *Process) ResizeConsole(ctx context.Context, width, height uint16) operation := "hcs::Process::ResizeConsole" - if process.handle == 0 { + if winapi.IsInvalidHandle(process.handle) { return makeProcessError(process, operation, ErrAlreadyClosed, nil) } modifyRequest := hcsschema.ProcessModifyRequest{ @@ -333,13 +347,13 @@ func (process *Process) StdioLegacy() (_ io.WriteCloser, _ io.ReadCloser, _ io.R defer span.End() defer func() { oc.SetSpanStatus(span, err) }() span.AddAttributes( - trace.StringAttribute("cid", process.SystemID()), - trace.Int64Attribute("pid", int64(process.processID))) + trace.StringAttribute(logfields.SystemID, process.SystemID()), + trace.Int64Attribute(logfields.ProcessID, int64(process.processID))) process.handleLock.RLock() defer process.handleLock.RUnlock() - if process.handle == 0 { + if winapi.IsInvalidHandle(process.handle) { return nil, nil, nil, makeProcessError(process, operation, ErrAlreadyClosed, nil) } @@ -382,13 +396,13 @@ func (process *Process) CloseStdin(ctx context.Context) (err error) { defer span.End() defer func() { oc.SetSpanStatus(span, err) }() span.AddAttributes( - trace.StringAttribute("cid", process.SystemID()), - trace.Int64Attribute("pid", int64(process.processID))) + trace.StringAttribute(logfields.SystemID, process.SystemID()), + trace.Int64Attribute(logfields.ProcessID, int64(process.processID))) process.handleLock.RLock() defer process.handleLock.RUnlock() - if process.handle == 0 { + if winapi.IsInvalidHandle(process.handle) { return makeProcessError(process, operation, ErrAlreadyClosed, nil) } @@ -428,13 +442,13 @@ func (process *Process) CloseStdout(ctx context.Context) (err error) { defer span.End() defer func() { oc.SetSpanStatus(span, err) }() span.AddAttributes( - trace.StringAttribute("cid", process.SystemID()), - trace.Int64Attribute("pid", int64(process.processID))) + trace.StringAttribute(logfields.SystemID, process.SystemID()), + trace.Int64Attribute(logfields.ProcessID, int64(process.processID))) process.handleLock.Lock() defer process.handleLock.Unlock() - if process.handle == 0 { + if winapi.IsInvalidHandle(process.handle) { return nil } @@ -452,13 +466,13 @@ func (process *Process) CloseStderr(ctx context.Context) (err error) { defer span.End() defer func() { oc.SetSpanStatus(span, err) }() span.AddAttributes( - trace.StringAttribute("cid", process.SystemID()), - trace.Int64Attribute("pid", int64(process.processID))) + trace.StringAttribute(logfields.SystemID, process.SystemID()), + trace.Int64Attribute(logfields.ProcessID, int64(process.processID))) process.handleLock.Lock() defer process.handleLock.Unlock() - if process.handle == 0 { + if winapi.IsInvalidHandle(process.handle) { return nil } @@ -473,20 +487,28 @@ func (process *Process) CloseStderr(ctx context.Context) (err error) { // Close cleans up any state associated with the process but does not kill // or wait on it. -func (process *Process) Close() (err error) { +func (process *Process) Close() error { + return process.CloseCtx(context.Background()) +} + +// CloseCtx is similar to [System.Close], but accepts a context. +// +// The context is used for all operations, including waits, so timeouts/cancellations may prevent +// proper system cleanup. +func (process *Process) CloseCtx(ctx context.Context) (err error) { operation := "hcs::Process::Close" - ctx, span := oc.StartSpan(context.Background(), operation) + ctx, span := oc.StartSpan(ctx, operation) defer span.End() defer func() { oc.SetSpanStatus(span, err) }() span.AddAttributes( - trace.StringAttribute("cid", process.SystemID()), - trace.Int64Attribute("pid", int64(process.processID))) + trace.StringAttribute(logfields.SystemID, process.SystemID()), + trace.Int64Attribute(logfields.ProcessID, int64(process.processID))) process.handleLock.Lock() defer process.handleLock.Unlock() // Don't double free this - if process.handle == 0 { + if winapi.IsInvalidHandle(process.handle) { return nil } @@ -559,7 +581,7 @@ func (process *Process) unregisterCallback(ctx context.Context) error { handle := callbackContext.handle - if handle == 0 { + if winapi.IsInvalidHandle(handle) { return nil } diff --git a/internal/hcs/system.go b/internal/hcs/system.go index b1597466f6..44369fa394 100644 --- a/internal/hcs/system.go +++ b/internal/hcs/system.go @@ -12,6 +12,9 @@ import ( "syscall" "time" + "github.com/sirupsen/logrus" + "go.opencensus.io/trace" + "github.com/Microsoft/hcsshim/internal/cow" "github.com/Microsoft/hcsshim/internal/hcs/schema1" hcsschema "github.com/Microsoft/hcsshim/internal/hcs/schema2" @@ -21,8 +24,7 @@ import ( "github.com/Microsoft/hcsshim/internal/oc" "github.com/Microsoft/hcsshim/internal/timeout" "github.com/Microsoft/hcsshim/internal/vmcompute" - "github.com/sirupsen/logrus" - "go.opencensus.io/trace" + "github.com/Microsoft/hcsshim/internal/winapi" ) type System struct { @@ -63,7 +65,7 @@ func CreateComputeSystem(ctx context.Context, id string, hcsDocumentInterface in ctx, span := oc.StartSpan(ctx, operation) defer span.End() defer func() { oc.SetSpanStatus(span, err) }() - span.AddAttributes(trace.StringAttribute("cid", id)) + span.AddAttributes(trace.StringAttribute(logfields.SystemID, id)) computeSystem := newSystem(id) @@ -83,7 +85,7 @@ func CreateComputeSystem(ctx context.Context, id string, hcsDocumentInterface in if createError == nil || IsPending(createError) { defer func() { if err != nil { - computeSystem.Close() + computeSystem.CloseCtx(context.WithoutCancel(ctx)) //nolint:errcheck } }() if err = computeSystem.registerCallback(ctx); err != nil { @@ -115,6 +117,8 @@ func CreateComputeSystem(ctx context.Context, id string, hcsDocumentInterface in func OpenComputeSystem(ctx context.Context, id string) (*System, error) { operation := "hcs::OpenComputeSystem" + log.G(ctx).WithField(logfields.SystemID, id).Trace(operation) + computeSystem := newSystem(id) handle, resultJSON, err := vmcompute.HcsOpenComputeSystem(ctx, id) events := processHcsResult(ctx, resultJSON) @@ -124,7 +128,7 @@ func OpenComputeSystem(ctx context.Context, id string) (*System, error) { computeSystem.handle = handle defer func() { if err != nil { - computeSystem.Close() + computeSystem.CloseCtx(context.WithoutCancel(ctx)) //nolint:errcheck } }() if err = computeSystem.registerCallback(ctx); err != nil { @@ -199,14 +203,14 @@ func (computeSystem *System) Start(ctx context.Context) (err error) { ctx, span := oc.StartSpan(ctx, operation) defer span.End() defer func() { oc.SetSpanStatus(span, err) }() - span.AddAttributes(trace.StringAttribute("cid", computeSystem.id)) + span.AddAttributes(trace.StringAttribute(logfields.SystemID, computeSystem.id)) computeSystem.handleLock.RLock() defer computeSystem.handleLock.RUnlock() // prevent starting an exited system because waitblock we do not recreate waitBlock // or rerun waitBackground, so we have no way to be notified of it closing again - if computeSystem.handle == 0 { + if winapi.IsInvalidHandle(computeSystem.handle) { return makeSystemError(computeSystem, operation, ErrAlreadyClosed, nil) } @@ -232,7 +236,7 @@ func (computeSystem *System) Shutdown(ctx context.Context) error { operation := "hcs::System::Shutdown" - if computeSystem.handle == 0 || computeSystem.stopped() { + if winapi.IsInvalidHandle(computeSystem.handle) || computeSystem.stopped() { return nil } @@ -254,7 +258,7 @@ func (computeSystem *System) Terminate(ctx context.Context) error { operation := "hcs::System::Terminate" - if computeSystem.handle == 0 || computeSystem.stopped() { + if winapi.IsInvalidHandle(computeSystem.handle) || computeSystem.stopped() { return nil } @@ -278,7 +282,7 @@ func (computeSystem *System) waitBackground() { operation := "hcs::System::waitBackground" ctx, span := oc.StartSpan(context.Background(), operation) defer span.End() - span.AddAttributes(trace.StringAttribute("cid", computeSystem.id)) + span.AddAttributes(trace.StringAttribute(logfields.SystemID, computeSystem.id)) err := waitForNotification(ctx, computeSystem.callbackNumber, hcsNotificationSystemExited, nil) if err == nil { @@ -351,7 +355,7 @@ func (computeSystem *System) Properties(ctx context.Context, types ...schema1.Pr operation := "hcs::System::Properties" - if computeSystem.handle == 0 { + if winapi.IsInvalidHandle(computeSystem.handle) { return nil, makeSystemError(computeSystem, operation, ErrAlreadyClosed, nil) } @@ -489,10 +493,12 @@ func (computeSystem *System) statisticsInProc(job *jobobject.JobObject) (*hcssch } // hcsPropertiesV2Query is a helper to make a HcsGetComputeSystemProperties call using the V2 schema property types. +// +// Requires holding [System.handleLock]. func (computeSystem *System) hcsPropertiesV2Query(ctx context.Context, types []hcsschema.PropertyType) (*hcsschema.Properties, error) { operation := "hcs::System::PropertiesV2" - if computeSystem.handle == 0 { + if winapi.IsInvalidHandle(computeSystem.handle) { return nil, makeSystemError(computeSystem, operation, ErrAlreadyClosed, nil) } @@ -581,12 +587,12 @@ func (computeSystem *System) Pause(ctx context.Context) (err error) { ctx, span := oc.StartSpan(ctx, operation) defer span.End() defer func() { oc.SetSpanStatus(span, err) }() - span.AddAttributes(trace.StringAttribute("cid", computeSystem.id)) + span.AddAttributes(trace.StringAttribute(logfields.SystemID, computeSystem.id)) computeSystem.handleLock.RLock() defer computeSystem.handleLock.RUnlock() - if computeSystem.handle == 0 { + if winapi.IsInvalidHandle(computeSystem.handle) { return makeSystemError(computeSystem, operation, ErrAlreadyClosed, nil) } @@ -609,12 +615,12 @@ func (computeSystem *System) Resume(ctx context.Context) (err error) { ctx, span := oc.StartSpan(ctx, operation) defer span.End() defer func() { oc.SetSpanStatus(span, err) }() - span.AddAttributes(trace.StringAttribute("cid", computeSystem.id)) + span.AddAttributes(trace.StringAttribute(logfields.SystemID, computeSystem.id)) computeSystem.handleLock.RLock() defer computeSystem.handleLock.RUnlock() - if computeSystem.handle == 0 { + if winapi.IsInvalidHandle(computeSystem.handle) { return makeSystemError(computeSystem, operation, ErrAlreadyClosed, nil) } @@ -637,7 +643,7 @@ func (computeSystem *System) Save(ctx context.Context, options interface{}) (err ctx, span := oc.StartSpan(ctx, operation) defer span.End() defer func() { oc.SetSpanStatus(span, err) }() - span.AddAttributes(trace.StringAttribute("cid", computeSystem.id)) + span.AddAttributes(trace.StringAttribute(logfields.SystemID, computeSystem.id)) saveOptions, err := json.Marshal(options) if err != nil { @@ -647,7 +653,7 @@ func (computeSystem *System) Save(ctx context.Context, options interface{}) (err computeSystem.handleLock.RLock() defer computeSystem.handleLock.RUnlock() - if computeSystem.handle == 0 { + if winapi.IsInvalidHandle(computeSystem.handle) { return makeSystemError(computeSystem, operation, ErrAlreadyClosed, nil) } @@ -665,7 +671,7 @@ func (computeSystem *System) createProcess(ctx context.Context, operation string computeSystem.handleLock.RLock() defer computeSystem.handleLock.RUnlock() - if computeSystem.handle == 0 { + if winapi.IsInvalidHandle(computeSystem.handle) { return nil, nil, makeSystemError(computeSystem, operation, ErrAlreadyClosed, nil) } @@ -686,7 +692,7 @@ func (computeSystem *System) createProcess(ctx context.Context, operation string return nil, nil, makeSystemError(computeSystem, operation, err, events) } - log.G(ctx).WithField("pid", processInfo.ProcessId).Debug("created process pid") + log.G(ctx).WithField(logfields.ProcessID, processInfo.ProcessId).Debug("created process pid") return newProcess(processHandle, int(processInfo.ProcessId), computeSystem), &processInfo, nil } @@ -727,7 +733,7 @@ func (computeSystem *System) OpenProcess(ctx context.Context, pid int) (*Process operation := "hcs::System::OpenProcess" - if computeSystem.handle == 0 { + if winapi.IsInvalidHandle(computeSystem.handle) { return nil, makeSystemError(computeSystem, operation, ErrAlreadyClosed, nil) } @@ -760,13 +766,13 @@ func (computeSystem *System) CloseCtx(ctx context.Context) (err error) { ctx, span := oc.StartSpan(ctx, operation) defer span.End() defer func() { oc.SetSpanStatus(span, err) }() - span.AddAttributes(trace.StringAttribute("cid", computeSystem.id)) + span.AddAttributes(trace.StringAttribute(logfields.SystemID, computeSystem.id)) computeSystem.handleLock.Lock() defer computeSystem.handleLock.Unlock() // Don't double free this - if computeSystem.handle == 0 { + if winapi.IsInvalidHandle(computeSystem.handle) { return nil } @@ -824,7 +830,7 @@ func (computeSystem *System) unregisterCallback(ctx context.Context) error { handle := callbackContext.handle - if handle == 0 { + if winapi.IsInvalidHandle(handle) { return nil } @@ -853,7 +859,7 @@ func (computeSystem *System) Modify(ctx context.Context, config interface{}) err operation := "hcs::System::Modify" - if computeSystem.handle == 0 { + if winapi.IsInvalidHandle(computeSystem.handle) { return makeSystemError(computeSystem, operation, ErrAlreadyClosed, nil) } diff --git a/internal/hcs/utils.go b/internal/hcs/utils.go index 76eb2be7cf..a44030d49f 100644 --- a/internal/hcs/utils.go +++ b/internal/hcs/utils.go @@ -5,13 +5,17 @@ package hcs import ( "context" "io" + "sync/atomic" "syscall" + "github.com/pkg/errors" + "golang.org/x/sys/windows" + "github.com/Microsoft/go-winio" diskutil "github.com/Microsoft/go-winio/vhd" + "github.com/Microsoft/hcsshim/computestorage" - "github.com/pkg/errors" - "golang.org/x/sys/windows" + "github.com/Microsoft/hcsshim/internal/winapi" ) // makeOpenFiles calls winio.NewOpenFile for each handle in a slice but closes all the handles @@ -19,7 +23,7 @@ import ( func makeOpenFiles(hs []syscall.Handle) (_ []io.ReadWriteCloser, err error) { fs := make([]io.ReadWriteCloser, len(hs)) for i, h := range hs { - if h != syscall.Handle(0) { + if !winapi.IsInvalidHandle(h) { if err == nil { fs[i], err = winio.NewOpenFile(windows.Handle(h)) } diff --git a/internal/logfields/fields.go b/internal/logfields/fields.go index cceb3e2d18..6cf9174045 100644 --- a/internal/logfields/fields.go +++ b/internal/logfields/fields.go @@ -14,6 +14,9 @@ const ( ProcessID = "pid" TaskID = "tid" UVMID = "uvm-id" + SystemID = "system-id" + + CallbackNumber = "callback-number" // networking and IO diff --git a/internal/winapi/utils.go b/internal/winapi/utils.go index de16750d76..8372560900 100644 --- a/internal/winapi/utils.go +++ b/internal/winapi/utils.go @@ -10,6 +10,11 @@ import ( "golang.org/x/sys/windows" ) +// IsInvalidHandle returns true if the Handle is zero or [windows.InvalidHandle]. +func IsInvalidHandle[H ~uintptr](h H) bool { + return h == 0 || uintptr(h) == uintptr(windows.InvalidHandle) +} + // Uint16BufferToSlice wraps a uint16 pointer-and-length into a slice // for easier interop with Go APIs func Uint16BufferToSlice(buffer *uint16, bufferLength int) (result []uint16) { diff --git a/test/pkg/uvm/lcow.go b/test/pkg/uvm/lcow.go index 5a16ea06a6..19d1537315 100644 --- a/test/pkg/uvm/lcow.go +++ b/test/pkg/uvm/lcow.go @@ -75,6 +75,7 @@ func CreateAndStartLCOWFromOpts(ctx context.Context, tb testing.TB, opts *uvm.Op return vm } +//nolint:staticcheck // SA5011: staticcheck thinks `opts` may be nil, even though we fail if it is func CreateLCOW(ctx context.Context, tb testing.TB, opts *uvm.OptionsLCOW) (*uvm.UtilityVM, CleanupFn) { tb.Helper() diff --git a/test/pkg/uvm/wcow.go b/test/pkg/uvm/wcow.go index 2060bd13c8..5caa809587 100644 --- a/test/pkg/uvm/wcow.go +++ b/test/pkg/uvm/wcow.go @@ -34,6 +34,8 @@ func CreateWCOWUVM(ctx context.Context, tb testing.TB, id, image string) (*uvm.U } // CreateWCOW creates a WCOW utility VM with the passed opts. +// +//nolint:staticcheck // SA5011: staticcheck thinks `opts` may be nil, even though we fail if it is func CreateWCOW(ctx context.Context, tb testing.TB, opts *uvm.OptionsWCOW) (*uvm.UtilityVM, CleanupFn) { tb.Helper() From 89d235746f2720a0a2c28888c34ea41c233069df Mon Sep 17 00:00:00 2001 From: Hamza El-Saawy Date: Tue, 17 Feb 2026 15:33:28 -0500 Subject: [PATCH 3/3] Use dedicated callback number type and atomic counter Add an explicit `callbackNumber` type and use an `atomic.Uintptr` to track callback numbers instead of the RWMutex `callbackMapLock`. Add comment clarifying use of `callbackNumber` as callback context. Add logs to `notificationWatcher` and `(*Process|*System)[un]registryCallback`. Signed-off-by: Hamza El-Saawy --- internal/hcs/callback.go | 65 ++++++++++++++++++++++++++++++-------- internal/hcs/process.go | 32 +++++++++++++------ internal/hcs/system.go | 30 ++++++++++++------ internal/hcs/utils.go | 1 - internal/hcs/waithelper.go | 13 ++++---- 5 files changed, 102 insertions(+), 39 deletions(-) diff --git a/internal/hcs/callback.go b/internal/hcs/callback.go index 7b27173c3a..b75f0d6a6f 100644 --- a/internal/hcs/callback.go +++ b/internal/hcs/callback.go @@ -3,20 +3,24 @@ package hcs import ( + "context" "fmt" "sync" + "sync/atomic" "syscall" + "github.com/sirupsen/logrus" + "github.com/Microsoft/hcsshim/internal/interop" + "github.com/Microsoft/hcsshim/internal/log" "github.com/Microsoft/hcsshim/internal/logfields" "github.com/Microsoft/hcsshim/internal/vmcompute" - "github.com/sirupsen/logrus" ) var ( - nextCallback uintptr - callbackMap = map[uintptr]*notificationWatcherContext{} + // used to lock [callbackMap]. callbackMapLock = sync.RWMutex{} + callbackMap = map[callbackNumber]*notificationWatcherContext{} notificationWatcherCallback = syscall.NewCallback(notificationWatcher) @@ -87,6 +91,31 @@ func (hn hcsNotification) String() string { } } +// HCS callbacks take the form: +// +// typedef void (CALLBACK *HCS_NOTIFICATION_CALLBACK)( +// _In_ DWORD notificationType, +// _In_opt_ void* context, +// _In_ HRESULT notificationStatus, +// _In_opt_ PCWSTR notificationData +// ); +// +// where the context is a pointer to the data that is associated with a particular notification. +// +// However, since Golang can freely move structs, pointer values are not stable. +// Therefore, interpret the pointer as the unique ID of a [notificationWatcherContext] +// stored in [callbackMap]. +// +// Note: Pointer stability via converting to [unsafe.Pointer] for syscalls is only guaranteed +// until the syscall returns, and the same pointer value is therefore invalid across different +// syscall invocations. +// See point (4) of the [unsafe.Pointer] documentation. +type callbackNumber uintptr + +var callbackCounter atomic.Uintptr + +func nextCallback() callbackNumber { return callbackNumber(callbackCounter.Add(1)) } + type notificationChannel chan error type notificationWatcherContext struct { @@ -132,30 +161,38 @@ func closeChannels(channels notificationChannels) { } } -func notificationWatcher(notificationType hcsNotification, callbackNumber uintptr, notificationStatus uintptr, notificationData *uint16) uintptr { +func notificationWatcher( + notificationType hcsNotification, + callbackNum callbackNumber, + notificationStatus uintptr, + notificationData *uint16, +) uintptr { + entry := log.G(context.Background()).WithFields(logrus.Fields{ + logfields.CallbackNumber: callbackNum, + "notification-type": notificationType.String(), + }) + var result error if int32(notificationStatus) < 0 { result = interop.Win32FromHresult(notificationStatus) } callbackMapLock.RLock() - context := callbackMap[callbackNumber] + callbackCtx := callbackMap[callbackNum] callbackMapLock.RUnlock() - if context == nil { + if callbackCtx == nil { + entry.Warn("received HCS notification for unknown callback number") return 0 } - log := logrus.WithFields(logrus.Fields{ - "notification-type": notificationType.String(), - "system-id": context.systemID, - }) - if context.processID != 0 { - log.Data[logfields.ProcessID] = context.processID + entry.Data[logfields.SystemID] = callbackCtx.systemID + if callbackCtx.processID != 0 { + entry.Data[logfields.ProcessID] = callbackCtx.processID } - log.Debug("HCS notification") + entry.Debug("received HCS notification") - if channel, ok := context.channels[notificationType]; ok { + if channel, ok := callbackCtx.channels[notificationType]; ok { channel <- result } diff --git a/internal/hcs/process.go b/internal/hcs/process.go index 17ef1a208a..f5993916f3 100644 --- a/internal/hcs/process.go +++ b/internal/hcs/process.go @@ -35,7 +35,7 @@ type Process struct { stdin io.WriteCloser stdout io.ReadCloser stderr io.ReadCloser - callbackNumber uintptr + callbackNumber callbackNumber killSignalDelivered bool closedWaitOnce sync.Once @@ -545,7 +545,16 @@ func (process *Process) CloseCtx(ctx context.Context) (err error) { return nil } +// Requires holding [Process.handleLock]. func (process *Process) registerCallback(ctx context.Context) error { + callbackNum := nextCallback() + + log.G(ctx).WithFields(logrus.Fields{ + logfields.SystemID: process.SystemID(), + logfields.ProcessID: process.processID, + logfields.CallbackNumber: callbackNum, + }).Trace("register process callback") + callbackContext := ¬ificationWatcherContext{ channels: newProcessChannels(), systemID: process.SystemID(), @@ -553,26 +562,31 @@ func (process *Process) registerCallback(ctx context.Context) error { } callbackMapLock.Lock() - callbackNumber := nextCallback - nextCallback++ - callbackMap[callbackNumber] = callbackContext + callbackMap[callbackNum] = callbackContext callbackMapLock.Unlock() - callbackHandle, err := vmcompute.HcsRegisterProcessCallback(ctx, process.handle, notificationWatcherCallback, callbackNumber) + callbackHandle, err := vmcompute.HcsRegisterProcessCallback(ctx, process.handle, notificationWatcherCallback, uintptr(callbackNum)) if err != nil { return err } callbackContext.handle = callbackHandle - process.callbackNumber = callbackNumber + process.callbackNumber = callbackNum return nil } +// Requires holding [Process.handleLock]. func (process *Process) unregisterCallback(ctx context.Context) error { - callbackNumber := process.callbackNumber + callbackNum := process.callbackNumber + + log.G(ctx).WithFields(logrus.Fields{ + logfields.SystemID: process.SystemID(), + logfields.ProcessID: process.processID, + logfields.CallbackNumber: callbackNum, + }).Trace("unregister process callback") callbackMapLock.RLock() - callbackContext := callbackMap[callbackNumber] + callbackContext := callbackMap[callbackNum] callbackMapLock.RUnlock() if callbackContext == nil { @@ -595,7 +609,7 @@ func (process *Process) unregisterCallback(ctx context.Context) error { closeChannels(callbackContext.channels) callbackMapLock.Lock() - delete(callbackMap, callbackNumber) + delete(callbackMap, callbackNum) callbackMapLock.Unlock() handle = 0 //nolint:ineffassign diff --git a/internal/hcs/system.go b/internal/hcs/system.go index 44369fa394..9c69512b6e 100644 --- a/internal/hcs/system.go +++ b/internal/hcs/system.go @@ -31,7 +31,7 @@ type System struct { handleLock sync.RWMutex handle vmcompute.HcsSystem id string - callbackNumber uintptr + callbackNumber callbackNumber closedWaitOnce sync.Once waitBlock chan struct{} @@ -794,34 +794,46 @@ func (computeSystem *System) CloseCtx(ctx context.Context) (err error) { return nil } +// Requires holding [System.handleLock]. func (computeSystem *System) registerCallback(ctx context.Context) error { + callbackNum := nextCallback() + + log.G(ctx).WithFields(logrus.Fields{ + logfields.SystemID: computeSystem.id, + logfields.CallbackNumber: callbackNum, + }).Trace("register computer system callback") + callbackContext := ¬ificationWatcherContext{ channels: newSystemChannels(), systemID: computeSystem.id, } callbackMapLock.Lock() - callbackNumber := nextCallback - nextCallback++ - callbackMap[callbackNumber] = callbackContext + callbackMap[callbackNum] = callbackContext callbackMapLock.Unlock() callbackHandle, err := vmcompute.HcsRegisterComputeSystemCallback(ctx, computeSystem.handle, - notificationWatcherCallback, callbackNumber) + notificationWatcherCallback, uintptr(callbackNum)) if err != nil { return err } callbackContext.handle = callbackHandle - computeSystem.callbackNumber = callbackNumber + computeSystem.callbackNumber = callbackNum return nil } +// Requires holding [System.handleLock]. func (computeSystem *System) unregisterCallback(ctx context.Context) error { - callbackNumber := computeSystem.callbackNumber + callbackNum := computeSystem.callbackNumber + + log.G(ctx).WithFields(logrus.Fields{ + logfields.SystemID: computeSystem.id, + logfields.CallbackNumber: callbackNum, + }).Trace("unregister computer system callback") callbackMapLock.RLock() - callbackContext := callbackMap[callbackNumber] + callbackContext := callbackMap[callbackNum] callbackMapLock.RUnlock() if callbackContext == nil { @@ -844,7 +856,7 @@ func (computeSystem *System) unregisterCallback(ctx context.Context) error { closeChannels(callbackContext.channels) callbackMapLock.Lock() - delete(callbackMap, callbackNumber) + delete(callbackMap, callbackNum) callbackMapLock.Unlock() handle = 0 //nolint:ineffassign diff --git a/internal/hcs/utils.go b/internal/hcs/utils.go index a44030d49f..9261274cb7 100644 --- a/internal/hcs/utils.go +++ b/internal/hcs/utils.go @@ -5,7 +5,6 @@ package hcs import ( "context" "io" - "sync/atomic" "syscall" "github.com/pkg/errors" diff --git a/internal/hcs/waithelper.go b/internal/hcs/waithelper.go index 3a51ed1955..b26e522abf 100644 --- a/internal/hcs/waithelper.go +++ b/internal/hcs/waithelper.go @@ -7,19 +7,20 @@ import ( "time" "github.com/Microsoft/hcsshim/internal/log" + "github.com/Microsoft/hcsshim/internal/logfields" ) func processAsyncHcsResult( ctx context.Context, err error, resultJSON string, - callbackNumber uintptr, + callbackNum callbackNumber, expectedNotification hcsNotification, timeout *time.Duration, ) ([]ErrorEvent, error) { events := processHcsResult(ctx, resultJSON) if IsPending(err) { - return nil, waitForNotification(ctx, callbackNumber, expectedNotification, timeout) + return nil, waitForNotification(ctx, callbackNum, expectedNotification, timeout) } return events, err @@ -27,17 +28,17 @@ func processAsyncHcsResult( func waitForNotification( ctx context.Context, - callbackNumber uintptr, + callbackNum callbackNumber, expectedNotification hcsNotification, timeout *time.Duration, ) error { callbackMapLock.RLock() - if _, ok := callbackMap[callbackNumber]; !ok { + if _, ok := callbackMap[callbackNum]; !ok { callbackMapLock.RUnlock() - log.G(ctx).WithField("callbackNumber", callbackNumber).Error("failed to waitForNotification: callbackNumber does not exist in callbackMap") + log.G(ctx).WithField(logfields.CallbackNumber, callbackNum).Error("failed to waitForNotification: callback number does not exist in callbackMap") return ErrHandleClose } - channels := callbackMap[callbackNumber].channels + channels := callbackMap[callbackNum].channels callbackMapLock.RUnlock() expectedChannel := channels[expectedNotification]