From 3a0cdb5e29046e09d13ed104601cf5b4de994d40 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?And=C5=BEej=20Maciusovi=C4=8D?= Date: Thu, 25 Nov 2021 15:48:25 +0200 Subject: [PATCH] feat: improve logging (#10) --- actions/actions.go | 18 ++++++++--------- castai/client.go | 7 +++++-- config/version.go | 4 ++-- hack/remote/deploy.sh | 7 ++++--- hack/remote/setup.sh | 2 +- main.go | 43 ++++++++++++++++++++++++----------------- version/version.go | 5 +---- version/version_test.go | 3 +-- 8 files changed, 48 insertions(+), 41 deletions(-) diff --git a/actions/actions.go b/actions/actions.go index ac3758ff..47b2a53d 100644 --- a/actions/actions.go +++ b/actions/actions.go @@ -24,7 +24,7 @@ type Config struct { } type Service interface { - Run(ctx context.Context) + Run(ctx context.Context) error } type ActionHandler interface { @@ -58,29 +58,29 @@ type service struct { actionHandlers map[reflect.Type]ActionHandler } -func (s *service) Run(ctx context.Context) { +func (s *service) Run(ctx context.Context) error { for { select { case <-time.After(s.cfg.PollWaitInterval): err := s.doWork(ctx) if err != nil { if errors.Is(err, context.Canceled) { - s.log.Debug("actions service stopped") - return + s.log.Info("service stopped") + return nil } s.log.Errorf("cycle failed: %v", err) continue } case <-ctx.Done(): - s.log.Debug("actions service stopped") - return + s.log.Info("service stopped") + return nil } } } func (s *service) doWork(ctx context.Context) error { - s.log.Debug("polling actions") + s.log.Info("polling actions") start := time.Now() actions, err := s.pollActions(ctx) if err != nil { @@ -89,11 +89,11 @@ func (s *service) doWork(ctx context.Context) error { pollDuration := time.Now().Sub(start) if len(actions) == 0 { - s.log.Debugf("no actions returned in %s", pollDuration) + s.log.Infof("no actions returned in %s", pollDuration) return nil } - s.log.Debugf("received %d actions in %s", len(actions), pollDuration) + s.log.Infof("received %d actions in %s", len(actions), pollDuration) if err := s.handleActions(ctx, actions); err != nil { return fmt.Errorf("handling actions: %w", err) } diff --git a/castai/client.go b/castai/client.go index 0a74a38d..cc6fa080 100644 --- a/castai/client.go +++ b/castai/client.go @@ -4,10 +4,12 @@ import ( "context" "fmt" "net/http" + "time" - "github.com/castai/cluster-controller/config" "github.com/go-resty/resty/v2" "github.com/sirupsen/logrus" + + "github.com/castai/cluster-controller/config" ) const ( @@ -30,9 +32,10 @@ func NewClient(log *logrus.Logger, rest *resty.Client, clusterID string) Client } // NewDefaultClient configures a default instance of the resty.Client used to do HTTP requests. -func NewDefaultClient(url, key string, level logrus.Level, binVersion *config.AgentActionsVersion) *resty.Client { +func NewDefaultClient(url, key string, level logrus.Level, binVersion *config.ClusterControllerVersion) *resty.Client { client := resty.New() client.SetHostURL(url) + client.SetTimeout(5 * time.Minute) // Hard timeout for any request. client.Header.Set(http.CanonicalHeaderKey(headerAPIKey), key) client.Header.Set(http.CanonicalHeaderKey(headerUserAgent), "castai-cluster-controller/"+binVersion.Version) if level == logrus.TraceLevel { diff --git a/config/version.go b/config/version.go index e8d73190..15a73bb8 100644 --- a/config/version.go +++ b/config/version.go @@ -2,10 +2,10 @@ package config import "fmt" -type AgentActionsVersion struct { +type ClusterControllerVersion struct { GitCommit, GitRef, Version string } -func (a *AgentActionsVersion) String() string { +func (a *ClusterControllerVersion) String() string { return fmt.Sprintf("GitCommit=%q GitRef=%q Version=%q", a.GitCommit, a.GitRef, a.Version) } diff --git a/hack/remote/deploy.sh b/hack/remote/deploy.sh index a39724a6..2e645e6b 100755 --- a/hack/remote/deploy.sh +++ b/hack/remote/deploy.sh @@ -23,8 +23,9 @@ cd "$(git rev-parse --show-toplevel)" GOOS=linux go build -o bin/castai-cluster-controller . DOCKER_IMAGE_REPO=europe-west3-docker.pkg.dev/ci-master-mo3d/tilt/$USER/castai-cluster-controller -docker build -t $DOCKER_IMAGE_REPO:latest . -docker push $DOCKER_IMAGE_REPO:latest +IMAGE_TAG=latest +docker build -t $DOCKER_IMAGE_REPO:$IMAGE_TAG . +docker push $DOCKER_IMAGE_REPO:$IMAGE_TAG helm template cluster-controller castai-helm/castai-cluster-controller \ -f ./hack/remote/values.yaml \ @@ -33,4 +34,4 @@ helm template cluster-controller castai-helm/castai-cluster-controller \ --set apiURL="$API_URL" \ --set clusterID="$CLUSTER_ID" | kubectl apply -f - -n castai-agent -kubectl rollout restart deployment castai-cluster-controller -n castai-agent \ No newline at end of file +kubectl rollout restart deployment castai-cluster-controller -n castai-agent diff --git a/hack/remote/setup.sh b/hack/remote/setup.sh index aa373cc2..edaeb35e 100755 --- a/hack/remote/setup.sh +++ b/hack/remote/setup.sh @@ -11,4 +11,4 @@ helm repo add castai-helm https://castai.github.io/helm-charts helm repo update $DOCKER_SECRET_TMPL_PATH castai-agent | kubectl apply -f - -n castai-agent -kubectl patch serviceaccount castai-cluster-controller -p '{"imagePullSecrets": [{"name": "artifact-registry"}]}' \ No newline at end of file +kubectl patch serviceaccount castai-cluster-controller -p '{"imagePullSecrets": [{"name": "artifact-registry"}]}' -n castai-agent diff --git a/main.go b/main.go index 6819c998..8deb2105 100644 --- a/main.go +++ b/main.go @@ -31,7 +31,7 @@ var ( func main() { cfg := config.Get() - binVersion := &config.AgentActionsVersion{ + binVersion := &config.ClusterControllerVersion{ GitCommit: GitCommit, GitRef: GitRef, Version: Version, @@ -39,10 +39,6 @@ func main() { logger := logrus.New() logger.SetLevel(logrus.Level(cfg.Log.Level)) - logger.WithFields(logrus.Fields{ - "version": binVersion.Version, - }) - logger.Infof("running castai-cluster-controller version %v", binVersion) client := castai.NewClient( logger, @@ -51,7 +47,7 @@ func main() { ) log := logrus.WithFields(logrus.Fields{}) - if err := run(signals.SetupSignalHandler(), logger, client, logger, cfg); err != nil { + if err := run(signals.SetupSignalHandler(), client, logger, cfg, binVersion); err != nil { logErr := &logContextErr{} if errors.As(err, &logErr) { log = logger.WithFields(logErr.fields) @@ -60,14 +56,19 @@ func main() { } } -func run(ctx context.Context, log logrus.FieldLogger, client castai.Client, logger *logrus.Logger, cfg config.Config) (reterr error) { +func run( + ctx context.Context, + client castai.Client, + logger *logrus.Logger, + cfg config.Config, + binVersion *config.ClusterControllerVersion, +) (reterr error) { fields := logrus.Fields{} defer func() { if reterr == nil { return } - reterr = &logContextErr{ err: reterr, fields: fields, @@ -78,7 +79,7 @@ func run(ctx context.Context, log logrus.FieldLogger, client castai.Client, logg logger.AddHook(e) logrus.RegisterExitHandler(e.Wait) - restconfig, err := retrieveKubeConfig(log) + restconfig, err := retrieveKubeConfig(logger) if err != nil { return err } @@ -88,6 +89,17 @@ func run(ctx context.Context, log logrus.FieldLogger, client castai.Client, logg return err } + k8sVersion, err := version.Get(clientset) + if err != nil { + panic(fmt.Errorf("failed getting kubernetes version: %v", err)) + } + + log := logger.WithFields(logrus.Fields{ + "version": binVersion.Version, + "k8s_version": k8sVersion.Full(), + }) + log.Infof("running castai-cluster-controller version %v", binVersion) + if cfg.PprofPort != 0 { go func() { addr := fmt.Sprintf(":%d", cfg.PprofPort) @@ -98,14 +110,6 @@ func run(ctx context.Context, log logrus.FieldLogger, client castai.Client, logg }() } - v, err := version.Get(log, clientset) - if err != nil { - panic(fmt.Errorf("failed getting kubernetes version: %v", err)) - } - - fields["k8s_version"] = v.Full() - log = log.WithFields(fields) - actionsConfig := actions.Config{ PollWaitInterval: 5 * time.Second, PollTimeout: 5 * time.Minute, @@ -115,8 +119,11 @@ func run(ctx context.Context, log logrus.FieldLogger, client castai.Client, logg ClusterID: cfg.ClusterID, } svc := actions.NewService(log, actionsConfig, clientset, client) - svc.Run(ctx) + // Run action service. Blocks. + if err := svc.Run(ctx); err != nil && !errors.Is(err, context.Canceled) { + return err + } return nil } diff --git a/version/version.go b/version/version.go index 317cdb99..b9230dd1 100644 --- a/version/version.go +++ b/version/version.go @@ -6,7 +6,6 @@ import ( "regexp" "strconv" - "github.com/sirupsen/logrus" "k8s.io/apimachinery/pkg/version" "k8s.io/client-go/kubernetes" ) @@ -16,7 +15,7 @@ type Interface interface { MinorInt() int } -func Get(log logrus.FieldLogger, clientset kubernetes.Interface) (Interface, error) { +func Get(clientset kubernetes.Interface) (Interface, error) { cs, ok := clientset.(*kubernetes.Clientset) if !ok { return nil, fmt.Errorf("expected clientset to be of type *kubernetes.Clientset but was %T", clientset) @@ -27,8 +26,6 @@ func Get(log logrus.FieldLogger, clientset kubernetes.Interface) (Interface, err return nil, fmt.Errorf("getting server version: %w", err) } - log.Infof("kubernetes version %s.%s", sv.Major, sv.Minor) - m, err := strconv.Atoi(regexp.MustCompile(`^(\d+)`).FindString(sv.Minor)) if err != nil { return nil, fmt.Errorf("parsing minor version: %w", err) diff --git a/version/version_test.go b/version/version_test.go index 0c5720fc..f554954e 100644 --- a/version/version_test.go +++ b/version/version_test.go @@ -6,7 +6,6 @@ import ( "net/http/httptest" "testing" - "github.com/sirupsen/logrus" "github.com/stretchr/testify/require" "k8s.io/apimachinery/pkg/version" "k8s.io/client-go/kubernetes" @@ -33,7 +32,7 @@ func Test(t *testing.T) { defer s.Close() client := kubernetes.NewForConfigOrDie(&rest.Config{Host: s.URL}) - got, err := Get(logrus.New(), client) + got, err := Get(client) if err != nil { return }