diff --git a/cmd/containerd-shim-runhcs-v1/task_hcs.go b/cmd/containerd-shim-runhcs-v1/task_hcs.go index afadc50c5e..aec4d8945a 100644 --- a/cmd/containerd-shim-runhcs-v1/task_hcs.go +++ b/cmd/containerd-shim-runhcs-v1/task_hcs.go @@ -469,11 +469,11 @@ func (ht *hcsTask) KillExec(ctx context.Context, eid string, signal uint32, all return true }) } - if signal == 0x9 && eid == "" && ht.host != nil { - // If this is a SIGKILL against the init process we start a background - // timer and wait on either the timer expiring or the process exiting - // cleanly. If the timer expires first we forcibly close the UVM as we - // assume the guest is misbehaving for some reason. + if signal == 0x9 && eid == "" && ht.host != nil && ht.ownsHost { + // SIGKILL to a UVM-owning task's init process: watchdog the guest and + // force-close the UVM if it doesn't exit in time. Gated on ownsHost so a + // workload container sharing the pod UVM can't tear down the sandbox and + // break in-place container restarts on Hyper-V pods. go func() { t := time.NewTimer(30 * time.Second) execExited := make(chan struct{}) @@ -485,9 +485,10 @@ func (ht *hcsTask) KillExec(ctx context.Context, eid string, signal uint32, all case <-execExited: t.Stop() case <-t.C: - // Safe to call multiple times if called previously on - // successful shutdown. - ht.host.Close() + log.G(ctx).WithField("tid", ht.id).Warn( + "hcsTask::KillExec watchdog expired; force-closing owned UVM") + // closeHost honors the ownsHost guard and emits TaskExit. + ht.closeHost(ctx) } }() } diff --git a/internal/gcs/bridge.go b/internal/gcs/bridge.go index c0520a3527..018f4ba2ff 100644 --- a/internal/gcs/bridge.go +++ b/internal/gcs/bridge.go @@ -227,6 +227,22 @@ func (call *rpc) complete(err error) { close(call.ch) } +// forceComplete completes a still-pending RPC out of band when the guest will +// never send its response (e.g. a signal reported the process missing). It +// removes the call from the map under lock first so a late response can't +// double-complete it; returns false if the RPC is no longer tracked. +func (brdg *bridge) forceComplete(call *rpc, err error) bool { + brdg.mu.Lock() + if _, ok := brdg.rpcs[call.id]; !ok { + brdg.mu.Unlock() + return false + } + delete(brdg.rpcs, call.id) + brdg.mu.Unlock() + call.complete(err) + return true +} + type rpcError struct { result int32 message string @@ -397,6 +413,17 @@ func (brdg *bridge) recvLoop() error { delete(brdg.rpcs, id) brdg.mu.Unlock() if call == nil { + waitResponseType := prot.MsgType(prot.RPCWaitForProcess) | prot.MsgTypeResponse + if typ == waitResponseType { + // SignalProcess can report a process missing before the + // guest's outstanding wait response arrives. The wait is + // completed locally, so its eventual response has no call. + brdg.log.WithFields(logrus.Fields{ + "message-id": id, + "type": typ.String(), + }).Warning("bridge received unmatched WaitForProcess response; ignoring") + continue + } return fmt.Errorf("bridge received unknown rpc response for id %d, type %s", id, typ) } err := json.Unmarshal(b, call.resp) diff --git a/internal/gcs/bridge_test.go b/internal/gcs/bridge_test.go index 5ce96f4888..9aeb628a1a 100644 --- a/internal/gcs/bridge_test.go +++ b/internal/gcs/bridge_test.go @@ -277,3 +277,75 @@ func TestPreregisterRPCReusesOutstanding(t *testing.T) { t.Errorf("duplicate PreregisterRPC returned a new call; want the outstanding one") } } + +func TestBridgeForceComplete(t *testing.T) { + s, _ := pipeConn() + b := newBridge(s, nil, logrus.NewEntry(logrus.StandardLogger())) + + call := &rpc{ch: make(chan struct{}), id: 42} + b.rpcs[call.id] = call + + sentinel := errors.New("forced") + if !b.forceComplete(call, sentinel) { + t.Fatal("forceComplete should report true for a tracked rpc") + } + if !call.Done() { + t.Fatal("rpc should be completed after forceComplete") + } + if !errors.Is(call.Err(), sentinel) { + t.Fatalf("expected err %v, got %v", sentinel, call.Err()) + } + if _, ok := b.rpcs[call.id]; ok { + t.Fatal("rpc should be removed from the tracking map") + } + + // A second call is a no-op: the rpc is no longer tracked. + if b.forceComplete(call, nil) { + t.Fatal("forceComplete on an untracked rpc should report false") + } +} + +func TestBridgeRecvUnmatchedWaitForProcessResponseIsNonFatal(t *testing.T) { + s, c := pipeConn() + b := newBridge(s, nil, logrus.NewEntry(logrus.StandardLogger())) + b.Start() + defer b.Close() + + go func() { + sendMessage(t, c, prot.MsgType(prot.RPCWaitForProcess)|prot.MsgTypeResponse, 42, []byte("{}")) + // Reflect so a subsequent real RPC can still complete. + reflector(t, c, 0) + }() + + // The bridge must still be usable after the expected late response. + req := testReq{X: 7} + var resp testResp + if err := b.RPC(context.Background(), prot.RPCCreate, &req, &resp, false); err != nil { + t.Fatalf("bridge should survive a late force-completed response, got: %v", err) + } + if resp.X != req.X { + t.Fatalf("expected echoed X=%d, got %d", req.X, resp.X) + } +} + +func TestBridgeRecvUnknownRPCResponseIsFatal(t *testing.T) { + s, c := pipeConn() + b := newBridge(s, nil, logrus.NewEntry(logrus.StandardLogger())) + b.Start() + defer b.Close() + + go sendMessage(t, c, prot.MsgType(prot.RPCCreate)|prot.MsgTypeResponse, 99999, []byte("{}")) + + waitCh := make(chan error, 1) + go func() { + waitCh <- b.Wait() + }() + select { + case err := <-waitCh: + if err == nil || !strings.Contains(err.Error(), "unknown rpc response") { + t.Fatalf("expected unknown response to terminate the bridge, got: %v", err) + } + case <-time.After(time.Second): + t.Fatal("bridge did not terminate after receiving an unknown rpc response") + } +} diff --git a/internal/gcs/process.go b/internal/gcs/process.go index adc249328e..5a6c68fe07 100644 --- a/internal/gcs/process.go +++ b/internal/gcs/process.go @@ -294,7 +294,10 @@ func (p *Process) Signal(ctx context.Context, options interface{}) (_ bool, err logrus.ErrorKey: err, logfields.ContainerID: p.cid, logfields.ProcessID: p.id, - }).Warn("ignoring missing process") + }).Warn("process reported missing by guest; synthesizing exit to unblock wait") + // Guest reported the process gone but never delivered its exit; + // force-complete the wait so Wait()/Stop don't block forever. + p.gc.brdg.forceComplete(p.waitCall, nil) } return false, nil } diff --git a/internal/gcs/process_test.go b/internal/gcs/process_test.go new file mode 100644 index 0000000000..36e12845c5 --- /dev/null +++ b/internal/gcs/process_test.go @@ -0,0 +1,92 @@ +//go:build windows + +package gcs + +import ( + "context" + "encoding/json" + "testing" + "time" + + "github.com/Microsoft/hcsshim/internal/gcs/prot" + "github.com/sirupsen/logrus" +) + +func TestProcessSignalNotFoundCompletesPendingWait(t *testing.T) { + s, c := pipeConn() + b := newBridge(s, nil, logrus.NewEntry(logrus.StandardLogger())) + p := &Process{ + gc: &GuestConnection{brdg: b}, + cid: t.Name(), + id: 1068, + waitResp: &prot.ContainerWaitForProcessResponse{}, + } + p.waitCall = &rpc{ + ch: make(chan struct{}), + id: 42, + proc: prot.RPCWaitForProcess, + resp: p.waitResp, + } + b.rpcs[p.waitCall.id] = p.waitCall + b.nextID = p.waitCall.id + 1 + b.Start() + defer b.Close() + + sendLateWait := make(chan struct{}) + go func() { + signalID, signalType, _, err := readMessage(c) + if err != nil { + t.Error(err) + return + } + if got := signalType &^ prot.MsgTypeRequest; got != prot.MsgType(prot.RPCSignalProcess) { + t.Errorf("request type = %s, want SignalProcess", signalType) + return + } + result := uint32(hrNotFound) + resp, err := json.Marshal(&prot.ResponseBase{ + Result: int32(result), + ErrorMessage: "Element not found.", + }) + if err != nil { + t.Error(err) + return + } + sendMessage(t, c, signalType^prot.MsgTypeRequest^prot.MsgTypeResponse, signalID, resp) + + <-sendLateWait + lateWaitResp, err := json.Marshal(&prot.ContainerWaitForProcessResponse{ExitCode: 1}) + if err != nil { + t.Error(err) + return + } + sendMessage(t, c, prot.MsgType(prot.RPCWaitForProcess)|prot.MsgTypeResponse, p.waitCall.id, lateWaitResp) + reflector(t, c, 0) + }() + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + signaled, err := p.Signal(ctx, nil) + if err != nil { + t.Fatalf("Signal() error = %v", err) + } + if signaled { + t.Fatal("Signal() reported signaling a process the guest said was missing") + } + if !p.waitCall.Done() { + t.Fatal("pending WaitForProcess was not completed") + } + if err := p.waitCall.Err(); err != nil { + t.Fatalf("force-completed WaitForProcess error = %v", err) + } + + close(sendLateWait) + var resp testResp + req := testReq{X: 7} + if err := b.RPC(ctx, prot.RPCCreate, &req, &resp, false); err != nil { + t.Fatalf("bridge should survive the late WaitForProcess response: %v", err) + } + if resp.X != req.X { + t.Fatalf("response X = %d, want %d", resp.X, req.X) + } +}