Operational logs over API: hypeman.log, vmm.log (#34)

* Operational logs over API: hypeman.log, vmm.log

* Fix test

* Review instance log handler

* Use log not found error

* Don't delete taps when instance state is unknown

* Review fixes

1. Exec endpoint now has logger injection:

2. Simplified InstanceLogHandler - no more file caching:
- Removed `sharedState` struct with mutex and fileCache
- Each write now opens, writes, closes the file
- No cleanup methods needed = no leak possible
- Simpler code, no shared state complexity

The performance impact is negligible since instance operations (start, stop, standby, etc.) are infrequent. The tradeoff of slightly more I/O vs. guaranteed no leaks and simpler code is worth it.

* add logs

* Fix which id

* Reivew fixes

* run cleanup when no vm

* Move resource id, partial id, name resolution to middleware

* Fix response code

* Extra careful checks

1. Fixed `ErrAmbiguousName` to return 409 Conflict (instead of 404)

Changed the HTTP status code from `http.StatusNotFound` to `http.StatusConflict` for ambiguous name errors, restoring the previous ingress behavior.

2. Added nil checks with 500 error responses for all `GetResolved*` calls

Added defensive nil checks to all 14 handlers that use the resolved resource from middleware. If the middleware didn't set the resource (which shouldn't happen in production but could in tests), the handler now returns a 500 error with `"resource not resolved"` message instead of panicking with a nil pointer dereference.

* resource_id instead of id, fix target in ingress to use instance name

$ hypeman ingress create q  --hostname 'nginx-test' --port 80 --host-port 8081
Creating ingress nginx-test-wmbi...
e5hbxzwc6cq0tnjchw861exg

$ hypeman ingress list
ID            NAME             HOSTNAME    TARGET         TLS  CREATED
e5hbxzwc6cq0  nginx-test-wmbi  nginx-test  nginx-gi7w:80  no   4 seconds ago

Fix is shows "nginx-gi7w:80" instead of "g:80"

Author: sjmiller609

cmd/api/api/api_test.go

@@ -11,6 +11,7 @@ import (
 	"github.com/onkernel/hypeman/cmd/api/config"
 	"github.com/onkernel/hypeman/lib/images"
 	"github.com/onkernel/hypeman/lib/instances"
+	mw "github.com/onkernel/hypeman/lib/middleware"
 	"github.com/onkernel/hypeman/lib/network"
 	"github.com/onkernel/hypeman/lib/oapi"
 	"github.com/onkernel/hypeman/lib/paths"
@@ -98,6 +99,36 @@ func ctx() context.Context {
 	return context.Background()
 }
 
+// ctxWithInstance creates a context with a resolved instance (simulates ResolveResource middleware)
+func ctxWithInstance(svc *ApiService, idOrName string) context.Context {
+	inst, err := svc.InstanceManager.GetInstance(ctx(), idOrName)
+	if err != nil {
+		return ctx() // Let handler deal with the error
+	}
+	return mw.WithResolvedInstance(ctx(), inst.Id, inst)
+}
+
+// ctxWithVolume creates a context with a resolved volume (simulates ResolveResource middleware)
+func ctxWithVolume(svc *ApiService, idOrName string) context.Context {
+	vol, err := svc.VolumeManager.GetVolume(ctx(), idOrName)
+	if err != nil {
+		vol, err = svc.VolumeManager.GetVolumeByName(ctx(), idOrName)
+	}
+	if err != nil {
+		return ctx()
+	}
+	return mw.WithResolvedVolume(ctx(), vol.Id, vol)
+}
+
+// ctxWithImage creates a context with a resolved image (simulates ResolveResource middleware)
+func ctxWithImage(svc *ApiService, name string) context.Context {
+	img, err := svc.ImageManager.GetImage(ctx(), name)
+	if err != nil {
+		return ctx()
+	}
+	return mw.WithResolvedImage(ctx(), img.Name, img)
+}
+
 // createAndWaitForImage creates an image and waits for it to be ready.
 // Returns the image name on success, or fails the test on error/timeout.
 func createAndWaitForImage(t *testing.T, svc *ApiService, imageName string, timeout time.Duration) string {
@@ -117,24 +148,26 @@ func createAndWaitForImage(t *testing.T, svc *ApiService, imageName string, time
 	t.Log("Waiting for image to be ready...")
 	deadline := time.Now().Add(timeout)
 	for time.Now().Before(deadline) {
-		imgResp, err := svc.GetImage(ctx(), oapi.GetImageRequestObject{
-			Name: imageName,
-		})
-		require.NoError(t, err)
-
-		img, ok := imgResp.(oapi.GetImage200JSONResponse)
-		if ok {
-			switch img.Status {
-			case "ready":
-				t.Log("Image is ready")
-				return imgCreated.Name
-			case "failed":
-				t.Fatalf("Image build failed: %v", img.Error)
-			default:
-				t.Logf("Image status: %s", img.Status)
+		// Get image from manager (may fail during pending/pulling, that's OK)
+		img, err := svc.ImageManager.GetImage(ctx(), imageName)
+		if err != nil {
+			time.Sleep(100 * time.Millisecond)
+			continue
+		}
+
+		switch img.Status {
+		case "ready":
+			t.Log("Image is ready")
+			return imgCreated.Name
+		case "failed":
+			errMsg := ""
+			if img.Error != nil {
+				errMsg = *img.Error
 			}
+			t.Fatalf("Image build failed: %v", errMsg)
 		}
-		time.Sleep(1 * time.Second)
+		// Still pending/pulling/converting, poll again
+		time.Sleep(100 * time.Millisecond)
 	}
 
 	t.Fatalf("Timeout waiting for image %s to be ready", imageName)

cmd/api/api/exec.go

@@ -10,11 +10,11 @@ import (
 	"sync"
 	"time"
 
-	"github.com/go-chi/chi/v5"
 	"github.com/gorilla/websocket"
 	"github.com/onkernel/hypeman/lib/exec"
 	"github.com/onkernel/hypeman/lib/instances"
 	"github.com/onkernel/hypeman/lib/logger"
+	mw "github.com/onkernel/hypeman/lib/middleware"
 )
 
 var upgrader = websocket.Upgrader{
@@ -36,22 +36,16 @@ type ExecRequest struct {
 }
 
 // ExecHandler handles exec requests via WebSocket for bidirectional streaming
+// Note: Resolution is handled by ResolveResource middleware
 func (s *ApiService) ExecHandler(w http.ResponseWriter, r *http.Request) {
 	ctx := r.Context()
-	log := logger.FromContext(ctx)
 	startTime := time.Now()
+	log := logger.FromContext(ctx)
 
-	instanceID := chi.URLParam(r, "id")
-
-	// Get instance
-	inst, err := s.InstanceManager.GetInstance(ctx, instanceID)
-	if err != nil {
-		if err == instances.ErrNotFound {
-			http.Error(w, `{"code":"not_found","message":"instance not found"}`, http.StatusNotFound)
-			return
-		}
-		log.ErrorContext(ctx, "failed to get instance", "error", err)
-		http.Error(w, `{"code":"internal_error","message":"failed to get instance"}`, http.StatusInternalServerError)
+	// Get instance resolved by middleware
+	inst := mw.GetResolvedInstance[instances.Instance](ctx)
+	if inst == nil {
+		http.Error(w, `{"code":"internal_error","message":"resource not resolved"}`, http.StatusInternalServerError)
 		return
 	}
 
@@ -105,7 +99,7 @@ func (s *ApiService) ExecHandler(w http.ResponseWriter, r *http.Request) {
 
 	// Audit log: exec session started
 	log.InfoContext(ctx, "exec session started",
-		"instance_id", instanceID,
+		"instance_id", inst.Id,
 		"subject", subject,
 		"command", execReq.Command,
 		"tty", execReq.TTY,
@@ -133,7 +127,7 @@ func (s *ApiService) ExecHandler(w http.ResponseWriter, r *http.Request) {
 	if err != nil {
 		log.ErrorContext(ctx, "exec failed",
 			"error", err,
-			"instance_id", instanceID,
+			"instance_id", inst.Id,
 			"subject", subject,
 			"duration_ms", duration.Milliseconds(),
 		)
@@ -148,7 +142,7 @@ func (s *ApiService) ExecHandler(w http.ResponseWriter, r *http.Request) {
 
 	// Audit log: exec session ended
 	log.InfoContext(ctx, "exec session ended",
-		"instance_id", instanceID,
+		"instance_id", inst.Id,
 		"subject", subject,
 		"exit_code", exit.Code,
 		"duration_ms", duration.Milliseconds(),

cmd/api/api/exec_test.go

@@ -8,6 +8,7 @@ import (
 	"time"
 
 	"github.com/onkernel/hypeman/lib/exec"
+	"github.com/onkernel/hypeman/lib/instances"
 	"github.com/onkernel/hypeman/lib/oapi"
 	"github.com/onkernel/hypeman/lib/paths"
 	"github.com/onkernel/hypeman/lib/system"
@@ -91,7 +92,7 @@ func TestExecInstanceNonTTY(t *testing.T) {
 	// Capture console log on failure with exec-agent filtering
 	t.Cleanup(func() {
 		if t.Failed() {
-			consolePath := paths.New(svc.Config.DataDir).InstanceConsoleLog(inst.Id)
+			consolePath := paths.New(svc.Config.DataDir).InstanceAppLog(inst.Id)
 			if consoleData, err := os.ReadFile(consolePath); err == nil {
 				lines := strings.Split(string(consoleData), "\n")
 
@@ -152,7 +153,7 @@ func TestExecInstanceNonTTY(t *testing.T) {
 
 	// Cleanup
 	t.Log("Cleaning up instance...")
-	delResp, err := svc.DeleteInstance(ctx(), oapi.DeleteInstanceRequestObject{
+	delResp, err := svc.DeleteInstance(ctxWithInstance(svc, inst.Id), oapi.DeleteInstanceRequestObject{
 		Id: inst.Id,
 	})
 	require.NoError(t, err)
@@ -211,7 +212,7 @@ func TestExecWithDebianMinimal(t *testing.T) {
 	// Cleanup on exit
 	t.Cleanup(func() {
 		t.Log("Cleaning up instance...")
-		svc.DeleteInstance(ctx(), oapi.DeleteInstanceRequestObject{Id: inst.Id})
+		svc.DeleteInstance(ctxWithInstance(svc, inst.Id), oapi.DeleteInstanceRequestObject{Id: inst.Id})
 	})
 
 	// Get actual instance to access vsock fields
@@ -280,7 +281,7 @@ func TestExecWithDebianMinimal(t *testing.T) {
 
 // collectTestLogs collects logs from an instance (non-streaming)
 func collectTestLogs(t *testing.T, svc *ApiService, instanceID string, n int) string {
-	logChan, err := svc.InstanceManager.StreamInstanceLogs(ctx(), instanceID, n, false)
+	logChan, err := svc.InstanceManager.StreamInstanceLogs(ctx(), instanceID, n, false, instances.LogSourceApp)
 	if err != nil {
 		return ""
 	}

cmd/api/api/images.go

@@ -6,6 +6,7 @@ import (
 
 	"github.com/onkernel/hypeman/lib/images"
 	"github.com/onkernel/hypeman/lib/logger"
+	mw "github.com/onkernel/hypeman/lib/middleware"
 	"github.com/onkernel/hypeman/lib/oapi"
 )
 
@@ -60,46 +61,38 @@ func (s *ApiService) CreateImage(ctx context.Context, request oapi.CreateImageRe
 	return oapi.CreateImage202JSONResponse(imageToOAPI(*img)), nil
 }
 
+// GetImage gets image details by name
+// Note: Resolution is handled by ResolveResource middleware
 func (s *ApiService) GetImage(ctx context.Context, request oapi.GetImageRequestObject) (oapi.GetImageResponseObject, error) {
-	log := logger.FromContext(ctx)
-
-	img, err := s.ImageManager.GetImage(ctx, request.Name)
-	if err != nil {
-		switch {
-		case errors.Is(err, images.ErrInvalidName), errors.Is(err, images.ErrNotFound):
-			return oapi.GetImage404JSONResponse{
-				Code:    "not_found",
-				Message: "image not found",
-			}, nil
-		default:
-			log.ErrorContext(ctx, "failed to get image", "error", err, "name", request.Name)
-			return oapi.GetImage500JSONResponse{
-				Code:    "internal_error",
-				Message: "failed to get image",
-			}, nil
-		}
+	img := mw.GetResolvedImage[images.Image](ctx)
+	if img == nil {
+		return oapi.GetImage500JSONResponse{
+			Code:    "internal_error",
+			Message: "resource not resolved",
+		}, nil
 	}
 	return oapi.GetImage200JSONResponse(imageToOAPI(*img)), nil
 }
 
+// DeleteImage deletes an image by name
+// Note: Resolution is handled by ResolveResource middleware
 func (s *ApiService) DeleteImage(ctx context.Context, request oapi.DeleteImageRequestObject) (oapi.DeleteImageResponseObject, error) {
+	img := mw.GetResolvedImage[images.Image](ctx)
+	if img == nil {
+		return oapi.DeleteImage500JSONResponse{
+			Code:    "internal_error",
+			Message: "resource not resolved",
+		}, nil
+	}
 	log := logger.FromContext(ctx)
 
-	err := s.ImageManager.DeleteImage(ctx, request.Name)
+	err := s.ImageManager.DeleteImage(ctx, img.Name)
 	if err != nil {
-		switch {
-		case errors.Is(err, images.ErrInvalidName), errors.Is(err, images.ErrNotFound):
-			return oapi.DeleteImage404JSONResponse{
-				Code:    "not_found",
-				Message: "image not found",
-			}, nil
-		default:
-			log.ErrorContext(ctx, "failed to delete image", "error", err, "name", request.Name)
-			return oapi.DeleteImage500JSONResponse{
-				Code:    "internal_error",
-				Message: "failed to delete image",
-			}, nil
-		}
+		log.ErrorContext(ctx, "failed to delete image", "error", err)
+		return oapi.DeleteImage500JSONResponse{
+			Code:    "internal_error",
+			Message: "failed to delete image",
+		}, nil
 	}
 	return oapi.DeleteImage204Response{}, nil
 }