//go:build linux && rootrunner package host import ( "bytes" "context" "encoding/json" "io" "net/http" "net/http/httptest" "os" "os/exec" "os/signal" "runtime" "strings" "sync" "syscall" "testing" "time" "github.com/carlosframework/platform/internal/hostbox" "github.com/carlosframework/platform/internal/hostclaim" execlease "github.com/carlosframework/platform/internal/hostexec" "github.com/carlosframework/platform/internal/hostguard" "github.com/carlosframework/platform/internal/instancectl" "github.com/carlosframework/platform/internal/park" ) type lifecycleControlTrace struct { ClaimRootWithLaunch t *testing.T } type lifecycleStopTrace struct { claimUnitStopKernel t *testing.T once sync.Once } func (k *lifecycleStopTrace) VerifyStopped(ctx context.Context, target hostguard.FenceTarget, inv StopInventory, ack DrainAcknowledgement) (StopKernelEvidence, error) { evidence, err := k.claimUnitStopKernel.VerifyStopped(ctx, target, inv, ack) if err != nil { k.once.Do(func() { if _, descriptor, ok := strings.Cut(err.Error(), "descriptor remains at "); ok { name, linkErr := os.Readlink(descriptor) info, infoErr := os.ReadFile(strings.Replace(descriptor, "/fd/", "/fdinfo/", 1)) k.t.Logf("retained descriptor %s target=%s link=%v info=%s read=%v", descriptor, name, linkErr, info, infoErr) } journal, readErr := k.Journal.Read(ctx, target) k.t.Logf("stop kernel refusal: %v; journal=%+v read=%v acknowledgement=%+v inventory=%+v", err, journal, readErr, ack, inv) }) } return evidence, err } type lifecycleResponse struct { http.ResponseWriter status int body bytes.Buffer } func (w *lifecycleResponse) Unwrap() http.ResponseWriter { return w.ResponseWriter } func (w *lifecycleResponse) WriteHeader(status int) { w.status = status w.ResponseWriter.WriteHeader(status) } func (w *lifecycleResponse) Write(body []byte) (int, error) { if w.body.Len() < 64<<10 { w.body.Write(body) } return w.ResponseWriter.Write(body) } func (h lifecycleControlTrace) ServeHTTP(w http.ResponseWriter, r *http.Request) { var q hostbox.RoleLaunchRequest var execution execlease.ExecutionRequest if r.URL.Path == "/claim/launch" || r.URL.Path == "/claim/execution" { raw, _ := io.ReadAll(r.Body) r.Body = io.NopCloser(bytes.NewReader(raw)) if r.URL.Path == "/claim/launch" { json.Unmarshal(raw, &q) } else { json.Unmarshal(raw, &execution) } } started := time.Now() response := &lifecycleResponse{ResponseWriter: w} h.ClaimRootWithLaunch.ServeHTTP(response, r) if response.status >= 400 || bytes.Contains(response.body.Bytes(), []byte(`"Failed":true`)) { if execution.Host != "" { raw, err := h.Root.executionRuntime.state.Read(execution.Host + ".json") diagnostic, cancel := context.WithTimeout(context.WithoutCancel(r.Context()), time.Second) a, authorityErr := h.Root.executionAuthorityWithMigration(diagnostic, h.Root.executionRuntime.state, execution, execlease.ControllerProcess{}) cancel() h.t.Logf("execution current authority=%+v err=%v", a, authorityErr) h.t.Logf("execution failure request=%+v retained=%s read=%v", execution, raw, err) } h.t.Logf("root RPC %s status=%d reply=%s", r.URL.Path, response.status, response.body.String()) h.t.Log("root RPC elapsed", time.Since(started)) } if q.Op == hostbox.RoleLaunchStop && q.Reservation != nil { in, err := h.Launch.Journal.Read(r.Context(), q.Reservation.Target) h.t.Logf("stop record err=%v request=%+v record=%+v containment=%v", err, *q.Reservation, in, validatePersistedUnitContainment(r.Context(), in, h.Launch.Units)) } } type lifecycleKernelTrace struct { ClaimLaunchKernel t *testing.T } func (k lifecycleKernelTrace) Observe(s instancectl.ClaimUnitStarted) (ClaimLaunchObserved, error) { got, err := k.ClaimLaunchKernel.Observe(s) k.t.Logf("launch observation: started=%+v observed=%+v error=%v", s, got, err) return got, err } func (k lifecycleKernelTrace) VerifyDigest(ctx context.Context, path string, id hostbox.LaunchFile, digest string) error { err := k.ClaimLaunchKernel.VerifyDigest(ctx, path, id, digest) k.t.Log("launch digest", err) return err } type lifecycleUnitsTrace struct { ClaimLaunchUnits t *testing.T } func (u lifecycleUnitsTrace) Placement(host string) (string, string, error) { return claimLaunchPlacement(u.ClaimLaunchUnits, host) } func (u lifecycleUnitsTrace) StopInvocation(ctx context.Context, host, inv string) error { err := claimStopInvocation(ctx, u.ClaimLaunchUnits, host, inv) u.t.Log("stop invocation", inv, err) return err } func (u lifecycleUnitsTrace) Gone(ctx context.Context, host, inv string) error { err := u.ClaimLaunchUnits.Gone(ctx, host, inv) u.t.Log("gone", inv, err) return err } func (u lifecycleUnitsTrace) StartReserved(ctx context.Context, in instancectl.ClaimUnit, l instancectl.Launch, p instancectl.ClaimExecPermit, check func() error) (instancectl.ClaimUnitStarted, error) { got, err := u.ClaimLaunchUnits.StartReserved(ctx, in, l, p, func() error { e := check(); u.t.Log("unit start revalidation", e); return e }) u.t.Log("start reserved", got, err) if err != nil { raw, _ := exec.Command("journalctl", "-u", instancectl.UnitName(instancectl.RoleRun, in.Host), "--no-pager", "-n", "60").CombinedOutput() u.t.Log(string(raw)) } return got, err } type lifecycleRegionalTrace struct { hostbox.RegionalEvidence t *testing.T once sync.Once } func (r *lifecycleRegionalTrace) VerifyObligation(ctx context.Context, o hostclaim.Observed, ob hostclaim.Obligation) (hostclaim.ParkScope, error) { scope, err := r.RegionalEvidence.(hostbox.RegionalObligationEvidence).VerifyObligation(ctx, o, ob) if err != nil { r.once.Do(func() { r.t.Logf("regional evidence: %v; obligation=%+v holder=%+v", err, ob, o.Claim.Holder) }) } return scope, err } func lifecycleTraceRegional(t *testing.T, p *ClaimProviders) { worker := p.Regional.(hostbox.RegionalWorker) worker.Regional.Engine.Now = func() time.Time { return time.Now().Add(park.SignatureAge + hostbox.RequestLimit + time.Second) } worker.Evidence = &lifecycleRegionalTrace{RegionalEvidence: worker.Evidence, t: t} view, authorize := worker.Regional.Engine.View, worker.Regional.Engine.Authorize var viewOnce, authorizeOnce sync.Once worker.Regional.Engine.View = func(ctx context.Context, o hostclaim.Observed) (park.View, error) { v, err := view(ctx, o) if err != nil { viewOnce.Do(func() { t.Log("regional view", err) }) } return v, err } worker.Regional.Engine.Authorize = func(ctx context.Context, o hostclaim.Observed, ob hostclaim.Obligation) error { err := authorize(ctx, o, ob) if err != nil { authorizeOnce.Do(func() { t.Log("regional authorization", err) }) } return err } p.Regional = worker } func lifecycleTraceParkState(t *testing.T, p ClaimProviders, o hostclaim.Observed) { engine := p.Regional.(hostbox.RegionalWorker).Regional.Engine v, err := engine.View(t.Context(), o) t.Logf("park view=%+v err=%v holder=%+v", v, err, o.Claim.Holder) if err != nil || o.Claim.Holder == nil { return } live, err := park.LiveGenerations(o.Claim, v, o.Claim.Holder.Location) t.Log("park live", live, err) versions, err := engine.Store.ListVersions(t.Context(), engine.Bucket, o.Claim.Holder.Location+"/") t.Log("park listing", err) for _, version := range versions { if strings.HasSuffix(version.Key, "/lock.json") { continue } generation, known := v.GenerationOf(park.Ref{Key: version.Key, VersionID: version.VersionID}) t.Logf("park version=%+v generation=%q known=%v", version, generation, known) } } func TestPlan14LifecycleTraceStreams(t *testing.T) { sink := httptest.NewRecorder() w := &lifecycleResponse{ResponseWriter: sink} if _, err := w.Write([]byte("fence")); err != nil { t.Fatal(err) } if err := http.NewResponseController(w).Flush(); err != nil { t.Fatal(err) } if !sink.Flushed || sink.Body.String() != "fence" { t.Fatal("drain frame buffered") } } func lifecycleStackTrace(t *testing.T) { signals := make(chan os.Signal, 1) signal.Notify(signals, syscall.SIGUSR1) done := make(chan struct{}) t.Cleanup(func() { signal.Stop(signals); close(done) }) go func() { for { select { case <-done: return case <-signals: buf := make([]byte, 2<<20) n := runtime.Stack(buf, true) t.Logf("lifecycle goroutines:\n%s", buf[:n]) } } }() } func lifecycleCrashDiagnostic(t *testing.T) { for _, unit := range []string{"carlos-edge.service", "carlos-instance-control.service"} { out, err := exec.Command("systemctl", "kill", "--kill-who=main", "--signal=SIGUSR1", unit).CombinedOutput() t.Logf("stack signal %s: %s %v", unit, out, err) } time.Sleep(time.Second) out, err := exec.Command("journalctl", "-u", "carlos-edge.service", "--no-pager", "-o", "cat").CombinedOutput() t.Logf("full edge log: %s %v", out, err) }