From 5b6697808f3ab87d4f2a6302e5b50742020eb685 Mon Sep 17 00:00:00 2001 From: Timon Engelke Date: Wed, 18 Dec 2024 16:28:59 +0100 Subject: [PATCH] logging: make default logging less verbose, add useful logs --- cmd/calendarsync/main.go | 11 +++++++---- internal/adapter/google/adapter.go | 4 ++-- internal/adapter/outlook_http/adapter.go | 4 ++-- internal/adapter/zep/client.go | 9 +++++++++ internal/sync/controller.go | 7 ++++--- 5 files changed, 24 insertions(+), 11 deletions(-) diff --git a/cmd/calendarsync/main.go b/cmd/calendarsync/main.go index 7275768..332767b 100644 --- a/cmd/calendarsync/main.go +++ b/cmd/calendarsync/main.go @@ -102,6 +102,8 @@ func main() { } func Run(c *cli.Context) error { + log.Info("started calendarsync") + if c.Bool(flagVersion) { fmt.Println("Version:", Version) os.Exit(0) @@ -111,7 +113,7 @@ func Run(c *cli.Context) error { if err != nil { return err } - log.Info("loaded config file", "path", cfg.Path) + log.Debug("loaded config file", "path", cfg.Path) if len(c.String(flagStorageEncryptionKey)) > 0 { log.Warn("Parsing the encryption key using the flag is deprecated. Please use the environment variable $CALENDARSYNC_ENCRYPTION_KEY instead.") @@ -163,7 +165,7 @@ func Run(c *cli.Context) error { if err != nil { return err } - log.Info("loaded source adapter", "adapter", cfg.Source.Adapter.Type, "calendar", cfg.Source.Adapter.Calendar) + log.Debug("loaded source adapter", "adapter", cfg.Source.Adapter.Type, "calendar", cfg.Source.Adapter.Calendar) sinkLogger := log.With("adapter", cfg.Sink.Adapter.Type, "type", "sink") @@ -178,7 +180,7 @@ func Run(c *cli.Context) error { if err != nil { return err } - log.Info("loaded sink adapter", "adapter", cfg.Sink.Adapter.Type, "calendar", cfg.Sink.Adapter.Calendar) + log.Debug("loaded sink adapter", "adapter", cfg.Sink.Adapter.Type, "calendar", cfg.Sink.Adapter.Calendar) if log.GetLevel() == log.DebugLevel { for _, transformation := range cfg.Transformations { @@ -190,7 +192,7 @@ func Run(c *cli.Context) error { if cfg.UpdateConcurrency != 0 { controller.SetConcurrency(cfg.UpdateConcurrency) } - log.Info("loaded sync controller") + log.Debug("loaded sync controller") if c.Bool("clean") { err = controller.CleanUp(c.Context, startTime, endTime) @@ -204,5 +206,6 @@ func Run(c *cli.Context) error { log.Fatalf("we had some errors during synchronization:\n%v", err) } } + log.Info("sync complete") return nil } diff --git a/internal/adapter/google/adapter.go b/internal/adapter/google/adapter.go index 13af05f..8023335 100644 --- a/internal/adapter/google/adapter.go +++ b/internal/adapter/google/adapter.go @@ -94,7 +94,7 @@ func (c *CalendarAPI) SetupOauth2(ctx context.Context, credentials auth.Credenti } c.authenticated = true - c.logger.Info("using stored credentials") + c.logger.Debug("using stored credentials") } return nil @@ -178,7 +178,7 @@ func (c *CalendarAPI) EventsInTimeframe(ctx context.Context, start time.Time, en return nil, err } - c.logger.Infof("loaded %d events between %s and %s.", len(events), start.Format(time.RFC1123), end.Format(time.RFC1123)) + c.logger.Infof("loaded %d events between %s and %s.", len(events), start.Format(time.DateOnly), end.Format(time.DateOnly)) return events, nil } diff --git a/internal/adapter/outlook_http/adapter.go b/internal/adapter/outlook_http/adapter.go index f343d83..815c5ab 100644 --- a/internal/adapter/outlook_http/adapter.go +++ b/internal/adapter/outlook_http/adapter.go @@ -154,7 +154,7 @@ func (c *CalendarAPI) SetupOauth2(ctx context.Context, credentials auth.Credenti } c.authenticated = true - c.logger.Info("using stored credentials") + c.logger.Debug("using stored credentials") c.logger.Debugf("expiry time of stored token: %s", expiry.String()) } @@ -207,7 +207,7 @@ func (c *CalendarAPI) EventsInTimeframe(ctx context.Context, start time.Time, en return nil, err } - c.logger.Infof("loaded %d events between %s and %s.", len(events), start.Format(time.RFC1123), end.Format(time.RFC1123)) + c.logger.Infof("loaded %d events between %s and %s.", len(events), start.Format(time.DateOnly), end.Format(time.DateOnly)) return events, nil } diff --git a/internal/adapter/zep/client.go b/internal/adapter/zep/client.go index 65cbff5..177db2a 100644 --- a/internal/adapter/zep/client.go +++ b/internal/adapter/zep/client.go @@ -32,6 +32,7 @@ type CalendarAPI struct { client *caldav.Client calendarID string + logger *log.Logger principal string homeSet string @@ -39,6 +40,7 @@ type CalendarAPI struct { // Assert that the expected interfaces are implemented var _ port.Configurable = &CalendarAPI{} +var _ port.LogSetter = &CalendarAPI{} func (zep *CalendarAPI) GetCalendarID() string { return zep.generateCalendarID() @@ -100,6 +102,9 @@ func (zep *CalendarAPI) EventsInTimeframe(ctx context.Context, start time.Time, } var syncEvents []models.Event + + zep.logger.Infof("loaded %d events between %s and %s.", len(absences), start.Format(time.DateOnly), end.Format(time.DateOnly)) + for _, v := range absences { syncEvents = append(syncEvents, models.Event{ @@ -209,3 +214,7 @@ func safeGetComponentPropValueString(event ical.Event, key string) string { } return prop.Value } + +func (zep *CalendarAPI) SetLogger(logger *log.Logger) { + zep.logger = logger +} diff --git a/internal/sync/controller.go b/internal/sync/controller.go index c83473d..24adbc1 100644 --- a/internal/sync/controller.go +++ b/internal/sync/controller.go @@ -80,7 +80,7 @@ func (p Controller) SynchroniseTimeframe(ctx context.Context, start time.Time, e filteredEventsInSource := []models.Event{} for _, filter := range p.filters { - p.logger.Info("loaded filter", "name", filter.Name()) + p.logger.Debug("loaded filter", "name", filter.Name()) } for _, event := range eventsInSource { @@ -96,7 +96,7 @@ func (p Controller) SynchroniseTimeframe(ctx context.Context, start time.Time, e // Output which transformers were loaded for _, trans := range p.transformers { - p.logger.Info("loaded transformer", "name", trans.Name()) + p.logger.Debug("loaded transformer", "name", trans.Name()) } for _, event := range filteredEventsInSource { @@ -104,6 +104,7 @@ func (p Controller) SynchroniseTimeframe(ctx context.Context, start time.Time, e } toCreate, toUpdate, toDelete := p.diffEvents(transformedEventsInSource, eventsInSink) + log.Infof("found %d new, %d changed, and %d deleted events", len(toCreate), len(toUpdate), len(toDelete)) if dryRun { p.logger.Warn("we're running in dry run mode, no changes will be executed") return nil @@ -200,7 +201,7 @@ func (p Controller) diffEvents(sourceEvents []models.Event, sinkEvents []models. // - Delete event (in calendar A) // - Run sync from calendar B to calendar A. This will copy (and thereby resurrect) the event. // - // Solution: Ignore events the originate from the sink, but no longer exist there. + // Solution: Ignore events that originate from the sink, but no longer exist there. if event.Metadata.SourceID == p.sink.GetCalendarID() { p.logger.Info("skipping event as it originates from the sink, but no longer exists there", logFields(event)...) continue