Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

✨ Improve startup logs #1687

Merged
merged 1 commit into from Oct 11, 2021
Merged

✨ Improve startup logs #1687

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
4 changes: 2 additions & 2 deletions pkg/builder/webhook.go
View file
Open in desktop
Expand Up @@ -132,14 +132,14 @@ func (blder *WebhookBuilder) registerValidatingWebhook() {
func (blder *WebhookBuilder) registerConversionWebhook() error {
ok, err := conversion.IsConvertible(blder.mgr.GetScheme(), blder.apiType)
if err != nil {
log.Error(err, "conversion check failed", "object", blder.apiType)
log.Error(err, "conversion check failed", "GVK", blder.gvk)
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

apiType is usually just an empty API type (e.g. https://github.com/kubernetes-sigs/cluster-api/blob/f4380fc82fa2eef5119967d9bfea9d428e103e76/api/v1beta1/cluster_webhook.go#L34-L38)
So it's better to log gvk

We're also doing it already for the other webhooks, e.g. l.125

return err
}
if ok {
if !blder.isAlreadyHandled("/convert") {
blder.mgr.GetWebhookServer().Register("/convert", &conversion.Webhook{})
}
log.Info("conversion webhook enabled", "object", blder.apiType)
log.Info("Conversion webhook enabled", "GVK", blder.gvk)
}

return nil
Expand Down
2 changes: 1 addition & 1 deletion pkg/internal/controller/controller.go
View file
Open in desktop
Expand Up @@ -175,7 +175,7 @@ func (c *Controller) Start(ctx context.Context) error {
// caches to sync so that they have a chance to register their intendeded
// caches.
for _, watch := range c.startWatches {
c.Log.Info("Starting EventSource", "source", watch.src)
c.Log.Info("Starting EventSource", "source", fmt.Sprintf("%s", watch.src))
Copy link
Member Author

@sbueringer sbueringer Oct 7, 2021 •
edited

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Otherwise the String() func is not called and instead the watch.src is logged, which is again mostly an empty api struct (link). Which looks roughly like that:

I1007 16:29:17.183304       1 controller.go:178] controller/machinehealthcheck "msg"="Starting EventSource" "reconciler group"="cluster.x-k8s.io" "reconciler kind"="MachineHealthCheck" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","selector":{},"unhealthyConditions":null},"status":{"expectedMachines":0,"currentHealthy":0,"remediationsAllowed":0}}}

https://storage.googleapis.com/kubernetes-jenkins/logs/periodic-cluster-api-e2e-main/1446148448939151360/artifacts/clusters/bootstrap/controllers/capi-controller-manager/capi-controller-manager-77b95c5bc7-xrdd4/manager.log

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Interesting, I would have expected the logger to call .String() if it is implemented. Maybe get rid of the fmt.Sprintf anduse just watch.src.String()?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That was my first thought. But as String() is not part of the source.Source interface it's not possible without a cast (or adding it to the interface).


if err := watch.src.Start(ctx, watch.handler, c.Queue, watch.predicates...); err != nil {
return err
Expand Down
2 changes: 1 addition & 1 deletion pkg/manager/internal.go
View file
Open in desktop
Expand Up @@ -380,7 +380,7 @@ func (cm *controllerManager) serveMetrics() {
}
// Run the server
cm.startRunnable(RunnableFunc(func(_ context.Context) error {
cm.logger.Info("starting metrics server", "path", defaultMetricsEndpoint)
cm.logger.Info("Starting metrics server", "path", defaultMetricsEndpoint)
if err := server.Serve(cm.metricsListener); err != nil && err != http.ErrServerClosed {
return err
}
Expand Down
2 changes: 1 addition & 1 deletion pkg/metrics/listener.go
View file
Open in desktop
Expand Up @@ -41,7 +41,7 @@ func NewListener(addr string) (net.Listener, error) {
return nil, nil
}

log.Info("metrics server is starting to listen", "addr", addr)
log.Info("Metrics server is starting to listen", "addr", addr)
ln, err := net.Listen("tcp", addr)
if err != nil {
er := fmt.Errorf("error listening on %s: %w", addr, err)
Expand Down
6 changes: 3 additions & 3 deletions pkg/source/source.go
View file
Open in desktop
Expand Up @@ -142,10 +142,10 @@ func (ks *Kind) Start(ctx context.Context, handler handler.EventHandler, queue w
}

func (ks *Kind) String() string {
if ks.Type != nil && ks.Type.GetObjectKind() != nil {
return fmt.Sprintf("kind source: %v", ks.Type.GetObjectKind().GroupVersionKind().String())
if ks.Type != nil {
Copy link
Member Author

@sbueringer sbueringer Oct 7, 2021 •
edited

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Assuming that source.Kind is usually created with an empty struct like here there is in ObjectKind but it's empty. So this would look something like this kind source: .

So if we don't want to look up the gvk via the struct, the best we can do is simply log the Go type.

return fmt.Sprintf("kind source: %T", ks.Type)
}
return "kind source: unknown GVK"
return "kind source: unknown type"
}

// WaitForSync implements SyncingSource to allow controllers to wait with starting
Expand Down
6 changes: 3 additions & 3 deletions pkg/webhook/server.go
View file
Open in desktop
Expand Up @@ -142,7 +142,7 @@ func (s *Server) Register(path string, hook http.Handler) {
s.WebhookMux.Handle(path, metrics.InstrumentedHook(path, hook))

regLog := log.WithValues("path", path)
regLog.Info("registering webhook")
regLog.Info("Registering webhook")

// we've already been "started", inject dependencies here.
// Otherwise, InjectFunc will do this for us later.
Expand Down Expand Up @@ -210,7 +210,7 @@ func (s *Server) Start(ctx context.Context) error {
s.defaultingOnce.Do(s.setDefaults)

baseHookLog := log.WithName("webhooks")
baseHookLog.Info("starting webhook server")
baseHookLog.Info("Starting webhook server")

certPath := filepath.Join(s.CertDir, s.CertName)
keyPath := filepath.Join(s.CertDir, s.KeyName)
Expand Down Expand Up @@ -259,7 +259,7 @@ func (s *Server) Start(ctx context.Context) error {
return err
}

log.Info("serving webhook server", "host", s.Host, "port", s.Port)
log.Info("Serving webhook server", "host", s.Host, "port", s.Port)

srv := &http.Server{
Handler: s.WebhookMux,
Expand Down