diff --git a/cmd/state-svc/internal/messages/messages.go b/cmd/state-svc/internal/messages/messages.go index 88cdf78f9e..1495a8a1b2 100644 --- a/cmd/state-svc/internal/messages/messages.go +++ b/cmd/state-svc/internal/messages/messages.go @@ -4,6 +4,7 @@ import ( "encoding/json" "fmt" "os" + "runtime/debug" "sync" "time" @@ -15,6 +16,7 @@ import ( "github.com/ActiveState/cli/internal/httputil" "github.com/ActiveState/cli/internal/logging" "github.com/ActiveState/cli/internal/poller" + "github.com/ActiveState/cli/internal/runbits/panics" "github.com/ActiveState/cli/internal/strutils" auth "github.com/ActiveState/cli/pkg/platform/authentication" "github.com/ActiveState/cli/pkg/sysinfo" @@ -43,6 +45,9 @@ func New(cfg *config.Instance, auth *auth.Auth) (*Messages, error) { } poll := poller.New(1*time.Hour, func() (interface{}, error) { + defer func() { + panics.LogAndPanic(recover(), debug.Stack()) + }() resp, err := fetch() return resp, err }) @@ -74,7 +79,11 @@ func (m *Messages) Check(command string, flags []string) ([]*graph.MessageInfo, if cacheValue == nil { return []*graph.MessageInfo{}, nil } - allMessages := cacheValue.([]*graph.MessageInfo) + + allMessages, ok := cacheValue.([]*graph.MessageInfo) + if !ok { + return nil, errs.New("cacheValue has unexpected type: %T", cacheValue) + } conditionParams := *m.baseParams // copy conditionParams.UserEmail = m.auth.Email() @@ -110,7 +119,11 @@ func check(params *ConditionParams, messages []*graph.MessageInfo, lastReportMap logging.Debug("Checking message %s", message.ID) // Ensure we don't show the same message too often if lastReport, ok := lastReportMap[message.ID]; ok { - lastReportTime, err := time.Parse(time.RFC3339, lastReport.(string)) + lr, ok := lastReport.(string) + if !ok { + return nil, errs.New("Could not get last reported time for message %s as it's not a string: %T", message.ID, lastReport) + } + lastReportTime, err := time.Parse(time.RFC3339, lr) if err != nil { return nil, errs.New("Could not parse last reported time for message %s as it's not a valid RFC3339 value: %v", message.ID, lastReport) } diff --git a/cmd/state-svc/internal/resolver/resolver.go b/cmd/state-svc/internal/resolver/resolver.go index 7995751f88..ba91441e7f 100644 --- a/cmd/state-svc/internal/resolver/resolver.go +++ b/cmd/state-svc/internal/resolver/resolver.go @@ -24,9 +24,9 @@ import ( "github.com/ActiveState/cli/internal/graph" "github.com/ActiveState/cli/internal/logging" configMediator "github.com/ActiveState/cli/internal/mediators/config" - "github.com/ActiveState/cli/internal/multilog" "github.com/ActiveState/cli/internal/poller" "github.com/ActiveState/cli/internal/rtutils/ptr" + "github.com/ActiveState/cli/internal/runbits/panics" "github.com/ActiveState/cli/internal/updater" "github.com/ActiveState/cli/pkg/platform/authentication" "github.com/ActiveState/cli/pkg/projectfile" @@ -57,6 +57,9 @@ func New(cfg *config.Instance, an *sync.Client, auth *authentication.Auth) (*Res upchecker := updater.NewDefaultChecker(cfg, an) pollUpdate := poller.New(1*time.Hour, func() (interface{}, error) { + defer func() { + panics.LogAndPanic(recover(), debug.Stack()) + }() logging.Debug("Poller checking for update info") return upchecker.CheckFor(constants.ChannelName, "") }) @@ -71,6 +74,9 @@ func New(cfg *config.Instance, an *sync.Client, auth *authentication.Auth) (*Res } pollAuth := poller.New(time.Duration(int64(time.Millisecond)*pollRate), func() (interface{}, error) { + defer func() { + panics.LogAndPanic(recover(), debug.Stack()) + }() if auth.SyncRequired() { return nil, auth.Sync() } @@ -110,7 +116,7 @@ func (r *Resolver) Query() genserver.QueryResolver { return r } func (r *Resolver) Mutation() genserver.MutationResolver { return r } func (r *Resolver) Version(ctx context.Context) (*graph.Version, error) { - defer func() { handlePanics(recover(), debug.Stack()) }() + defer func() { panics.LogAndPanic(recover(), debug.Stack()) }() r.an.EventWithLabel(anaConsts.CatStateSvc, "endpoint", "Version") logging.Debug("Version resolver") @@ -126,7 +132,7 @@ func (r *Resolver) Version(ctx context.Context) (*graph.Version, error) { } func (r *Resolver) AvailableUpdate(ctx context.Context, desiredChannel, desiredVersion string) (*graph.AvailableUpdate, error) { - defer func() { handlePanics(recover(), debug.Stack()) }() + defer func() { panics.LogAndPanic(recover(), debug.Stack()) }() if desiredChannel == "" { desiredChannel = constants.ChannelName @@ -174,7 +180,7 @@ func (r *Resolver) AvailableUpdate(ctx context.Context, desiredChannel, desiredV } func (r *Resolver) Projects(ctx context.Context) ([]*graph.Project, error) { - defer func() { handlePanics(recover(), debug.Stack()) }() + defer func() { panics.LogAndPanic(recover(), debug.Stack()) }() r.an.EventWithLabel(anaConsts.CatStateSvc, "endpoint", "Projects") logging.Debug("Projects resolver") @@ -194,7 +200,7 @@ func (r *Resolver) Projects(ctx context.Context) ([]*graph.Project, error) { } func (r *Resolver) AnalyticsEvent(_ context.Context, category, action, source string, _label *string, dimensionsJson string) (*graph.AnalyticsEventResponse, error) { - defer func() { handlePanics(recover(), debug.Stack()) }() + defer func() { panics.LogAndPanic(recover(), debug.Stack()) }() logging.Debug("Analytics event resolver: %s - %s: %s (%s)", category, action, ptr.From(_label, "NIL"), source) @@ -228,7 +234,7 @@ func (r *Resolver) AnalyticsEvent(_ context.Context, category, action, source st } func (r *Resolver) ReportRuntimeUsage(_ context.Context, pid int, exec, source string, dimensionsJSON string) (*graph.ReportRuntimeUsageResponse, error) { - defer func() { handlePanics(recover(), debug.Stack()) }() + defer func() { panics.LogAndPanic(recover(), debug.Stack()) }() logging.Debug("Runtime usage resolver: %d - %s", pid, exec) var dims *dimensions.Values @@ -242,26 +248,26 @@ func (r *Resolver) ReportRuntimeUsage(_ context.Context, pid int, exec, source s } func (r *Resolver) CheckMessages(ctx context.Context, command string, flags []string) ([]*graph.MessageInfo, error) { - defer func() { handlePanics(recover(), debug.Stack()) }() + defer func() { panics.LogAndPanic(recover(), debug.Stack()) }() logging.Debug("Check messages resolver") return r.messages.Check(command, flags) } func (r *Resolver) ConfigChanged(ctx context.Context, key string) (*graph.ConfigChangedResponse, error) { - defer func() { handlePanics(recover(), debug.Stack()) }() + defer func() { panics.LogAndPanic(recover(), debug.Stack()) }() go configMediator.NotifyListeners(key) return &graph.ConfigChangedResponse{Received: true}, nil } func (r *Resolver) FetchLogTail(ctx context.Context) (string, error) { - defer func() { handlePanics(recover(), debug.Stack()) }() + defer func() { panics.LogAndPanic(recover(), debug.Stack()) }() return logging.ReadTail(), nil } func (r *Resolver) GetProcessesInUse(ctx context.Context, execDir string) ([]*graph.ProcessInfo, error) { - defer func() { handlePanics(recover(), debug.Stack()) }() + defer func() { panics.LogAndPanic(recover(), debug.Stack()) }() inUse := r.rtwatch.GetProcessesInUse(execDir) processes := make([]*graph.ProcessInfo, 0, len(inUse)) @@ -272,7 +278,7 @@ func (r *Resolver) GetProcessesInUse(ctx context.Context, execDir string) ([]*gr } func (r *Resolver) GetJwt(ctx context.Context) (*graph.Jwt, error) { - defer func() { handlePanics(recover(), debug.Stack()) }() + defer func() { panics.LogAndPanic(recover(), debug.Stack()) }() if err := r.auth.MaybeRenew(); err != nil { return nil, errs.Wrap(err, "Could not renew auth token") @@ -308,7 +314,7 @@ func (r *Resolver) GetJwt(ctx context.Context) (*graph.Jwt, error) { } func (r *Resolver) HashGlobs(ctx context.Context, wd string, globs []string) (*graph.GlobResult, error) { - defer func() { handlePanics(recover(), debug.Stack()) }() + defer func() { panics.LogAndPanic(recover(), debug.Stack()) }() hash, files, err := r.fileHasher.HashFiles(wd, globs) if err != nil { @@ -341,11 +347,3 @@ func (r *Resolver) SetCache(ctx context.Context, key string, value string, expir r.globalCache.Set(key, value, time.Duration(expiry)*time.Second) return &graphqltypes.Void{}, nil } - -func handlePanics(recovered interface{}, stack []byte) { - if recovered != nil { - multilog.Error("Panic: %v", recovered) - logging.Debug("Stack: %s", string(stack)) - panic(recovered) // We're only logging the panic, not interrupting it - } -} diff --git a/internal/runbits/panics/panics.go b/internal/runbits/panics/panics.go index 7dd3f3fc5f..d743f7a5e8 100644 --- a/internal/runbits/panics/panics.go +++ b/internal/runbits/panics/panics.go @@ -34,3 +34,12 @@ func LogPanics(recovered interface{}, stack []byte) bool { } return false } + +// LogAndPanic produces actionable output for panic events (that shouldn't happen) and panics +func LogAndPanic(recovered interface{}, stack []byte) { + if recovered != nil { + multilog.Error("Panic: %v", recovered) + logging.Debug("Stack: %s", string(stack)) + panic(recovered) // We're only logging the panic, not interrupting it + } +}