From d05ce2d2741cdaeafba99c4fd164951b589c4238 Mon Sep 17 00:00:00 2001 From: Matt Joiner Date: Thu, 16 Apr 2020 17:20:58 +1000 Subject: [PATCH] Update anacrolix/log --- client.go | 37 ++++++++++++++---------------------- go.mod | 2 +- go.sum | 2 ++ peerconn.go | 4 ++-- portfwd.go | 6 +++--- torrent.go | 10 +++++----- tracker_scraper.go | 2 +- webtorrent/tracker_client.go | 8 ++++---- 8 files changed, 32 insertions(+), 39 deletions(-) diff --git a/client.go b/client.go index 36ad98b4..30a12ac5 100644 --- a/client.go +++ b/client.go @@ -146,17 +146,11 @@ func (cl *Client) WriteStatus(_w io.Writer) { } } -const debugLogValue = log.Debug - -func (cl *Client) debugLogFilter(m log.Msg) bool { - if cl.config.Debug { - return true - } - return !m.HasValue(debugLogValue) -} - func (cl *Client) initLogger() { - cl.logger = cl.config.Logger.WithValues(cl).WithFilter(cl.debugLogFilter) + cl.logger = cl.config.Logger.WithValues(cl) + if !cl.config.Debug { + cl.logger = cl.logger.FilterLevel(log.Info) + } } func (cl *Client) announceKey() int32 { @@ -443,13 +437,13 @@ func (cl *Client) acceptConnections(l net.Listener) { return } if err != nil { - log.Fmsg("error accepting connection: %s", err).AddValue(debugLogValue).Log(cl.logger) + log.Fmsg("error accepting connection: %s", err).SetLevel(log.Debug).Log(cl.logger) continue } go func() { if reject != nil { torrent.Add("rejected accepted connections", 1) - log.Fmsg("rejecting accepted conn: %v", reject).AddValue(debugLogValue).Log(cl.logger) + log.Fmsg("rejecting accepted conn: %v", reject).SetLevel(log.Debug).Log(cl.logger) conn.Close() } else { go cl.incomingConnection(conn) @@ -458,7 +452,7 @@ func (cl *Client) acceptConnections(l net.Listener) { l.Addr().Network(), conn.LocalAddr(), conn.RemoteAddr(), - ).AddValue(debugLogValue).Log(cl.logger) + ).SetLevel(log.Debug).Log(cl.logger) torrent.Add(fmt.Sprintf("accepted conn remote IP len=%d", len(addrIpOrNil(conn.RemoteAddr()))), 1) torrent.Add(fmt.Sprintf("accepted conn network=%s", conn.RemoteAddr().Network()), 1) torrent.Add(fmt.Sprintf("accepted on %s listener", l.Addr().Network()), 1) @@ -836,11 +830,10 @@ func (cl *Client) runReceivedConn(c *PeerConn) { if err != nil { log.Fmsg( "error receiving handshakes on %v: %s", c, err, - ).AddValue( - debugLogValue, - ).Add( - "network", c.network, - ).Log(cl.logger) + ).SetLevel(log.Debug). + Add( + "network", c.network, + ).Log(cl.logger) torrent.Add("error receiving handshake", 1) cl.lock() cl.onBadAccept(c.remoteAddr) @@ -849,7 +842,7 @@ func (cl *Client) runReceivedConn(c *PeerConn) { } if t == nil { torrent.Add("received handshake for unloaded torrent", 1) - log.Fmsg("received handshake for unloaded torrent").AddValue(debugLogValue).Log(cl.logger) + log.Fmsg("received handshake for unloaded torrent").SetLevel(log.Debug).Log(cl.logger) cl.lock() cl.onBadAccept(c.remoteAddr) cl.unlock() @@ -883,7 +876,7 @@ func (cl *Client) runHandshookConn(c *PeerConn, t *Torrent) { torrent.Add("completed handshake over ipv6", 1) } if err := t.addConnection(c); err != nil { - log.Fmsg("error adding connection: %s", err).AddValues(c, debugLogValue).Log(t.logger) + log.Fmsg("error adding connection: %s", err).AddValues(c).SetLevel(log.Debug).Log(t.logger) return } defer t.dropConnection(c) @@ -1251,9 +1244,7 @@ func (cl *Client) newConnection(nc net.Conn, outgoing bool, remoteAddr net.Addr, network: network, connString: connString, } - c.logger = cl.logger.WithValues(c, - log.Debug, // I want messages to default to debug, and can set it here as it's only used by new code - ).WithText(func(m log.Msg) string { + c.logger = cl.logger.WithValues(c).WithDefaultLevel(log.Debug).WithText(func(m log.Msg) string { return fmt.Sprintf("%v: %s", c, m.Text()) }) c.writerCond.L = cl.locker() diff --git a/go.mod b/go.mod index 0f2e065f..79dd78d0 100644 --- a/go.mod +++ b/go.mod @@ -6,7 +6,7 @@ require ( github.com/anacrolix/dht/v2 v2.5.1-0.20200317023935-129f05e9b752 github.com/anacrolix/envpprof v1.1.0 github.com/anacrolix/go-libutp v1.0.2 - github.com/anacrolix/log v0.6.0 + github.com/anacrolix/log v0.6.1-0.20200416071330-f58a030e6149 github.com/anacrolix/missinggo v1.2.1 github.com/anacrolix/missinggo/perf v1.0.0 github.com/anacrolix/missinggo/v2 v2.4.1-0.20200227072623-f02f6484f997 diff --git a/go.sum b/go.sum index aedd7080..616b4423 100644 --- a/go.sum +++ b/go.sum @@ -53,6 +53,8 @@ github.com/anacrolix/log v0.5.0 h1:SD3p5SJZ77we9rt+YbRsL64SAQTAns+9nSYXxFmVVi8= github.com/anacrolix/log v0.5.0/go.mod h1:lWvLTqzAnCWPJA08T2HCstZi0L1y2Wyvm3FJgwU9jwU= github.com/anacrolix/log v0.6.0 h1:5y+wtTWoecbrAWWuoBCH7UuGFiD6q2jnQxrLK01RC+Q= github.com/anacrolix/log v0.6.0/go.mod h1:lWvLTqzAnCWPJA08T2HCstZi0L1y2Wyvm3FJgwU9jwU= +github.com/anacrolix/log v0.6.1-0.20200416071330-f58a030e6149 h1:3cEyLU9ObAfTnBHCev8uuWGhbHfol8uTwyMRkLIpZGg= +github.com/anacrolix/log v0.6.1-0.20200416071330-f58a030e6149/go.mod h1:s5yBP/j046fm9odtUTbHOfDUq/zh1W8OkPpJtnX0oQI= github.com/anacrolix/missinggo v0.0.0-20180522035225-b4a5853e62ff/go.mod h1:b0p+7cn+rWMIphK1gDH2hrDuwGOcbB6V4VXeSsEfHVk= github.com/anacrolix/missinggo v0.0.0-20180725070939-60ef2fbf63df/go.mod h1:kwGiTUTZ0+p4vAz3VbAI5a30t2YbvemcmspjKwrAz5s= github.com/anacrolix/missinggo v0.2.1-0.20190310234110-9fbdc9f242a8 h1:E2Xb2SBsVzHJ1tNMW9QcckYEQcyBKz1ee8qVjeVRWys= diff --git a/peerconn.go b/peerconn.go index 052dcdc0..bfc935e7 100644 --- a/peerconn.go +++ b/peerconn.go @@ -1082,7 +1082,7 @@ func (c *PeerConn) mainReadLoop() (err error) { }) case pp.Suggest: torrent.Add("suggests received", 1) - log.Fmsg("peer suggested piece %d", msg.Index).AddValues(c, msg.Index, debugLogValue).Log(c.t.logger) + log.Fmsg("peer suggested piece %d", msg.Index).AddValues(c, msg.Index).SetLevel(log.Debug).Log(c.t.logger) c.updateRequests() case pp.HaveAll: err = c.onPeerSentHaveAll() @@ -1093,7 +1093,7 @@ func (c *PeerConn) mainReadLoop() (err error) { delete(c.validReceiveChunks, newRequestFromMessage(&msg)) case pp.AllowedFast: torrent.Add("allowed fasts received", 1) - log.Fmsg("peer allowed fast: %d", msg.Index).AddValues(c, debugLogValue).Log(c.t.logger) + log.Fmsg("peer allowed fast: %d", msg.Index).AddValues(c).SetLevel(log.Debug).Log(c.t.logger) c.peerAllowedFast.Add(int(msg.Index)) c.updateRequests() case pp.Extended: diff --git a/portfwd.go b/portfwd.go index db5bb7df..2a4da0a6 100644 --- a/portfwd.go +++ b/portfwd.go @@ -10,11 +10,11 @@ import ( func (cl *Client) addPortMapping(d upnp.Device, proto upnp.Protocol, internalPort int, upnpID string) { externalPort, err := d.AddPortMapping(proto, internalPort, internalPort, upnpID, 0) if err != nil { - cl.logger.WithValues(log.Warning).Printf("error adding %s port mapping: %s", proto, err) + cl.logger.WithDefaultLevel(log.Warning).Printf("error adding %s port mapping: %s", proto, err) } else if externalPort != internalPort { - cl.logger.WithValues(log.Warning).Printf("external port %d does not match internal port %d in port mapping", externalPort, internalPort) + cl.logger.WithDefaultLevel(log.Warning).Printf("external port %d does not match internal port %d in port mapping", externalPort, internalPort) } else { - cl.logger.WithValues(log.Info).Printf("forwarded external %s port %d", proto, externalPort) + cl.logger.WithDefaultLevel(log.Info).Printf("forwarded external %s port %d", proto, externalPort) } } diff --git a/torrent.go b/torrent.go index 9435fe63..c2da92e2 100644 --- a/torrent.go +++ b/torrent.go @@ -1107,7 +1107,7 @@ func (t *Torrent) updatePieceCompletion(piece pieceIndex) bool { t.logger.Printf("marked piece %v complete but still has dirtiers", piece) } if changed { - log.Fstr("piece %d completion changed: %+v -> %+v", piece, cached, uncached).WithValues(debugLogValue).Log(t.logger) + log.Fstr("piece %d completion changed: %+v -> %+v", piece, cached, uncached).SetLevel(log.Debug).Log(t.logger) t.pieceCompletionChanged(piece) } return changed @@ -1338,12 +1338,12 @@ func (t *Torrent) startScrapingTracker(_url string) { wst := websocketTracker{*u, webtorrent.NewTrackerClient(t.cl.peerID, t.infoHash, t.onWebRtcConn, t.logger.WithText(func(m log.Msg) string { return fmt.Sprintf("%q: %v", u.String(), m.Text()) - }).WithValues(log.Debug))} + }).WithDefaultLevel(log.Debug))} ar := t.announceRequest(tracker.Started) go func() { err := wst.TrackerClient.Run(ar, u.String()) if err != nil { - t.logger.WithValues(log.Error).Printf( + t.logger.WithDefaultLevel(log.Error).Printf( "error running websocket tracker announcer for %q: %v", u.String(), err) } @@ -1471,7 +1471,7 @@ func (t *Torrent) dhtAnnouncer(s DhtServer) { defer cl.lock() err := t.announceToDht(true, s) if err != nil { - t.logger.WithValues(log.Warning).Printf("error announcing %q to DHT: %s", t, err) + t.logger.WithDefaultLevel(log.Warning).Printf("error announcing %q to DHT: %s", t, err) } }() } @@ -1618,7 +1618,7 @@ func (t *Torrent) SetMaxEstablishedConns(max int) (oldMax int) { } func (t *Torrent) pieceHashed(piece pieceIndex, passed bool, hashIoErr error) { - t.logger.Log(log.Fstr("hashed piece %d (passed=%t)", piece, passed).WithValues(debugLogValue)) + t.logger.Log(log.Fstr("hashed piece %d (passed=%t)", piece, passed).SetLevel(log.Debug)) p := t.piece(piece) p.numVerifies++ t.cl.event.Broadcast() diff --git a/tracker_scraper.go b/tracker_scraper.go index ffe4be6c..ae82da5c 100644 --- a/tracker_scraper.go +++ b/tracker_scraper.go @@ -117,7 +117,7 @@ func (me *trackerScraper) announce(event tracker.AnnounceEvent) (ret trackerAnno me.t.cl.rLock() req := me.t.announceRequest(event) me.t.cl.rUnlock() - me.t.logger.WithValues(log.Debug).Printf("announcing to %q: %#v", me.u.String(), req) + me.t.logger.WithDefaultLevel(log.Debug).Printf("announcing to %q: %#v", me.u.String(), req) res, err := tracker.Announce{ HTTPProxy: me.t.cl.config.HTTPProxy, UserAgent: me.t.cl.config.HTTPUserAgent, diff --git a/webtorrent/tracker_client.go b/webtorrent/tracker_client.go index 8039e8ce..ca0f90ad 100644 --- a/webtorrent/tracker_client.go +++ b/webtorrent/tracker_client.go @@ -55,13 +55,13 @@ func (c *TrackerClient) Run(ar tracker.AnnounceRequest, url string) error { return fmt.Errorf("failed to dial tracker: %w", err) } defer t.Close() - c.logger.WithValues(log.Info).Printf("dialed tracker %q", url) + c.logger.WithDefaultLevel(log.Debug).Printf("dialed tracker %q", url) c.tracker = t go func() { err := c.announce(ar) if err != nil { - c.logger.WithValues(log.Error).Printf("error announcing: %v", err) + c.logger.WithDefaultLevel(log.Error).Printf("error announcing: %v", err) } }() return c.trackerReadLoop() @@ -126,7 +126,7 @@ func (c *TrackerClient) trackerReadLoop() error { if err != nil { return fmt.Errorf("read error: %w", err) } - c.logger.WithValues(log.Debug).Printf("received message from tracker: %q", message) + c.logger.WithDefaultLevel(log.Debug).Printf("received message from tracker: %q", message) var ar AnnounceResponse if err := json.Unmarshal(message, &ar); err != nil { @@ -169,7 +169,7 @@ func (c *TrackerClient) trackerReadLoop() error { offer, ok := c.outboundOffers[ar.OfferID] c.lock.Unlock() if !ok { - c.logger.WithValues(log.Warning).Printf("could not find offer for id %q", ar.OfferID) + c.logger.WithDefaultLevel(log.Warning).Printf("could not find offer for id %q", ar.OfferID) continue } c.logger.Printf("offer %q got answer %v", ar.OfferID, *ar.Answer) -- 2.44.0