From 198b68d3bdccbcf61cfadbbf459b28a1ac23509c Mon Sep 17 00:00:00 2001 From: gabe Date: Tue, 9 Apr 2024 18:21:02 -0400 Subject: [PATCH] contextual logging --- impl/cmd/main.go | 13 +++++-------- impl/pkg/dht/dht.go | 4 ++-- impl/pkg/server/util.go | 2 +- impl/pkg/service/pkarr.go | 18 +++++++++--------- impl/pkg/storage/db/bolt/bolt.go | 6 +++--- impl/pkg/storage/db/postgres/postgres.go | 2 +- 6 files changed, 21 insertions(+), 24 deletions(-) diff --git a/impl/cmd/main.go b/impl/cmd/main.go index d15265ec..0a20fcb1 100644 --- a/impl/cmd/main.go +++ b/impl/cmd/main.go @@ -31,10 +31,7 @@ import ( // @license.name Apache 2.0 // @license.url http://www.apache.org/licenses/LICENSE-2.0.html func main() { - logrus.SetFormatter(&logrus.JSONFormatter{ - DisableTimestamp: false, - PrettyPrint: true, - }) + logrus.SetFormatter(&logrus.JSONFormatter{}) logrus.SetReportCaller(true) log := logrus.NewEntry(logrus.StandardLogger()).WithField("version", config.Version) @@ -59,10 +56,10 @@ func run() error { configPath = envConfigPath } - logrus.WithField("path", configPath).Info("loading config from file") + logrus.WithContext(ctx).WithField("path", configPath).Info("loading config from file") cfg, err := config.LoadConfig(configPath) if err != nil { - logrus.Fatalf("could not instantiate config: %s", err.Error()) + logrus.WithContext(ctx).Fatalf("could not instantiate config: %s", err.Error()) } // set up logger @@ -91,7 +88,7 @@ func run() error { serverErrors := make(chan error, 1) go func() { - logrus.WithField("listen_address", s.Addr).Info("starting listener") + logrus.WithContext(ctx).WithField("listen_address", s.Addr).Info("starting listener") serverErrors <- s.ListenAndServe() }() @@ -99,7 +96,7 @@ func run() error { case err = <-serverErrors: return errors.Wrap(err, "server error") case sig := <-shutdown: - logrus.WithField("signal", sig.String()).Info("shutdown signal received") + logrus.WithContext(ctx).WithField("signal", sig.String()).Info("shutdown signal received") ctx, cancel := context.WithTimeout(context.Background(), time.Second*5) defer cancel() diff --git a/impl/pkg/dht/dht.go b/impl/pkg/dht/dht.go index b3a68932..43d5074a 100644 --- a/impl/pkg/dht/dht.go +++ b/impl/pkg/dht/dht.go @@ -88,7 +88,7 @@ func (d *DHT) Put(ctx context.Context, request bep44.Put) (string, error) { // Check if there are any nodes in the DHT if len(d.Server.Nodes()) == 0 { - logrus.Warn("no nodes available in the DHT for publishing") + logrus.WithContext(ctx).Warn("no nodes available in the DHT for publishing") } key := util.Z32Encode(request.K[:]) @@ -101,7 +101,7 @@ func (d *DHT) Put(ctx context.Context, request bep44.Put) (string, error) { } return "", errutil.LoggingNewErrorf("failed to put key[%s] into dht, tried %d nodes, got %d responses", key, t.NumAddrsTried, t.NumResponses) } else { - logrus.WithField("key", key).Debug("successfully put key into dht") + logrus.WithContext(ctx).WithField("key", key).Debug("successfully put key into dht") } return util.Z32Encode(request.K[:]), nil } diff --git a/impl/pkg/server/util.go b/impl/pkg/server/util.go index 2e6bcb4d..ee447f41 100644 --- a/impl/pkg/server/util.go +++ b/impl/pkg/server/util.go @@ -46,7 +46,7 @@ func RespondBytes(c *gin.Context, data []byte, statusCode int) { // LoggingRespondError sends an error response back to the client as a safe error func LoggingRespondError(c *gin.Context, err error, statusCode int) { - logrus.WithError(err).Error() + logrus.WithContext(c).WithError(err).Error() Respond(c, err, statusCode) } diff --git a/impl/pkg/service/pkarr.go b/impl/pkg/service/pkarr.go index 7f198c3d..274a85ab 100644 --- a/impl/pkg/service/pkarr.go +++ b/impl/pkg/service/pkarr.go @@ -76,7 +76,7 @@ func (s *PkarrService) PublishPkarr(ctx context.Context, id string, record pkarr if got, err := s.cache.Get(id); err == nil { var resp pkarr.Response if err = json.Unmarshal(got, &resp); err == nil && record.Response().Equals(resp) { - logrus.WithField("record_id", id).Debug("resolved pkarr record from cache with matching response") + logrus.WithContext(ctx).WithField("record_id", id).Debug("resolved pkarr record from cache with matching response") return nil } } @@ -101,7 +101,7 @@ func (s *PkarrService) PublishPkarr(ctx context.Context, id string, record pkarr defer cancel() if _, err = s.dht.Put(putCtx, record.BEP44()); err != nil { - logrus.WithError(err).Errorf("error from dht.Put for record: %s", id) + logrus.WithContext(ctx).WithError(err).Errorf("error from dht.Put for record: %s", id) } }() @@ -117,17 +117,17 @@ func (s *PkarrService) GetPkarr(ctx context.Context, id string) (*pkarr.Response if got, err := s.cache.Get(id); err == nil { var resp pkarr.Response if err = json.Unmarshal(got, &resp); err == nil { - logrus.WithField("record_id", id).Debug("resolved pkarr record from cache") + logrus.WithContext(ctx).WithField("record_id", id).Debug("resolved pkarr record from cache") return &resp, nil } - logrus.WithError(err).WithField("record", id).Warn("failed to get pkarr record from cache, falling back to dht") + logrus.WithContext(ctx).WithError(err).WithField("record", id).Warn("failed to get pkarr record from cache, falling back to dht") } // next do a dht lookup got, err := s.dht.GetFull(ctx, id) if err != nil { // try to resolve from storage before returning and error - logrus.WithError(err).WithField("record", id).Warn("failed to get pkarr record from dht, attempting to resolve from storage") + logrus.WithContext(ctx).WithError(err).WithField("record", id).Warn("failed to get pkarr record from dht, attempting to resolve from storage") rawID, err := util.Z32Decode(id) if err != nil { @@ -136,11 +136,11 @@ func (s *PkarrService) GetPkarr(ctx context.Context, id string) (*pkarr.Response record, err := s.db.ReadRecord(ctx, rawID) if err != nil || record == nil { - logrus.WithError(err).WithField("record", id).Error("failed to resolve pkarr record from storage") + logrus.WithContext(ctx).WithError(err).WithField("record", id).Error("failed to resolve pkarr record from storage") return nil, err } - logrus.WithField("record", id).Debug("resolved pkarr record from storage") + logrus.WithContext(ctx).WithField("record", id).Debug("resolved pkarr record from storage") resp := record.Response() if err = s.addRecordToCache(id, record.Response()); err != nil { logrus.WithError(err).WithField("record", id).Error("failed to set pkarr record in cache") @@ -166,7 +166,7 @@ func (s *PkarrService) GetPkarr(ctx context.Context, id string) (*pkarr.Response // add the record to cache, do it here to avoid duplicate calculations if err = s.addRecordToCache(id, resp); err != nil { - logrus.WithError(err).Errorf("failed to set pkarr record[%s] in cache", id) + logrus.WithContext(ctx).WithError(err).Errorf("failed to set pkarr record[%s] in cache", id) } return &resp, nil @@ -206,7 +206,7 @@ func (s *PkarrService) republish() { } if len(allRecords) == 0 { - logrus.Info("No records to republish") + logrus.Info("no records to republish") return } diff --git a/impl/pkg/storage/db/bolt/bolt.go b/impl/pkg/storage/db/bolt/bolt.go index 54d5ec10..19dc100c 100644 --- a/impl/pkg/storage/db/bolt/bolt.go +++ b/impl/pkg/storage/db/bolt/bolt.go @@ -141,7 +141,7 @@ func (b *Bolt) read(ctx context.Context, namespace, key string) ([]byte, error) err := b.db.View(func(tx *bolt.Tx) error { bucket := tx.Bucket([]byte(namespace)) if bucket == nil { - logrus.WithField("namespace", namespace).Info("namespace does not exist") + logrus.WithContext(ctx).WithField("namespace", namespace).Info("namespace does not exist") return nil } result = bucket.Get([]byte(key)) @@ -175,7 +175,7 @@ func (b *Bolt) readSeveral(ctx context.Context, namespace string, after []byte, err := b.db.View(func(tx *bolt.Tx) error { bucket := tx.Bucket([]byte(namespace)) if bucket == nil { - logrus.WithField("namespace", namespace).Warn("namespace does not exist") + logrus.WithContext(ctx).WithField("namespace", namespace).Warn("namespace does not exist") return nil } @@ -210,7 +210,7 @@ func (b *Bolt) RecordCount(ctx context.Context) (int, error) { err := b.db.View(func(tx *bolt.Tx) error { bucket := tx.Bucket([]byte(pkarrNamespace)) if bucket == nil { - logrus.WithField("namespace", pkarrNamespace).Warn("namespace does not exist") + logrus.WithContext(ctx).WithField("namespace", pkarrNamespace).Warn("namespace does not exist") return nil } count = bucket.Stats().KeyN diff --git a/impl/pkg/storage/db/postgres/postgres.go b/impl/pkg/storage/db/postgres/postgres.go index 7d3872a5..bd41e684 100644 --- a/impl/pkg/storage/db/postgres/postgres.go +++ b/impl/pkg/storage/db/postgres/postgres.go @@ -135,7 +135,7 @@ func (p Postgres) ListRecords(ctx context.Context, nextPageToken []byte, limit i record, err := pkarr.NewRecord(row.Key, row.Value, row.Sig, row.Seq) if err != nil { // TODO: do something useful if this happens - logrus.WithError(err).WithField("record_id", row.ID).Warn("error loading record from database, skipping") + logrus.WithContext(ctx).WithError(err).WithField("record_id", row.ID).Warn("error loading record from database, skipping") continue }