fix(daemon): restore slog default after viperblock.New mutates it

viperblock.New unconditionally calls vb.SetDebug, which calls
slog.SetDefault with a TextHandler at LevelError — globally silencing
every slog.Info and slog.Warn in the caller process for the rest of
its life. Discovered while validating microvm Phase 2 (mulga-siv-68):
the daemon stopped emitting Info logs the moment the first customer
VM with volumes launched, hiding direct-boot timing,
LaunchSystemInstance completed, and CreateLoadBalancer completed
lines that we need for boot-time tuning.

Workaround in newViperblock: re-install an Info-level TextHandler on
os.Stderr after each viperblock.New call. Also drop the three explicit
vb.SetDebug(false) calls in prepareRootVolume / prepareEFIVolume /
prepareCloudInitVolume — they were no-ops (viperblock.New already
runs SetDebug internally) and each one re-triggered the global
mutation we are trying to undo.

Proper fix is in viperblock itself — tracked as mulga-siv-70: SetDebug
should not call slog.SetDefault. Until then, this restore call is the
shortest path to getting the daemon's observability back so we can
measure t1_to_t2_ms and tune Phase 2.

Preflight note: golangci-lint not available on this dev host, so the
project preflight target cannot run end-to-end. Verified with
go vet ./spinifex/handlers/ec2/instance/... (clean) and
go test ./spinifex/handlers/ec2/instance/... (pass).
This commit is contained in:
joshsiv-mulga
2026-05-17 18:23:17 +10:00
parent 478c32fe51
commit 509ea34927
+14 -7
View File
@@ -877,7 +877,20 @@ func (s *InstanceServiceImpl) newViperblock(volumeName string, size int, volumeC
VolumeConfig: volumeConfig,
}
return viperblock.New(&vbconfig, "s3", cfg)
vb, err := viperblock.New(&vbconfig, "s3", cfg)
restoreSlogDefault()
return vb, err
}
// restoreSlogDefault re-installs the daemon's Info-level slog handler after
// viperblock.New mutates the global slog default via its SetDebug method
// (see viperblock.go SetDebug — it calls slog.SetDefault with LevelError,
// silencing every Info/Warn in the entire process). Tracked for proper fix
// in viperblock as mulga-siv-70.
func restoreSlogDefault() {
slog.SetDefault(slog.New(slog.NewTextHandler(os.Stderr, &slog.HandlerOptions{
Level: slog.LevelInfo,
})))
}
// prepareRootVolume handles creation/cloning of the root volume
@@ -888,8 +901,6 @@ func (s *InstanceServiceImpl) prepareRootVolume(input *ec2.RunInstancesInput, im
return errors.New(awserrors.ErrorServerInternal)
}
vb.SetDebug(false)
// Initialize the backend
err = vb.Backend.Init()
if err != nil {
@@ -996,8 +1007,6 @@ func (s *InstanceServiceImpl) prepareEFIVolume(imageId string, volumeConfig vipe
return errors.New(awserrors.ErrorServerInternal)
}
efiVb.SetDebug(false)
// Initialize the backend
slog.Debug("Initializing EFI Viperblock store backend")
err = efiVb.Backend.Init()
@@ -1083,8 +1092,6 @@ func (s *InstanceServiceImpl) prepareCloudInitVolume(input *ec2.RunInstancesInpu
return errors.New(awserrors.ErrorServerInternal)
}
cloudInitVb.SetDebug(false)
// Initialize the backend
slog.Debug("Initializing cloud-init Viperblock store backend")
err = cloudInitVb.Backend.Init()