client.go | 7 +++++++ connection.go | 8 ++++++-- connection_test.go | 4 ++-- diff --git a/client.go b/client.go index 587d973ea7d921976a5cb81bb5cc02fa5cc05f93..6351286cbeb1ef61f23aecb0eaf4408333053241 100644 --- a/client.go +++ b/client.go @@ -980,6 +980,7 @@ c.Post(t.newMetadataExtensionMessage(c, pp.RejectMetadataExtensionMsgType, d["piece"], nil)) return nil } start := (1 << 14) * piece + c.logger.Printf("sending metadata piece %d", piece) c.Post(t.newMetadataExtensionMessage(c, pp.DataMetadataExtensionMsgType, piece, t.metadataBytes[start:start+t.metadataPieceSize(piece)])) return nil case pp.RejectMetadataExtensionMsgType: @@ -1228,12 +1229,18 @@ writeBuffer: new(bytes.Buffer), remoteAddr: remoteAddr, network: network, } + 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 { + return fmt.Sprintf("%v: %s", c, m.Text()) + }) c.writerCond.L = cl.locker() c.setRW(connStatsReadWriter{nc, c}) c.r = &rateLimitedReader{ l: cl.config.DownloadRateLimiter, r: c.r, } + c.logger.Printf("initialized with remote %v over network %v (outgoing=%t)", remoteAddr, network, outgoing) return } diff --git a/connection.go b/connection.go index c2914bbdaffb4ca605b2b77e05d96fc32884aff3..cb24082625cf9e2f7370f01b2b28bf39581ba8ba 100644 --- a/connection.go +++ b/connection.go @@ -115,6 +115,8 @@ writeBuffer *bytes.Buffer uploadTimer *time.Timer writerCond sync.Cond + + logger log.Logger } func (cn *connection) updateExpectingChunks() { @@ -348,6 +350,7 @@ } if index < len(cn.metadataRequests) && cn.metadataRequests[index] { return } + cn.logger.Printf("requesting metadata piece %d", index) cn.Post(pp.Message{ Type: pp.Extended, ExtendedID: eID, @@ -1225,7 +1228,7 @@ return nil case metadataExtendedId: err := cl.gotMetadataExtensionMsg(payload, t, c) if err != nil { - return fmt.Errorf("error handling metadata extension message: %s", err) + return fmt.Errorf("handling metadata extension message: %w", err) } return nil case pexExtendedId: @@ -1546,6 +1549,7 @@ if c.t != nil { panic("connection already associated with a torrent") } c.t = t + c.logger.Printf("torrent=%v", t) t.reconcileHandshakeStats(c) } @@ -1562,5 +1566,5 @@ return c.remoteAddr } func (c *connection) String() string { - return fmt.Sprintf("%p", c) + return fmt.Sprintf("connection %p", c) } diff --git a/connection_test.go b/connection_test.go index 56a07f030918877f457f36c0a7972a87a16876a0..661fb99862238057c11f9cd8aa665c740491a89a 100644 --- a/connection_test.go +++ b/connection_test.go @@ -19,9 +19,8 @@ // Ensure that no race exists between sending a bitfield, and a subsequent // Have that would potentially alter it. func TestSendBitfieldThenHave(t *testing.T) { - r, w := io.Pipe() cl := Client{ - config: &ClientConfig{DownloadRateLimiter: unlimited}, + config: TestingConfig(), } cl.initLogger() c := cl.newConnection(nil, false, IpPort{}, "") @@ -29,6 +28,7 @@ c.setTorrent(cl.newTorrent(metainfo.Hash{}, nil)) c.t.setInfo(&metainfo.Info{ Pieces: make([]byte, metainfo.HashSize*3), }) + r, w := io.Pipe() c.r = r c.w = w go c.writer(time.Minute)