diff --git a/discover/ntp.go b/discover/ntp.go index 48ceffe..38b3406 100644 --- a/discover/ntp.go +++ b/discover/ntp.go @@ -20,12 +20,11 @@ package discover import ( - "fmt" "net" "sort" "time" - "github.com/ethereum/go-ethereum/log" + "go.uber.org/zap" ) const ( @@ -49,10 +48,10 @@ func checkClockDrift() { return } if drift < -driftThreshold || drift > driftThreshold { - log.Warn(fmt.Sprintf("System clock seems off by %v, which can prevent network connectivity", drift)) - log.Warn("Please enable network time synchronisation in system settings.") + zap.L().Warn("System clock seems off", zap.Duration("drift", drift)) + zap.L().Warn("Please enable network time synchronisation in system settings.") } else { - log.Debug("NTP sanity check done", "drift", drift) + zap.L().Debug("NTP sanity check done", zap.Duration("drift", drift)) } } diff --git a/discover/table.go b/discover/table.go index 56088eb..1846cc5 100644 --- a/discover/table.go +++ b/discover/table.go @@ -334,7 +334,7 @@ func (tab *Table) doRevalidate(done chan<- struct{}) { // Ping the selected node and wait for a pong. remoteSeq, err := tab.net.ping(unwrapNode(last)) - logger := tab.log.With(zap.String("id", last.ID().String()), zap.String("addr", last.addr().String())) + logger := tab.log.With(zap.Stringer("id", last.ID()), zap.Stringer("addr", last.addr())) // Also fetch record if the node replied and returned a higher sequence number. if last.Seq() < remoteSeq { @@ -364,8 +364,8 @@ func (tab *Table) doRevalidate(done chan<- struct{}) { if r := tab.replace(b, last); r != nil { tab.log.Debug("Replaced dead node", zap.Uint("checks", last.livenessChecks), - zap.String("r", r.ID().String()), - zap.String("rip", r.IP().String())) + zap.Stringer("r", r.ID()), + zap.Stringer("rip", r.IP())) } else { tab.log.Debug("Removed dead node", zap.Uint("checks", last.livenessChecks)) diff --git a/discover/v5_talk.go b/discover/v5_talk.go index e71d83a..cc030e1 100644 --- a/discover/v5_talk.go +++ b/discover/v5_talk.go @@ -21,7 +21,8 @@ import ( "sync" "time" - "github.com/ethereum/go-ethereum/log" + "go.uber.org/zap" + "github.com/ethereum/go-ethereum/p2p/enode" "github.com/waku-org/go-discover/discover/v5wire" ) @@ -95,7 +96,7 @@ func (t *talkSystem) handleRequest(id enode.ID, addr *net.UDPAddr, req *v5wire.T case <-timeout.C: // Couldn't get it in time, drop the request. if time.Since(t.lastLog) > 5*time.Second { - log.Warn("Dropping TALKREQ due to overload", "ndrop", t.dropCount) + t.transport.log.Warn("Dropping TALKREQ due to overload", zap.Int("ndrop", t.dropCount)) t.lastLog = time.Now() t.dropCount++ } diff --git a/discover/v5_udp.go b/discover/v5_udp.go index 614d78a..ad9106c 100644 --- a/discover/v5_udp.go +++ b/discover/v5_udp.go @@ -29,11 +29,13 @@ import ( "sync" "time" + "go.uber.org/zap" + "github.com/ethereum/go-ethereum/common/mclock" - "github.com/ethereum/go-ethereum/log" "github.com/ethereum/go-ethereum/p2p/enode" "github.com/ethereum/go-ethereum/p2p/enr" "github.com/ethereum/go-ethereum/p2p/netutil" + "github.com/waku-org/go-discover/discover/v5wire" ) @@ -67,7 +69,7 @@ type UDPv5 struct { priv *ecdsa.PrivateKey localNode *enode.LocalNode db *enode.DB - log log.Logger + log *zap.Logger clock mclock.Clock validSchemes enr.IdentityScheme @@ -404,7 +406,10 @@ func (t *UDPv5) waitForNodes(c *callV5, distances []uint) ([]*enode.Node, error) for _, record := range response.Nodes { node, err := t.verifyResponseNode(c, record, distances, seen) if err != nil { - t.log.Debug("Invalid record in "+response.Name(), "id", c.node.ID(), "err", err) + t.log.Debug("Invalid record in "+response.Name(), + zap.Stringer("id", c.node.ID()), + zap.Error(err), + ) continue } nodes = append(nodes, node) @@ -649,12 +654,11 @@ func (t *UDPv5) send(toID enode.ID, toAddr *net.UDPAddr, packet v5wire.Packet, c enc, nonce, err := t.codec.Encode(toID, addr, packet, c) if err != nil { t.logcontext = append(t.logcontext, "err", err) - t.log.Warn(">> "+packet.Name(), t.logcontext...) + t.log.Warn(">> "+packet.Name(), zap.Any("context", t.logcontext)) return nonce, err } _, err = t.conn.WriteToUDP(enc, toAddr) - t.log.Trace(">> "+packet.Name(), t.logcontext...) return nonce, err } @@ -667,12 +671,12 @@ func (t *UDPv5) readLoop() { nbytes, from, err := t.conn.ReadFromUDP(buf) if netutil.IsTemporaryError(err) { // Ignore temporary read errors. - t.log.Debug("Temporary UDP read error", "err", err) + t.log.Debug("Temporary UDP read error", zap.Error(err)) continue } else if err != nil { // Shut down the loop for permanent errors. if !errors.Is(err, io.EOF) { - t.log.Debug("UDP read error", "err", err) + t.log.Debug("UDP read error", zap.Error(err)) } return } @@ -697,13 +701,12 @@ func (t *UDPv5) handlePacket(rawpacket []byte, fromAddr *net.UDPAddr) error { if err != nil { if t.unhandled != nil && v5wire.IsInvalidHeader(err) { // The packet seems unrelated to discv5, send it to the next protocol. - // t.log.Trace("Unhandled discv5 packet", "id", fromID, "addr", addr, "err", err) up := ReadPacket{Data: make([]byte, len(rawpacket)), Addr: fromAddr} copy(up.Data, rawpacket) t.unhandled <- up return nil } - t.log.Debug("Bad discv5 packet", "id", fromID, "addr", addr, "err", err) + t.log.Debug("Bad discv5 packet", zap.Stringer("id", fromID), zap.Stringer("addr", fromAddr), zap.Error(err)) return err } if fromNode != nil { @@ -714,7 +717,6 @@ func (t *UDPv5) handlePacket(rawpacket []byte, fromAddr *net.UDPAddr) error { // WHOAREYOU logged separately to report errors. t.logcontext = append(t.logcontext[:0], "id", fromID, "addr", addr) t.logcontext = packet.AppendLogInfo(t.logcontext) - t.log.Trace("<< "+packet.Name(), t.logcontext...) } t.handle(packet, fromID, fromAddr) return nil @@ -724,15 +726,15 @@ func (t *UDPv5) handlePacket(rawpacket []byte, fromAddr *net.UDPAddr) error { func (t *UDPv5) handleCallResponse(fromID enode.ID, fromAddr *net.UDPAddr, p v5wire.Packet) bool { ac := t.activeCallByNode[fromID] if ac == nil || !bytes.Equal(p.RequestID(), ac.reqid) { - t.log.Debug(fmt.Sprintf("Unsolicited/late %s response", p.Name()), "id", fromID, "addr", fromAddr) + t.log.Debug(fmt.Sprintf("Unsolicited/late %s response", p.Name()), zap.Stringer("id", fromID), zap.Stringer("addr", fromAddr)) return false } if !fromAddr.IP.Equal(ac.addr.IP) || fromAddr.Port != ac.addr.Port { - t.log.Debug(fmt.Sprintf("%s from wrong endpoint", p.Name()), "id", fromID, "addr", fromAddr) + t.log.Debug(fmt.Sprintf("%s from wrong endpoint", p.Name()), zap.Stringer("id", fromID), zap.Stringer("addr", fromAddr)) return false } if p.Kind() != ac.responseType { - t.log.Debug(fmt.Sprintf("Wrong discv5 response type %s", p.Name()), "id", fromID, "addr", fromAddr) + t.log.Debug(fmt.Sprintf("Wrong discv5 response type %s", p.Name()), zap.Stringer("id", fromID), zap.Stringer("addr", fromAddr)) return false } t.startResponseTimeout(ac) @@ -796,18 +798,17 @@ var ( func (t *UDPv5) handleWhoareyou(p *v5wire.Whoareyou, fromID enode.ID, fromAddr *net.UDPAddr) { c, err := t.matchWithCall(fromID, p.Nonce) if err != nil { - t.log.Debug("Invalid "+p.Name(), "addr", fromAddr, "err", err) + t.log.Debug("Invalid "+p.Name(), zap.String("addr", fromAddr.String()), zap.Error(err)) return } if c.node == nil { // Can't perform handshake because we don't have the ENR. - t.log.Debug("Can't handle "+p.Name(), "addr", fromAddr, "err", "call has no ENR") + t.log.Debug("Can't handle "+p.Name(), zap.String("addr", fromAddr.String()), zap.Error(errors.New("call has no ENR"))) c.err <- errors.New("remote wants handshake, but call has no ENR") return } // Resend the call that was answered by WHOAREYOU. - t.log.Trace("<< "+p.Name(), "id", c.node.ID(), "addr", fromAddr) c.handshakeCount++ c.challenge = p p.Node = c.node