From 6d78a008a1b33be7e12350b038e7bac346609b7e Mon Sep 17 00:00:00 2001 From: Adrian Lanzafame Date: Tue, 29 Oct 2019 18:21:21 +1000 Subject: [PATCH 1/2] remove deprecated log.Warning(f) Part of the work to unblock: https://github.com/ipfs/go-log/pull/65 --- bitswap.go | 2 +- go.mod | 17 ++++------------- go.sum | 9 +++++++++ messagequeue/messagequeue.go | 2 +- network/ipfs_impl.go | 4 ++-- testnet/virtual.go | 2 +- workers.go | 2 +- 7 files changed, 19 insertions(+), 19 deletions(-) diff --git a/bitswap.go b/bitswap.go index 93759802..c8ba82b5 100644 --- a/bitswap.go +++ b/bitswap.go @@ -392,7 +392,7 @@ func (bs *Bitswap) ReceiveMessage(ctx context.Context, p peer.ID, incoming bsmsg // Process blocks err := bs.receiveBlocksFrom(ctx, p, iblocks) if err != nil { - log.Warningf("ReceiveMessage recvBlockFrom error: %s", err) + log.Warnf("ReceiveMessage recvBlockFrom error: %s", err) return } } diff --git a/go.mod b/go.mod index 614c96cb..53fb6302 100644 --- a/go.mod +++ b/go.mod @@ -1,11 +1,8 @@ module github.com/ipfs/go-bitswap require ( - github.com/btcsuite/btcd v0.0.0-20190605094302-a0d1e3e36d50 // indirect github.com/cskr/pubsub v1.0.2 - github.com/davecgh/go-spew v1.1.1 // indirect github.com/gogo/protobuf v1.3.1 - github.com/golang/protobuf v1.3.1 // indirect github.com/google/uuid v1.1.1 github.com/ipfs/go-block-format v0.0.2 github.com/ipfs/go-cid v0.0.3 @@ -17,25 +14,19 @@ require ( github.com/ipfs/go-ipfs-exchange-interface v0.0.1 github.com/ipfs/go-ipfs-routing v0.1.0 github.com/ipfs/go-ipfs-util v0.0.1 - github.com/ipfs/go-log v0.0.1 + github.com/ipfs/go-log v0.0.2-0.20190920042044-a609c1ae5144 github.com/ipfs/go-metrics-interface v0.0.1 github.com/ipfs/go-peertaskqueue v0.1.1 github.com/jbenet/goprocess v0.1.3 github.com/libp2p/go-buffer-pool v0.0.2 github.com/libp2p/go-libp2p v0.4.0 - github.com/libp2p/go-libp2p-core v0.0.3 + github.com/libp2p/go-libp2p-core v0.2.3 github.com/libp2p/go-libp2p-loggables v0.1.0 github.com/libp2p/go-libp2p-netutil v0.1.0 - github.com/libp2p/go-libp2p-testing v0.0.4 + github.com/libp2p/go-libp2p-testing v0.1.0 github.com/libp2p/go-msgio v0.0.4 github.com/mattn/go-colorable v0.1.2 // indirect - github.com/multiformats/go-multiaddr v0.0.4 - github.com/opentracing/opentracing-go v1.1.0 // indirect - golang.org/x/crypto v0.0.0-20190611184440-5c40567a22f8 // indirect - golang.org/x/net v0.0.0-20190611141213-3f473d35a33a // indirect - golang.org/x/sys v0.0.0-20190610200419-93c9922d18ae // indirect - golang.org/x/text v0.3.2 // indirect - gopkg.in/yaml.v2 v2.2.2 // indirect + github.com/multiformats/go-multiaddr v0.1.1 ) go 1.12 diff --git a/go.sum b/go.sum index ed7333af..a34ea60d 100644 --- a/go.sum +++ b/go.sum @@ -128,6 +128,8 @@ github.com/ipfs/go-ipfs-util v0.0.1 h1:Wz9bL2wB2YBJqggkA4dD7oSmqB4cAnpNbGrlHJulv github.com/ipfs/go-ipfs-util v0.0.1/go.mod h1:spsl5z8KUnrve+73pOhSVZND1SIxPW5RyBCNzQxlJBc= github.com/ipfs/go-log v0.0.1 h1:9XTUN/rW64BCG1YhPK9Hoy3q8nr4gOmHHBpgFdfw6Lc= github.com/ipfs/go-log v0.0.1/go.mod h1:kL1d2/hzSpI0thNYjiKfjanbVNU+IIGA/WnNESY9leM= +github.com/ipfs/go-log v0.0.2-0.20190920042044-a609c1ae5144 h1:5WM8S1nwquWQ3zEuNhK82NE5Di6Pd41qz9JxxvxTAIA= +github.com/ipfs/go-log v0.0.2-0.20190920042044-a609c1ae5144/go.mod h1:azGN5dH7ailfREknDDNYB0Eq4qZ/4I4Y3gO0ivjJNyM= github.com/ipfs/go-metrics-interface v0.0.1 h1:j+cpbjYvu4R8zbleSs36gvB7jR+wsL2fGD6n0jO4kdg= github.com/ipfs/go-metrics-interface v0.0.1/go.mod h1:6s6euYU4zowdslK0GKHmqaIZ3j/b/tL7HTWtJ4VPgWY= github.com/ipfs/go-peertaskqueue v0.1.1 h1:+gPjbI+V3NktXZOqJA1kzbms2pYmhjgQQal0MzZrOAY= @@ -377,6 +379,7 @@ github.com/stretchr/objx v0.1.1/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+ github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= github.com/stretchr/testify v1.3.0 h1:TivCn/peBQ7UY8ooIcPgZFpTNSz0Q2U6UrFlUfqbe0Q= github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= +github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4= github.com/syndtr/goleveldb v1.0.0/go.mod h1:ZVVdQEZoIme9iO1Ch2Jdy24qqXrMMOU6lpPAyBWyWuQ= github.com/ugorji/go/codec v0.0.0-20181204163529-d75b2dcb6bc8/go.mod h1:VFNgLljTbGfSG7qAOspJ7OScBnGdDN/yBr0sguwnwf0= github.com/whyrusleeping/go-keyspace v0.0.0-20160322163242-5b898ac5add1/go.mod h1:8UvriyWtv5Q5EOgjHaSseUEdkQfvwFv1I/In/O2M9gc= @@ -395,6 +398,12 @@ github.com/xordataexchange/crypt v0.0.3-0.20170626215501-b2862e3d0a77/go.mod h1: go.opencensus.io v0.21.0/go.mod h1:mSImk1erAIZhrmZN+AvHh14ztQfjbGwt4TtuofqLduU= go.opencensus.io v0.22.1 h1:8dP3SGL7MPB94crU3bEPplMPe83FI4EouesJUeFHv50= go.opencensus.io v0.22.1/go.mod h1:Ap50jQcDJrx6rB6VgeeFPtuPIf3wMRvRfrfYDO6+BmA= +go.uber.org/atomic v1.4.0 h1:cxzIVoETapQEqDhQu3QfnvXAV4AlzcvUCxkVUFw3+EU= +go.uber.org/atomic v1.4.0/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE= +go.uber.org/multierr v1.1.0 h1:HoEmRHQPVSqub6w2z2d2EOVs2fjyFRGyofhKuyDq0QI= +go.uber.org/multierr v1.1.0/go.mod h1:wR5kodmAFQ0UK8QlbwjlSNy0Z68gJhDJUG5sjR94q/0= +go.uber.org/zap v1.10.0 h1:ORx85nbTijNz8ljznvCMR1ZBIPKFn3jQrag10X2AsuM= +go.uber.org/zap v1.10.0/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q= golang.org/x/crypto v0.0.0-20170930174604-9419663f5a44/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= golang.org/x/crypto v0.0.0-20180904163835-0709b304e793/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= golang.org/x/crypto v0.0.0-20181203042331-505ab145d0a9/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= diff --git a/messagequeue/messagequeue.go b/messagequeue/messagequeue.go index 601a7074..3c94663d 100644 --- a/messagequeue/messagequeue.go +++ b/messagequeue/messagequeue.go @@ -230,7 +230,7 @@ func (mq *MessageQueue) attemptSendAndRecovery(message bsmsg.BitSwapMessage) boo return true case <-time.After(time.Millisecond * 100): // wait 100ms in case disconnect notifications are still propogating - log.Warning("SendMsg errored but neither 'done' nor context.Done() were set") + log.Warn("SendMsg errored but neither 'done' nor context.Done() were set") } err = mq.initializeSender() diff --git a/network/ipfs_impl.go b/network/ipfs_impl.go index 036d1532..b8b8c271 100644 --- a/network/ipfs_impl.go +++ b/network/ipfs_impl.go @@ -85,7 +85,7 @@ func (bsnet *impl) msgToStream(ctx context.Context, s network.Stream, msg bsmsg. } if err := s.SetWriteDeadline(deadline); err != nil { - log.Warningf("error setting deadline: %s", err) + log.Warnf("error setting deadline: %s", err) } switch s.Protocol() { @@ -104,7 +104,7 @@ func (bsnet *impl) msgToStream(ctx context.Context, s network.Stream, msg bsmsg. } if err := s.SetWriteDeadline(time.Time{}); err != nil { - log.Warningf("error resetting deadline: %s", err) + log.Warnf("error resetting deadline: %s", err) } return nil } diff --git a/testnet/virtual.go b/testnet/virtual.go index 8421c2db..20c62224 100644 --- a/testnet/virtual.go +++ b/testnet/virtual.go @@ -270,7 +270,7 @@ func (nc *networkClient) ConnectTo(_ context.Context, p peer.ID) error { tag := tagForPeers(nc.local, p) if _, ok := nc.network.conns[tag]; ok { nc.network.mu.Unlock() - log.Warning("ALREADY CONNECTED TO PEER (is this a reconnect? test lib needs fixing)") + log.Warn("ALREADY CONNECTED TO PEER (is this a reconnect? test lib needs fixing)") return nil } nc.network.conns[tag] = struct{}{} diff --git a/workers.go b/workers.go index fb3dc019..053a4df9 100644 --- a/workers.go +++ b/workers.go @@ -127,7 +127,7 @@ func (bs *Bitswap) provideWorker(px process.Process) { defer cancel() if err := bs.network.Provide(ctx, k); err != nil { - log.Warning(err) + log.Warn(err) } } From 268817f1ef4e909dcb3eca6b09b430e4cd0c64b5 Mon Sep 17 00:00:00 2001 From: Adrian Lanzafame Date: Tue, 29 Oct 2019 18:34:14 +1000 Subject: [PATCH 2/2] remove log.Event, replace with structured log --- bitswap.go | 2 +- getter/getter.go | 2 +- go.mod | 1 + go.sum | 1 + workers.go | 24 ++++++++++++------------ 5 files changed, 16 insertions(+), 14 deletions(-) diff --git a/bitswap.go b/bitswap.go index c8ba82b5..82059e0a 100644 --- a/bitswap.go +++ b/bitswap.go @@ -358,7 +358,7 @@ func (bs *Bitswap) receiveBlocksFrom(ctx context.Context, from peer.ID, blks []b if from != "" { for _, b := range wanted { - log.Event(ctx, "Bitswap.GetBlockRequest.End", b.Cid()) + log.Infow("Bitswap.GetBlockRequest.End", "cid", b.Cid()) } } diff --git a/getter/getter.go b/getter/getter.go index 018bf87a..85ec9c84 100644 --- a/getter/getter.go +++ b/getter/getter.go @@ -77,7 +77,7 @@ func AsyncGetBlocks(ctx context.Context, sessctx context.Context, keys []cid.Cid remaining := cid.NewSet() promise := notif.Subscribe(ctx, keys...) for _, k := range keys { - log.Event(ctx, "Bitswap.GetBlockRequest.Start", k) + log.Infow("Bitswap.GetBlockRequest.Start", "cid", k) remaining.Add(k) } diff --git a/go.mod b/go.mod index 53fb6302..85e938e8 100644 --- a/go.mod +++ b/go.mod @@ -27,6 +27,7 @@ require ( github.com/libp2p/go-msgio v0.0.4 github.com/mattn/go-colorable v0.1.2 // indirect github.com/multiformats/go-multiaddr v0.1.1 + go.uber.org/zap v1.10.0 ) go 1.12 diff --git a/go.sum b/go.sum index a34ea60d..f2649f1d 100644 --- a/go.sum +++ b/go.sum @@ -234,6 +234,7 @@ github.com/libp2p/go-libp2p-testing v0.0.3 h1:bdij4bKaaND7tCsaXVjRfYkMpvoOeKj9AV github.com/libp2p/go-libp2p-testing v0.0.3/go.mod h1:gvchhf3FQOtBdr+eFUABet5a4MBLK8jM3V4Zghvmi+E= github.com/libp2p/go-libp2p-testing v0.0.4 h1:Qev57UR47GcLPXWjrunv5aLIQGO4n9mhI/8/EIrEEFc= github.com/libp2p/go-libp2p-testing v0.0.4/go.mod h1:gvchhf3FQOtBdr+eFUABet5a4MBLK8jM3V4Zghvmi+E= +github.com/libp2p/go-libp2p-testing v0.1.0 h1:WaFRj/t3HdMZGNZqnU2pS7pDRBmMeoDx7/HDNpeyT9U= github.com/libp2p/go-libp2p-testing v0.1.0/go.mod h1:xaZWMJrPUM5GlDBxCeGUi7kI4eqnjVyavGroI2nxEM0= github.com/libp2p/go-libp2p-transport-upgrader v0.1.1 h1:PZMS9lhjK9VytzMCW3tWHAXtKXmlURSc3ZdvwEcKCzw= github.com/libp2p/go-libp2p-transport-upgrader v0.1.1/go.mod h1:IEtA6or8JUbsV07qPW4r01GnTenLW4oi3lOPbUMGJJA= diff --git a/workers.go b/workers.go index 053a4df9..6b13e426 100644 --- a/workers.go +++ b/workers.go @@ -9,6 +9,7 @@ import ( logging "github.com/ipfs/go-log" process "github.com/jbenet/goprocess" procctx "github.com/jbenet/goprocess/context" + "go.uber.org/zap" ) // TaskWorkerCount is the total number of simultaneous threads sending @@ -39,10 +40,9 @@ func (bs *Bitswap) startWorkers(ctx context.Context, px process.Process) { } func (bs *Bitswap) taskWorker(ctx context.Context, id int) { - idmap := logging.LoggableMap{"ID": id} defer log.Debug("bitswap task worker shutting down...") for { - log.Event(ctx, "Bitswap.TaskWorker.Loop", idmap) + log.Desugar().Info("Bitswap.TaskWorker.Loop", zap.Int("id", id)) select { case nextEnvelope := <-bs.engine.Outbox(): select { @@ -54,13 +54,11 @@ func (bs *Bitswap) taskWorker(ctx context.Context, id int) { // TODO: Should only track *useful* messages in ledger outgoing := bsmsg.New(false) for _, block := range envelope.Message.Blocks() { - log.Event(ctx, "Bitswap.TaskWorker.Work", logging.LoggableF(func() map[string]interface{} { - return logging.LoggableMap{ - "ID": id, - "Target": envelope.Peer.Pretty(), - "Block": block.Cid().String(), - } - })) + log.Desugar().Info("Bitswap.TaskWorker.Work", + zap.Int("id", id), + zap.String("target", envelope.Peer.Pretty()), + zap.String("block", block.Cid().String()), + ) outgoing.AddBlock(block) } bs.engine.MessageSent(envelope.Peer, outgoing) @@ -121,7 +119,10 @@ func (bs *Bitswap) provideWorker(px process.Process) { }() ev := logging.LoggableMap{"ID": wid} - defer log.EventBegin(ctx, "Bitswap.ProvideWorker.Work", ev, k).Done() + defer log.Desugar().Info("Bitswap.ProvideWorker.Work", + zap.Int("id", wid), + zap.String("cid", k.String()), + ) ctx, cancel := context.WithTimeout(ctx, provideTimeout) // timeout ctx defer cancel() @@ -134,8 +135,7 @@ func (bs *Bitswap) provideWorker(px process.Process) { // worker spawner, reads from bs.provideKeys until it closes, spawning a // _ratelimited_ number of workers to handle each key. for wid := 2; ; wid++ { - ev := logging.LoggableMap{"ID": 1} - log.Event(ctx, "Bitswap.ProvideWorker.Loop", ev) + log.Infow("Bitswap.ProvideWorker.Loop", "id", 1) select { case <-px.Closing():