From a344dbc8ac77dbe3ab8170d2dfe4b2ef7865f89e Mon Sep 17 00:00:00 2001 From: Lachezar Tsonov Date: Thu, 5 Mar 2026 10:51:48 +0200 Subject: [PATCH 1/7] Add more logging as spot-handler looks stuck currently. --- handler/handler.go | 3 +++ 1 file changed, 3 insertions(+) diff --git a/handler/handler.go b/handler/handler.go index 8d9aaeb..7986da7 100644 --- a/handler/handler.go +++ b/handler/handler.go @@ -124,11 +124,14 @@ func (g *SpotHandler) Run(ctx context.Context) error { if err != nil { g.log.Errorf("checking for cloud events: %v", err) } + g.log.Debugf("poll tick completed") case <-deadline.C: + g.log.Infof("grace period elapsed, exiting") return nil case <-ctx.Done(): // Signal received, starting countdown until exiting the loop. once.Do(func() { + g.log.Infof("termination signal received, waiting grace period of %s before exit", g.gracePeriod) deadline.Reset(g.gracePeriod) }) } From 09bbdd09780f816f2fe22fcd61445e818ecd9809 Mon Sep 17 00:00:00 2001 From: Lachezar Tsonov Date: Thu, 5 Mar 2026 10:52:01 +0200 Subject: [PATCH 2/7] Respect log level from config for main logger as well. --- main.go | 1 + 1 file changed, 1 insertion(+) diff --git a/main.go b/main.go index fb55993..2b76607 100644 --- a/main.go +++ b/main.go @@ -30,6 +30,7 @@ func main() { cfg := config.Get() logger := logrus.New() + logger.SetLevel(logrus.Level(cfg.LogLevel)) log := logrus.WithFields(logrus.Fields{}) kubeconfig, err := retrieveKubeConfig(log, cfg) From 202e69d8b943961a307a470996fb8abe2d042085 Mon Sep 17 00:00:00 2001 From: Lachezar Tsonov Date: Thu, 5 Mar 2026 10:55:57 +0200 Subject: [PATCH 3/7] Log on stopping as well to make it clear --- handler/handler.go | 1 + 1 file changed, 1 insertion(+) diff --git a/handler/handler.go b/handler/handler.go index 7986da7..fd579ab 100644 --- a/handler/handler.go +++ b/handler/handler.go @@ -101,6 +101,7 @@ func (g *SpotHandler) Run(ctx context.Context) error { return err } // Stop after ACK. + g.log.Infof("stopping poll ticker") t.Stop() } From be08df452a77fef297f4dca77a9c40a4b76958ee Mon Sep 17 00:00:00 2001 From: Lachezar Tsonov Date: Thu, 5 Mar 2026 11:06:34 +0200 Subject: [PATCH 4/7] Prepend https protocol if missing from API url - as it breaks resty. --- main.go | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/main.go b/main.go index 2b76607..7cf6538 100644 --- a/main.go +++ b/main.go @@ -6,6 +6,7 @@ import ( "net/http" _ "net/http/pprof" "os" + "strings" "time" "github.com/sirupsen/logrus" @@ -72,9 +73,16 @@ func main() { log.Fatalf("interrupt checker: %v", err) } + apiURL := cfg.APIUrl + if !strings.HasPrefix(apiURL, "http://") && + !strings.HasPrefix(apiURL, "https://") { + log.Warnf("API_URL %q is missing protocol scheme, will convert to https://%s", apiURL, apiURL) + apiURL = "https://" + apiURL + } + // Set 5 seconds until we timeout calling mothership and retry. castHttpClient, err := castai.NewRestyClient( - cfg.APIUrl, + apiURL, cfg.APIKey, cfg.TLSCACert, logrus.Level(cfg.LogLevel), From 01f87880b1c52264dac96bc487ae5b4378774eb1 Mon Sep 17 00:00:00 2001 From: Lachezar Tsonov Date: Thu, 5 Mar 2026 11:52:52 +0200 Subject: [PATCH 5/7] Revert api url prepend --- main.go | 10 +--------- 1 file changed, 1 insertion(+), 9 deletions(-) diff --git a/main.go b/main.go index 7cf6538..2b76607 100644 --- a/main.go +++ b/main.go @@ -6,7 +6,6 @@ import ( "net/http" _ "net/http/pprof" "os" - "strings" "time" "github.com/sirupsen/logrus" @@ -73,16 +72,9 @@ func main() { log.Fatalf("interrupt checker: %v", err) } - apiURL := cfg.APIUrl - if !strings.HasPrefix(apiURL, "http://") && - !strings.HasPrefix(apiURL, "https://") { - log.Warnf("API_URL %q is missing protocol scheme, will convert to https://%s", apiURL, apiURL) - apiURL = "https://" + apiURL - } - // Set 5 seconds until we timeout calling mothership and retry. castHttpClient, err := castai.NewRestyClient( - apiURL, + cfg.APIUrl, cfg.APIKey, cfg.TLSCACert, logrus.Level(cfg.LogLevel), From 2410bd6a089edb3d98964ef075fc819730e84b4a Mon Sep 17 00:00:00 2001 From: Lachezar Tsonov Date: Mon, 9 Mar 2026 15:31:41 +0200 Subject: [PATCH 6/7] Add a logger to azure checker (and fixing some reusability) --- handler/azure.go | 5 ++++- handler/azure_test.go | 3 +++ main.go | 8 ++++---- 3 files changed, 11 insertions(+), 5 deletions(-) diff --git a/handler/azure.go b/handler/azure.go index 2acf29d..8b1c43d 100644 --- a/handler/azure.go +++ b/handler/azure.go @@ -6,11 +6,12 @@ import ( "time" "github.com/go-resty/resty/v2" + "github.com/sirupsen/logrus" ) // NewAzureInterruptChecker checks for azure spot interrupt event from metadata server. // See https://docs.microsoft.com/en-us/azure/virtual-machines/linux/scheduled-events#endpoint-discovery -func NewAzureInterruptChecker() MetadataChecker { +func NewAzureInterruptChecker(log logrus.FieldLogger) MetadataChecker { client := resty.New() // Times out if set to 1 second, after 2 we will try again soon anyway client.SetTimeout(time.Second * 2) @@ -18,12 +19,14 @@ func NewAzureInterruptChecker() MetadataChecker { return &azureInterruptChecker{ client: client, metadataServerURL: "http://169.254.169.254", + log: log, } } type azureInterruptChecker struct { client *resty.Client metadataServerURL string + log logrus.FieldLogger } type azureSpotScheduledEvent struct { diff --git a/handler/azure_test.go b/handler/azure_test.go index 9b6d938..754bfca 100644 --- a/handler/azure_test.go +++ b/handler/azure_test.go @@ -8,6 +8,7 @@ import ( "testing" "github.com/go-resty/resty/v2" + "github.com/sirupsen/logrus" "github.com/stretchr/testify/require" ) @@ -32,9 +33,11 @@ func TestAzureInterruptChecker(t *testing.T) { })) defer s.Close() + log := logrus.New() checker := azureInterruptChecker{ client: resty.New(), metadataServerURL: s.URL, + log: log, } interrupted, err := checker.CheckInterrupt(context.Background()) diff --git a/main.go b/main.go index 2b76607..4efd70d 100644 --- a/main.go +++ b/main.go @@ -31,7 +31,7 @@ func main() { logger := logrus.New() logger.SetLevel(logrus.Level(cfg.LogLevel)) - log := logrus.WithFields(logrus.Fields{}) + log := logger.WithFields(logrus.Fields{}) kubeconfig, err := retrieveKubeConfig(log, cfg) if err != nil { @@ -67,7 +67,7 @@ func main() { "k8s_version": k8sVersionField, }) - interruptChecker, err := buildInterruptChecker(cfg.Provider) + interruptChecker, err := buildInterruptChecker(cfg.Provider, log) if err != nil { log.Fatalf("interrupt checker: %v", err) } @@ -116,10 +116,10 @@ func main() { } } -func buildInterruptChecker(provider string) (handler.MetadataChecker, error) { +func buildInterruptChecker(provider string, log logrus.FieldLogger) (handler.MetadataChecker, error) { switch provider { case "azure": - return handler.NewAzureInterruptChecker(), nil + return handler.NewAzureInterruptChecker(log), nil case "gcp": return handler.NewGCPChecker(), nil case "aws": From f4b4c699acd0d691d297fed1b90b397e94fb9108 Mon Sep 17 00:00:00 2001 From: Lachezar Tsonov Date: Mon, 9 Mar 2026 15:39:51 +0200 Subject: [PATCH 7/7] Extend logging per incarnation and more event details --- handler/azure.go | 20 ++++++++++++++++++-- 1 file changed, 18 insertions(+), 2 deletions(-) diff --git a/handler/azure.go b/handler/azure.go index 8b1c43d..a780548 100644 --- a/handler/azure.go +++ b/handler/azure.go @@ -29,11 +29,19 @@ type azureInterruptChecker struct { log logrus.FieldLogger } +// azureSpotScheduledEvent is a single event schema, not all fields are necessarily mapped +// see https://learn.microsoft.com/en-us/azure/virtual-machines/linux/scheduled-events#the-basics for details type azureSpotScheduledEvent struct { - EventType string + EventId string + EventType string + EventStatus string + EventSource string + Description string + NotBefore string } type azureSpotScheduledEvents struct { - Events []azureSpotScheduledEvent + DocumentIncarnation int + Events []azureSpotScheduledEvent } func (c *azureInterruptChecker) CheckInterrupt(ctx context.Context) (bool, error) { @@ -50,7 +58,15 @@ func (c *azureInterruptChecker) CheckInterrupt(ctx context.Context) (bool, error return false, fmt.Errorf("received unexpected status code: %d", resp.StatusCode()) } + if len(responseBody.Events) == 0 { + return false, nil + } + + c.log.Debugf("Received %d scheduled events with incarnation %d", len(responseBody.Events), responseBody.DocumentIncarnation) + for _, e := range responseBody.Events { + c.log.Debugf("Scheduled event seen: EventId=%s, EventType=%s, EventStatus=%s, EventSource=%s, NotBefore=%s, Description=%s", + e.EventId, e.EventType, e.EventStatus, e.EventSource, e.NotBefore, e.Description) if e.EventType == "Preempt" { return true, nil }