diff --git a/client.go b/client.go index 1e0a3b4d..a247b3c4 100644 --- a/client.go +++ b/client.go @@ -34,7 +34,7 @@ import ( pp "github.com/anacrolix/torrent/peer_protocol" "github.com/anacrolix/torrent/storage" "github.com/davecgh/go-spew/spew" - "github.com/dustin/go-humanize" + humanize "github.com/dustin/go-humanize" "github.com/google/btree" "golang.org/x/time/rate" ) @@ -151,7 +151,7 @@ func (cl *Client) WriteStatus(_w io.Writer) { } } -const debugLogValue = "debug" +const debugLogValue = log.Debug func (cl *Client) debugLogFilter(m *log.Msg) bool { if !cl.config.Debug { @@ -200,7 +200,7 @@ func NewClient(cfg *ClientConfig) (cl *Client, err error) { storageImpl = storage.NewFile(cfg.DataDir) cl.onClose = append(cl.onClose, func() { if err := storageImpl.Close(); err != nil { - log.Printf("error closing default storage: %s", err) + cl.logger.Printf("error closing default storage: %s", err) } }) } @@ -319,9 +319,9 @@ func (cl *Client) newDhtServer(conn net.PacketConn) (s *dht.Server, err error) { go func() { ts, err := s.Bootstrap() if err != nil { - log.Printf("error bootstrapping dht: %s", err) + cl.logger.Printf("error bootstrapping dht: %s", err) } - log.Printf("%s: dht bootstrap: %#v", s, ts) + log.Str("completed bootstrap").AddValues(s, ts).Log(cl.logger) }() } return @@ -433,7 +433,7 @@ func (cl *Client) acceptConnections(l net.Listener) { return } if err != nil { - log.Printf("error accepting connection: %s", err) + cl.logger.Printf("error accepting connection: %s", err) continue } go func() { @@ -668,7 +668,7 @@ func (cl *Client) outgoingConnection(t *Torrent, addr IpPort, ps peerSource) { cl.noLongerHalfOpen(t, addr.String()) if err != nil { if cl.config.Debug { - log.Printf("error establishing outgoing connection: %s", err) + cl.logger.Printf("error establishing outgoing connection: %s", err) } return } @@ -845,7 +845,7 @@ func (cl *Client) runHandshookConn(c *connection, t *Torrent) { cl.sendInitialMessages(c, t) err := c.mainReadLoop() if err != nil && cl.config.Debug { - log.Printf("error during connection main read loop: %s", err) + cl.logger.Printf("error during connection main read loop: %s", err) } } @@ -1160,7 +1160,7 @@ func (cl *Client) AddDHTNodes(nodes []string) { hmp := missinggo.SplitHostMaybePort(n) ip := net.ParseIP(hmp.Host) if ip == nil { - log.Printf("won't add DHT node with bad IP: %q", hmp.Host) + cl.logger.Printf("won't add DHT node with bad IP: %q", hmp.Host) continue } ni := krpc.NodeInfo{ diff --git a/connection.go b/connection.go index 21f1fdc2..2352009c 100644 --- a/connection.go +++ b/connection.go @@ -1193,7 +1193,7 @@ func (c *connection) onReadExtendedMsg(id pp.ExtensionNumber, payload []byte) (e case pp.HandshakeExtendedID: var d pp.ExtendedHandshakeMessage if err := bencode.Unmarshal(payload, &d); err != nil { - log.Printf("error parsing extended handshake message %q: %s", payload, err) + c.t.logger.Printf("error parsing extended handshake message %q: %s", payload, err) return errors.Wrap(err, "unmarshalling extended handshake payload") } if d.Reqq != 0 { @@ -1335,7 +1335,7 @@ func (c *connection) receiveChunk(msg *pp.Message) error { piece.decrementPendingWrites() if err != nil { - log.Printf("%s (%s): error writing chunk %v: %s", t, t.infoHash, req, err) + c.t.logger.Printf("%s (%s): error writing chunk %v: %s", t, t.infoHash, req, err) t.pendRequest(req) t.updatePieceCompletion(pieceIndex(msg.Index)) return nil diff --git a/go.mod b/go.mod index 9361a9a2..b2739b7b 100644 --- a/go.mod +++ b/go.mod @@ -5,7 +5,7 @@ require ( github.com/anacrolix/dht v0.0.0-20181129074040-b09db78595aa github.com/anacrolix/envpprof v0.0.0-20180404065416-323002cec2fa github.com/anacrolix/go-libutp v0.0.0-20180808010927-aebbeb60ea05 - github.com/anacrolix/log v0.0.0-20180808012509-286fcf906b48 + github.com/anacrolix/log v0.2.0 github.com/anacrolix/missinggo v0.0.0-20181129073415-3237bf955fed github.com/anacrolix/sync v0.0.0-20180808010631-44578de4e778 github.com/anacrolix/tagflag v0.0.0-20180803105420-3a8ff5428f76 diff --git a/go.sum b/go.sum index bbb6a698..54f7186b 100644 --- a/go.sum +++ b/go.sum @@ -17,8 +17,8 @@ github.com/anacrolix/go-libutp v0.0.0-20180808010927-aebbeb60ea05 h1:Zoniih3jyqt github.com/anacrolix/go-libutp v0.0.0-20180808010927-aebbeb60ea05/go.mod h1:POY/GPlrFKRxnOKH1sGAB+NBWMoP+sI+hHJxgcgWbWw= github.com/anacrolix/log v0.0.0-20180412014343-2323884b361d h1:G8ITVMWuQL4adKRC3A6aBOo0YFJYcmpS3JFQd+rZrn0= github.com/anacrolix/log v0.0.0-20180412014343-2323884b361d/go.mod h1:sf/7c2aTldL6sRQj/4UKyjgVZBu2+M2z9wf7MmwPiew= -github.com/anacrolix/log v0.0.0-20180808012509-286fcf906b48 h1:aHwCj9Q6sjQOq5sC8Bzylt7GCAvt+D5MPEpkD6TeXxU= -github.com/anacrolix/log v0.0.0-20180808012509-286fcf906b48/go.mod h1:sf/7c2aTldL6sRQj/4UKyjgVZBu2+M2z9wf7MmwPiew= +github.com/anacrolix/log v0.2.0 h1:LzaW6XTEk2zcmLZkcZPkJ2mDdnZkOdOTeBH7Kt81ouU= +github.com/anacrolix/log v0.2.0/go.mod h1:sf/7c2aTldL6sRQj/4UKyjgVZBu2+M2z9wf7MmwPiew= github.com/anacrolix/missinggo v0.0.0-20180522035225-b4a5853e62ff/go.mod h1:b0p+7cn+rWMIphK1gDH2hrDuwGOcbB6V4VXeSsEfHVk= github.com/anacrolix/missinggo v0.0.0-20180621131740-7fc7cfea16ea/go.mod h1:kwGiTUTZ0+p4vAz3VbAI5a30t2YbvemcmspjKwrAz5s= github.com/anacrolix/missinggo v0.0.0-20180725070939-60ef2fbf63df/go.mod h1:kwGiTUTZ0+p4vAz3VbAI5a30t2YbvemcmspjKwrAz5s= diff --git a/torrent.go b/torrent.go index b376ba59..f90b265f 100644 --- a/torrent.go +++ b/torrent.go @@ -268,7 +268,7 @@ func (t *Torrent) saveMetadataPiece(index int, data []byte) { return } if index >= len(t.metadataCompletedChunks) { - log.Printf("%s: ignoring metadata piece %d", t, index) + t.logger.Printf("%s: ignoring metadata piece %d", t, index) return } copy(t.metadataBytes[(1<<14)*index:], data) @@ -366,7 +366,7 @@ func (t *Torrent) setInfo(info *metainfo.Info) error { func (t *Torrent) onSetInfo() { for conn := range t.conns { if err := conn.setNumPieces(t.numPieces()); err != nil { - log.Printf("closing connection: %s", err) + t.logger.Printf("closing connection: %s", err) conn.Close() } } @@ -374,7 +374,7 @@ func (t *Torrent) onSetInfo() { t.updatePieceCompletion(pieceIndex(i)) p := &t.pieces[i] if !p.storageCompletionOk { - // log.Printf("piece %s completion unknown, queueing check", p) + // t.logger.Printf("piece %s completion unknown, queueing check", p) t.queuePieceCheck(pieceIndex(i)) } } @@ -744,7 +744,7 @@ func (t *Torrent) hashPiece(piece pieceIndex) (ret metainfo.Hash) { return } if err != io.ErrUnexpectedEOF && !os.IsNotExist(err) { - log.Printf("unexpected error hashing piece with %T: %s", t.storage.TorrentImpl, err) + t.logger.Printf("unexpected error hashing piece with %T: %s", t.storage.TorrentImpl, err) } return } @@ -802,7 +802,7 @@ func (t *Torrent) wantPieceIndex(index pieceIndex) bool { if t.pendingPieces.Contains(bitmap.BitIndex(index)) { return true } - // log.Printf("piece %d not pending", index) + // t.logger.Printf("piece %d not pending", index) return !t.forReaderOffsetPieces(func(begin, end pieceIndex) bool { return index < begin || index >= end }) @@ -900,7 +900,7 @@ func (t *Torrent) maybeNewConns() { } func (t *Torrent) piecePriorityChanged(piece pieceIndex) { - // log.Printf("piece %d priority changed", piece) + // t.logger.Printf("piece %d priority changed", piece) for c := range t.conns { if c.updatePiecePriority(piece) { // log.Print("conn piece priority changed") @@ -914,7 +914,7 @@ func (t *Torrent) piecePriorityChanged(piece pieceIndex) { func (t *Torrent) updatePiecePriority(piece pieceIndex) { p := &t.pieces[piece] newPrio := p.uncachedPriority() - // log.Printf("torrent %p: piece %d: uncached priority: %v", t, piece, newPrio) + // t.logger.Printf("torrent %p: piece %d: uncached priority: %v", t, piece, newPrio) if newPrio == PiecePriorityNone { if !t.pendingPieces.Remove(bitmap.BitIndex(piece)) { return @@ -1062,8 +1062,8 @@ func (t *Torrent) updatePieceCompletion(piece pieceIndex) { p.storageCompletionOk = pcu.Ok t.completedPieces.Set(bitmap.BitIndex(piece), pcu.Complete) t.tickleReaders() - // log.Printf("piece %d uncached completion: %v", piece, pcu.Complete) - // log.Printf("piece %d changed: %v", piece, changed) + // t.logger.Printf("piece %d uncached completion: %v", piece, pcu.Complete) + // t.logger.Printf("piece %d changed: %v", piece, changed) if changed { t.pieceCompletionChanged(piece) } @@ -1099,7 +1099,7 @@ func (t *Torrent) maybeCompleteMetadata() error { return fmt.Errorf("error setting info bytes: %s", err) } if t.cl.config.Debug { - log.Printf("%s: got metadata from peers", t) + t.logger.Printf("%s: got metadata from peers", t) } return nil } @@ -1247,9 +1247,11 @@ func (t *Torrent) startScrapingTracker(_url string) { } u, err := url.Parse(_url) if err != nil { - log.Str("error parsing tracker url").AddValues("url", _url).Log(t.logger) - // TODO: Handle urls with leading '*', some kind of silly uTorrent - // convention? + // URLs with a leading '*' appear to be a uTorrent convention to + // disable trackers. + if _url[0] != '*' { + log.Str("error parsing tracker url").AddValues("url", _url).Log(t.logger) + } return } if u.Scheme == "udp" { @@ -1383,7 +1385,7 @@ func (t *Torrent) dhtAnnouncer(s *dht.Server) { if err == nil { t.numDHTAnnounces++ } else { - log.Printf("error announcing %q to DHT: %s", t, err) + t.logger.Printf("error announcing %q to DHT: %s", t, err) } }() select { @@ -1539,7 +1541,7 @@ func (t *Torrent) pieceHashed(piece pieceIndex, correct bool) { if correct { pieceHashedCorrect.Add(1) } else { - log.Printf("%s: piece %d (%s) failed hash: %d connections contributed", t, piece, p.hash, len(touchers)) + log.Fmsg("piece failed hash: %d connections contributed", len(touchers)).AddValue(t, p).Log(t.logger) pieceHashedNotCorrect.Add(1) } } @@ -1554,7 +1556,7 @@ func (t *Torrent) pieceHashed(piece pieceIndex, correct bool) { } err := p.Storage().MarkComplete() if err != nil { - log.Printf("%T: error marking piece complete %d: %s", t.storage, piece, err) + t.logger.Printf("%T: error marking piece complete %d: %s", t.storage, piece, err) } } else { if len(touchers) != 0 { @@ -1567,7 +1569,7 @@ func (t *Torrent) pieceHashed(piece pieceIndex, correct bool) { } slices.Sort(touchers, connLessTrusted) if t.cl.config.Debug { - log.Printf("dropping first corresponding conn from trust: %v", func() (ret []int64) { + t.logger.Printf("dropping first corresponding conn from trust: %v", func() (ret []int64) { for _, c := range touchers { ret = append(ret, c.netGoodPiecesDirtied()) } @@ -1605,7 +1607,7 @@ func (t *Torrent) onIncompletePiece(piece pieceIndex) { t.pendAllChunkSpecs(piece) } if !t.wantPieceIndex(piece) { - // log.Printf("piece %d incomplete and unwanted", piece) + // t.logger.Printf("piece %d incomplete and unwanted", piece) return } // We could drop any connections that we told we have a piece that we