Make use of the lazylog branch of anacrolix/log
This avoids significant allocations and overhead.
This commit is contained in:
Matt Joiner
parent
6568928bfd
commit
a324fbfee3
39
client.go
39
client.go
|
|
@ -174,19 +174,13 @@ func (cl *Client) WriteStatus(_w io.Writer) {
|
|||
}
|
||||
}
|
||||
|
||||
// Filters things that are less than warning from UPnP discovery.
|
||||
func upnpDiscoverLogFilter(m log.Msg) bool {
|
||||
level, ok := m.GetLevel()
|
||||
return !m.HasValue(UpnpDiscoverLogTag) || (!level.LessThan(log.Warning) && ok)
|
||||
}
|
||||
|
||||
func (cl *Client) initLogger() {
|
||||
logger := cl.config.Logger
|
||||
if logger.IsZero() {
|
||||
logger = log.Default
|
||||
if !cl.config.Debug {
|
||||
logger = logger.FilterLevel(log.Info).WithFilter(upnpDiscoverLogFilter)
|
||||
}
|
||||
if cl.config.Debug {
|
||||
logger = logger.FilterLevel(log.Debug)
|
||||
}
|
||||
cl.logger = logger.WithValues(cl)
|
||||
}
|
||||
|
|
@ -514,22 +508,26 @@ func (cl *Client) acceptConnections(l Listener) {
|
|||
return
|
||||
}
|
||||
if err != nil {
|
||||
log.Fmsg("error accepting connection: %s", err).SetLevel(log.Debug).Log(cl.logger)
|
||||
log.Fmsg("error accepting connection: %s", err).LogLevel(log.Debug, cl.logger)
|
||||
continue
|
||||
}
|
||||
go func() {
|
||||
if reject != nil {
|
||||
torrent.Add("rejected accepted connections", 1)
|
||||
log.Fmsg("rejecting accepted conn: %v", reject).SetLevel(log.Debug).Log(cl.logger)
|
||||
cl.logger.LazyLog(log.Debug, func() log.Msg {
|
||||
return log.Fmsg("rejecting accepted conn: %v", reject)
|
||||
})
|
||||
conn.Close()
|
||||
} else {
|
||||
go cl.incomingConnection(conn)
|
||||
}
|
||||
log.Fmsg("accepted %q connection at %q from %q",
|
||||
cl.logger.LazyLog(log.Debug, func() log.Msg {
|
||||
return log.Fmsg("accepted %q connection at %q from %q",
|
||||
l.Addr().Network(),
|
||||
conn.LocalAddr(),
|
||||
conn.RemoteAddr(),
|
||||
).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)
|
||||
|
|
@ -909,12 +907,13 @@ func (cl *Client) runReceivedConn(c *PeerConn) {
|
|||
}
|
||||
t, err := cl.receiveHandshakes(c)
|
||||
if err != nil {
|
||||
log.Fmsg(
|
||||
cl.logger.LazyLog(log.Debug, func() log.Msg {
|
||||
return log.Fmsg(
|
||||
"error receiving handshakes on %v: %s", c, err,
|
||||
).SetLevel(log.Debug).
|
||||
Add(
|
||||
).Add(
|
||||
"network", c.Network,
|
||||
).Log(cl.logger)
|
||||
)
|
||||
})
|
||||
torrent.Add("error receiving handshake", 1)
|
||||
cl.lock()
|
||||
cl.onBadAccept(c.RemoteAddr)
|
||||
|
|
@ -923,7 +922,9 @@ func (cl *Client) runReceivedConn(c *PeerConn) {
|
|||
}
|
||||
if t == nil {
|
||||
torrent.Add("received handshake for unloaded torrent", 1)
|
||||
log.Fmsg("received handshake for unloaded torrent").SetLevel(log.Debug).Log(cl.logger)
|
||||
cl.logger.LazyLog(log.Debug, func() log.Msg {
|
||||
return log.Fmsg("received handshake for unloaded torrent")
|
||||
})
|
||||
cl.lock()
|
||||
cl.onBadAccept(c.RemoteAddr)
|
||||
cl.unlock()
|
||||
|
|
@ -954,7 +955,7 @@ func (cl *Client) runHandshookConn(c *PeerConn, t *Torrent) error {
|
|||
// address, we won't record the remote address as a doppleganger. Instead, the initiator
|
||||
// can record *us* as the doppleganger.
|
||||
} */
|
||||
t.logger.WithLevel(log.Debug).Printf("local and remote peer ids are the same")
|
||||
t.logger.Levelf(log.Debug, "local and remote peer ids are the same")
|
||||
return nil
|
||||
}
|
||||
c.r = deadlineReader{c.conn, c.r}
|
||||
|
|
@ -1186,7 +1187,7 @@ func (cl *Client) newTorrentOpt(opts AddTorrentOpts) (t *Torrent) {
|
|||
gotMetainfoC: make(chan struct{}),
|
||||
}
|
||||
t.networkingEnabled.Set()
|
||||
t.logger = cl.logger.WithContextValue(t)
|
||||
t.logger = cl.logger.WithContextValue(t).WithNames("torrent", t.infoHash.HexString())
|
||||
if opts.ChunkSize == 0 {
|
||||
opts.ChunkSize = defaultChunkSize
|
||||
}
|
||||
|
|
|
|||
|
|
@ -255,8 +255,12 @@ func downloadErr(flags downloadFlags) error {
|
|||
if flags.DownloadRate != nil {
|
||||
clientConfig.DownloadRateLimiter = rate.NewLimiter(rate.Limit(*flags.DownloadRate), 1<<16)
|
||||
}
|
||||
{
|
||||
logger := log.Default.WithNames("main", "client")
|
||||
if flags.Quiet {
|
||||
clientConfig.Logger = log.Discard
|
||||
logger = logger.FilterLevel(log.Critical)
|
||||
}
|
||||
clientConfig.Logger = logger
|
||||
}
|
||||
if flags.RequireFastExtension {
|
||||
clientConfig.MinPeerExtensions.SetBit(pp.ExtensionBitFast, true)
|
||||
|
|
|
|||
6
go.mod
6
go.mod
|
|
@ -7,11 +7,11 @@ require (
|
|||
github.com/alexflint/go-arg v1.4.2
|
||||
github.com/anacrolix/args v0.4.1-0.20211104085705-59f0fe94eb8f
|
||||
github.com/anacrolix/chansync v0.3.0
|
||||
github.com/anacrolix/dht/v2 v2.14.1-0.20211220010335-4062f7927abf
|
||||
github.com/anacrolix/dht/v2 v2.15.2-0.20220123034220-0538803801cb
|
||||
github.com/anacrolix/envpprof v1.1.1
|
||||
github.com/anacrolix/fuse v0.2.0
|
||||
github.com/anacrolix/go-libutp v1.1.0
|
||||
github.com/anacrolix/log v0.10.0
|
||||
github.com/anacrolix/log v0.10.1-0.20220123034749-3920702c17f8
|
||||
github.com/anacrolix/missinggo v1.3.0
|
||||
github.com/anacrolix/missinggo/perf v1.0.0
|
||||
github.com/anacrolix/missinggo/v2 v2.5.2
|
||||
|
|
@ -19,7 +19,7 @@ require (
|
|||
github.com/anacrolix/squirrel v0.4.0
|
||||
github.com/anacrolix/sync v0.4.0
|
||||
github.com/anacrolix/tagflag v1.3.0
|
||||
github.com/anacrolix/upnp v0.1.2-0.20200416075019-5e9378ed1425
|
||||
github.com/anacrolix/upnp v0.1.3-0.20220123035249-922794e51c96
|
||||
github.com/anacrolix/utp v0.1.0
|
||||
github.com/bradfitz/iter v0.0.0-20191230175014-e8f45d346db8
|
||||
github.com/davecgh/go-spew v1.1.1
|
||||
|
|
|
|||
11
go.sum
11
go.sum
|
|
@ -104,8 +104,9 @@ github.com/anacrolix/dht/v2 v2.9.1/go.mod h1:ZyYcIQinN/TE3oKONCchQOLjhYR786Jaxz3
|
|||
github.com/anacrolix/dht/v2 v2.10.0/go.mod h1:KC51tqylRYBu82RM5pEYf+g1n7db+F0tOJqSbCjjZWc=
|
||||
github.com/anacrolix/dht/v2 v2.10.5-0.20210902001729-06cc4fe90e53/go.mod h1:zHjijcebN+L7JbzxW0mOraHis+I81EIgsJAAtiw8bQ8=
|
||||
github.com/anacrolix/dht/v2 v2.10.6-0.20211007004332-99263ec9c1c8/go.mod h1:WID4DexLrucfnwzv1OV8REzgoCpyVDwEczxIOrUeFrY=
|
||||
github.com/anacrolix/dht/v2 v2.14.1-0.20211220010335-4062f7927abf h1:gPdUT2QIlVX37CCRoKzyx5263AqQJIMyDM0b9DiZyR8=
|
||||
github.com/anacrolix/dht/v2 v2.14.1-0.20211220010335-4062f7927abf/go.mod h1:zJgaiAU2yhzmchZE2mY8WyZ64LK/F/D9MAeN0ct73qQ=
|
||||
github.com/anacrolix/dht/v2 v2.15.2-0.20220123034220-0538803801cb h1:c4e9XiiT0P3uMkONTkpzLVGxz3if5fIn6UB4HTrVlc0=
|
||||
github.com/anacrolix/dht/v2 v2.15.2-0.20220123034220-0538803801cb/go.mod h1:GCylVI6WTvbxvhY7pBoHiE5dmjfDWkhqbobDpjND01A=
|
||||
github.com/anacrolix/envpprof v0.0.0-20180404065416-323002cec2fa/go.mod h1:KgHhUaQMc8cC0+cEflSgCFNFbKwi5h54gqtVn8yhP7c=
|
||||
github.com/anacrolix/envpprof v1.0.0/go.mod h1:KgHhUaQMc8cC0+cEflSgCFNFbKwi5h54gqtVn8yhP7c=
|
||||
github.com/anacrolix/envpprof v1.0.1/go.mod h1:My7T5oSqVfEn4MD4Meczkw/f5lSIndGAKu/0SM/rkf4=
|
||||
|
|
@ -130,8 +131,9 @@ github.com/anacrolix/log v0.6.1-0.20200416071330-f58a030e6149/go.mod h1:s5yBP/j0
|
|||
github.com/anacrolix/log v0.7.1-0.20200604014615-c244de44fd2d/go.mod h1:s5yBP/j046fm9odtUTbHOfDUq/zh1W8OkPpJtnX0oQI=
|
||||
github.com/anacrolix/log v0.8.0/go.mod h1:s5yBP/j046fm9odtUTbHOfDUq/zh1W8OkPpJtnX0oQI=
|
||||
github.com/anacrolix/log v0.9.0/go.mod h1:s5yBP/j046fm9odtUTbHOfDUq/zh1W8OkPpJtnX0oQI=
|
||||
github.com/anacrolix/log v0.10.0 h1:uz9XDnmsw8ZEO/TTRU03lL7I74PlgVRFszYqPZ39WNY=
|
||||
github.com/anacrolix/log v0.10.0/go.mod h1:s5yBP/j046fm9odtUTbHOfDUq/zh1W8OkPpJtnX0oQI=
|
||||
github.com/anacrolix/log v0.10.1-0.20220123034749-3920702c17f8 h1:o1KNFCLJ6f5SRMVb70SUFiPnNiazVd0gpMxYfYCsvK4=
|
||||
github.com/anacrolix/log v0.10.1-0.20220123034749-3920702c17f8/go.mod h1:GmnE2c0nvz8pOIPUSC9Rawgefy1sDXqposC2wgtBZE4=
|
||||
github.com/anacrolix/lsan v0.0.0-20211126052245-807000409a62 h1:P04VG6Td13FHMgS5ZBcJX23NPC/fiC4cp9bXwYujdYM=
|
||||
github.com/anacrolix/lsan v0.0.0-20211126052245-807000409a62/go.mod h1:66cFKPCO7Sl4vbFnAaSq7e4OXtdMhRSBagJGWgmpJbM=
|
||||
github.com/anacrolix/missinggo v0.0.0-20180522035225-b4a5853e62ff/go.mod h1:b0p+7cn+rWMIphK1gDH2hrDuwGOcbB6V4VXeSsEfHVk=
|
||||
|
|
@ -168,6 +170,7 @@ github.com/anacrolix/multiless v0.2.0/go.mod h1:TrCLEZfIDbMVfLoQt5tOoiBS/uq4y8+o
|
|||
github.com/anacrolix/publicip v0.2.0/go.mod h1:67G1lVkLo8UjdEcJkwScWVTvlJ35OCDsRJoWXl/wi4g=
|
||||
github.com/anacrolix/squirrel v0.1.0/go.mod h1:YzgVvikMdFD441oTWlNG189bpKabO9Sbf3uCSVgca04=
|
||||
github.com/anacrolix/squirrel v0.1.1-0.20210914065657-81bc5ecdc43a/go.mod h1:YzgVvikMdFD441oTWlNG189bpKabO9Sbf3uCSVgca04=
|
||||
github.com/anacrolix/squirrel v0.2.1-0.20211119092713-2efaee06d169/go.mod h1:dJyE7VefQvX0KAKMkOQDGOVEs91a+LvXQ2BjEKl/DIw=
|
||||
github.com/anacrolix/squirrel v0.4.0 h1:MOxYwh0mD2rcEJT+N2tFj2Z3dBDrWn6kRxP4qsBxfyk=
|
||||
github.com/anacrolix/squirrel v0.4.0/go.mod h1:dJyE7VefQvX0KAKMkOQDGOVEs91a+LvXQ2BjEKl/DIw=
|
||||
github.com/anacrolix/stm v0.1.0/go.mod h1:ZKz7e7ERWvP0KgL7WXfRjBXHNRhlVRlbBQecqFtPq+A=
|
||||
|
|
@ -209,9 +212,11 @@ github.com/anacrolix/torrent v1.29.0/go.mod h1:40Hf2bWxFqTbTWbrdig57JnmYLCjShbWW
|
|||
github.com/anacrolix/torrent v1.30.2/go.mod h1:vbNxKfaGiNq8edcCaQI1oSNJwh4GMqtMUMF9qOdZ6C0=
|
||||
github.com/anacrolix/torrent v1.31.1-0.20210910222643-d957502528e0/go.mod h1:akZJHHFN8aWH2lcPZQ0I3etujnenwYpUvj36HV9uvAI=
|
||||
github.com/anacrolix/torrent v1.35.1-0.20211104090255-eaeb38b18c6a/go.mod h1:97nxJW8NIeUyGdBvMOAl9cmcxi8xPez3nlE0RwSZcL0=
|
||||
github.com/anacrolix/torrent v1.40.0/go.mod h1:ejOLXT7fZE8ONHsoIYD7WS4/l6SEwtRGxcsP3dEu/Fk=
|
||||
github.com/anacrolix/upnp v0.1.1/go.mod h1:LXsbsp5h+WGN7YR+0A7iVXm5BL1LYryDev1zuJMWYQo=
|
||||
github.com/anacrolix/upnp v0.1.2-0.20200416075019-5e9378ed1425 h1:/Wi6l2ONI1FUFWN4cBwHOO90V4ylp4ud/eov6GUcVFk=
|
||||
github.com/anacrolix/upnp v0.1.2-0.20200416075019-5e9378ed1425/go.mod h1:Pz94W3kl8rf+wxH3IbCa9Sq+DTJr8OSbV2Q3/y51vYs=
|
||||
github.com/anacrolix/upnp v0.1.3-0.20220123035249-922794e51c96 h1:QAVZ3pN/J4/UziniAhJR2OZ9Ox5kOY2053tBbbqUPYA=
|
||||
github.com/anacrolix/upnp v0.1.3-0.20220123035249-922794e51c96/go.mod h1:Wa6n8cYIdaG35x15aH3Zy6d03f7P728QfdcDeD/IEOs=
|
||||
github.com/anacrolix/utp v0.0.0-20180219060659-9e0e1d1d0572/go.mod h1:MDwc+vsGEq7RMw6lr2GKOEqjWny5hO5OZXRVNaBJ2Dk=
|
||||
github.com/anacrolix/utp v0.1.0 h1:FOpQOmIwYsnENnz7tAGohA+r6iXpRjrq8ssKSre2Cp4=
|
||||
github.com/anacrolix/utp v0.1.0/go.mod h1:MDwc+vsGEq7RMw6lr2GKOEqjWny5hO5OZXRVNaBJ2Dk=
|
||||
|
|
|
|||
11
peerconn.go
11
peerconn.go
|
|
@ -1096,9 +1096,9 @@ func runSafeExtraneous(f func()) {
|
|||
}
|
||||
|
||||
func (c *PeerConn) logProtocolBehaviour(level log.Level, format string, arg ...interface{}) {
|
||||
c.logger.WithLevel(level).WithContextText(fmt.Sprintf(
|
||||
c.logger.WithContextText(fmt.Sprintf(
|
||||
"peer id %q, ext v %q", c.PeerID, c.PeerClientName.Load(),
|
||||
)).SkipCallers(1).Printf(format, arg...)
|
||||
)).SkipCallers(1).Levelf(level, format, arg...)
|
||||
}
|
||||
|
||||
// Processes incoming BitTorrent wire-protocol messages. The client lock is held upon entry and
|
||||
|
|
@ -1186,10 +1186,11 @@ func (c *PeerConn) mainReadLoop() (err error) {
|
|||
if preservedCount != 0 {
|
||||
// TODO: Yes this is a debug log but I'm not happy with the state of the logging lib
|
||||
// right now.
|
||||
c.logger.WithLevel(log.Debug).Printf(
|
||||
c.logger.Levelf(log.Debug,
|
||||
"%v requests were preserved while being choked (fast=%v)",
|
||||
preservedCount,
|
||||
c.fastEnabled())
|
||||
|
||||
torrent.Add("requestsPreservedThroughChoking", int64(preservedCount))
|
||||
}
|
||||
if !c.t._pendingPieces.IsEmpty() {
|
||||
|
|
@ -1240,7 +1241,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).SetLevel(log.Debug).Log(c.t.logger)
|
||||
log.Fmsg("peer suggested piece %d", msg.Index).AddValues(c, msg.Index).LogLevel(log.Debug, c.t.logger)
|
||||
c.updateRequests("suggested")
|
||||
case pp.HaveAll:
|
||||
err = c.onPeerSentHaveAll()
|
||||
|
|
@ -1254,7 +1255,7 @@ func (c *PeerConn) mainReadLoop() (err error) {
|
|||
}
|
||||
case pp.AllowedFast:
|
||||
torrent.Add("allowed fasts received", 1)
|
||||
log.Fmsg("peer allowed fast: %d", msg.Index).AddValues(c).SetLevel(log.Debug).Log(c.t.logger)
|
||||
log.Fmsg("peer allowed fast: %d", msg.Index).AddValues(c).LogLevel(log.Debug, c.t.logger)
|
||||
c.updateRequests("PeerConn.mainReadLoop allowed fast")
|
||||
case pp.Extended:
|
||||
err = c.onReadExtendedMsg(msg.ExtendedID, msg.ExtendedPayload)
|
||||
|
|
|
|||
|
|
@ -310,7 +310,7 @@ func (r *reader) Seek(off int64, whence int) (newPos int64, err error) {
|
|||
}
|
||||
|
||||
func (r *reader) log(m log.Msg) {
|
||||
r.t.logger.Log(m.Skip(1))
|
||||
r.t.logger.LogLevel(log.Debug, m.Skip(1))
|
||||
}
|
||||
|
||||
// Implementation inspired by https://news.ycombinator.com/item?id=27019613.
|
||||
|
|
|
|||
|
|
@ -4,6 +4,7 @@ import (
|
|||
"testing"
|
||||
"time"
|
||||
|
||||
"github.com/anacrolix/log"
|
||||
pp "github.com/anacrolix/torrent/peer_protocol"
|
||||
)
|
||||
|
||||
|
|
@ -18,6 +19,7 @@ func TestingConfig(t testing.TB) *ClientConfig {
|
|||
cfg.ListenPort = 0
|
||||
cfg.KeepAliveTimeout = time.Millisecond
|
||||
cfg.MinPeerExtensions.SetBit(pp.ExtensionBitFast, true)
|
||||
cfg.Logger = log.Default.WithNames(t.Name())
|
||||
//cfg.Debug = true
|
||||
//cfg.Logger = cfg.Logger.WithText(func(m log.Msg) string {
|
||||
// t := m.Text()
|
||||
|
|
|
|||
11
torrent.go
11
torrent.go
|
|
@ -1302,7 +1302,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).SetLevel(log.Debug).Log(t.logger)
|
||||
log.Fstr("piece %d completion changed: %+v -> %+v", piece, cached, uncached).LogLevel(log.Debug, t.logger)
|
||||
t.pieceCompletionChanged(piece, "Torrent.updatePieceCompletion")
|
||||
}
|
||||
return changed
|
||||
|
|
@ -1932,7 +1932,9 @@ 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).SetLevel(log.Debug))
|
||||
t.logger.LazyLog(log.Debug, func() log.Msg {
|
||||
return log.Fstr("hashed piece %d (passed=%t)", piece, passed)
|
||||
})
|
||||
p := t.piece(piece)
|
||||
p.numVerifies++
|
||||
t.cl.event.Broadcast()
|
||||
|
|
@ -1947,7 +1949,10 @@ func (t *Torrent) pieceHashed(piece pieceIndex, passed bool, hashIoErr error) {
|
|||
} else {
|
||||
log.Fmsg(
|
||||
"piece %d failed hash: %d connections contributed", piece, len(p.dirtiers),
|
||||
).AddValues(t, p).SetLevel(log.Debug).Log(t.logger)
|
||||
).AddValues(t, p).LogLevel(
|
||||
|
||||
log.Debug, t.logger)
|
||||
|
||||
pieceHashedNotCorrect.Add(1)
|
||||
}
|
||||
}
|
||||
|
|
|
|||
|
|
@ -45,7 +45,7 @@ func (cc *ConnClient) reader() {
|
|||
}
|
||||
err = cc.d.Dispatch(b[:n], addr)
|
||||
if err != nil {
|
||||
cc.newOpts.Logger.WithLevel(log.Debug).Printf("dispatching packet received on %v: %v", cc.conn.LocalAddr(), err)
|
||||
cc.newOpts.Logger.Levelf(log.Debug, "dispatching packet received on %v: %v", cc.conn.LocalAddr(), err)
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
|
|||
|
|
@ -128,7 +128,7 @@ func (ws *webseedPeer) handleUpdateRequests() {
|
|||
}
|
||||
|
||||
func (ws *webseedPeer) onClose() {
|
||||
ws.peer.logger.WithLevel(log.Debug).Print("closing")
|
||||
ws.peer.logger.Levelf(log.Debug, "closing")
|
||||
// Just deleting them means we would have to manually cancel active requests.
|
||||
ws.peer.cancelAllRequests()
|
||||
ws.peer.t.iterPeers(func(p *Peer) {
|
||||
|
|
|
|||
Loading…
Reference in New Issue