Tweak logging

client.go

@@ -1294,7 +1294,7 @@ func (cl *Client) newTorrentOpt(opts AddTorrentOpts) (t *Torrent) {
 	t.smartBanCache.Hash = sha1.Sum
 	t.smartBanCache.Init()
 	t.networkingEnabled.Set()
-	t.logger = cl.logger.WithContextValue(t).WithNames("torrent", t.infoHash.HexString()).WithDefaultLevel(log.Debug)
+	t.logger = cl.logger.WithDefaultLevel(log.Debug)
 	t.sourcesLogger = t.logger.WithNames("sources")
 	if opts.ChunkSize == 0 {
 		opts.ChunkSize = defaultChunkSize
@@ -1601,8 +1601,8 @@ func (cl *Client) newConnection(nc net.Conn, opts newConnectionOpts) (c *PeerCon
 	}
 	c.logger.Levelf(
 		log.Debug,
-		"new PeerConn %p [Client %p remoteAddr %v network %v outgoing %t]",
+		"inited with remoteAddr %v network %v outgoing %t",
-		c, cl, opts.remoteAddr, opts.network, opts.outgoing,
+		opts.remoteAddr, opts.network, opts.outgoing,
 	)
 	for _, f := range cl.config.Callbacks.NewPeer {
 		f(&c.Peer)

go.mod

@@ -14,7 +14,7 @@ require (
 	github.com/anacrolix/fuse v0.2.0
 	github.com/anacrolix/generics v0.0.0-20230428105757-683593396d68
 	github.com/anacrolix/go-libutp v1.2.0
-	github.com/anacrolix/log v0.13.2-0.20221123232138-02e2764801c3
+	github.com/anacrolix/log v0.13.2-0.20230518105052-6aef2c4c91f1
 	github.com/anacrolix/missinggo v1.3.0
 	github.com/anacrolix/missinggo/perf v1.0.0
 	github.com/anacrolix/missinggo/v2 v2.7.0

go.sum

@@ -84,8 +84,8 @@ github.com/anacrolix/log v0.3.0/go.mod h1:lWvLTqzAnCWPJA08T2HCstZi0L1y2Wyvm3FJgw
 github.com/anacrolix/log v0.6.0/go.mod h1:lWvLTqzAnCWPJA08T2HCstZi0L1y2Wyvm3FJgwU9jwU=
 github.com/anacrolix/log v0.10.0/go.mod h1:s5yBP/j046fm9odtUTbHOfDUq/zh1W8OkPpJtnX0oQI=
 github.com/anacrolix/log v0.10.1-0.20220123034749-3920702c17f8/go.mod h1:GmnE2c0nvz8pOIPUSC9Rawgefy1sDXqposC2wgtBZE4=
-github.com/anacrolix/log v0.13.2-0.20221123232138-02e2764801c3 h1:qDcPnH18SanNZMeMuEjzKpB3NQGR1ahytV08KOhZhNo=
+github.com/anacrolix/log v0.13.2-0.20230518105052-6aef2c4c91f1 h1:Yo4XQhmdmrkB4RGP7RWvl8U+og2rCBsNqoJFTew0plk=
-github.com/anacrolix/log v0.13.2-0.20221123232138-02e2764801c3/go.mod h1:MD4fn2pYcyhUAQg9SxoGOpTnV/VIdiKVYKZdCbDC97k=
+github.com/anacrolix/log v0.13.2-0.20230518105052-6aef2c4c91f1/go.mod h1:1OmJESOtxQGNMlUO5rcv96Vpp9mfMqXXbe2RdinFLdY=
 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-20180725070939-60ef2fbf63df/go.mod h1:kwGiTUTZ0+p4vAz3VbAI5a30t2YbvemcmspjKwrAz5s=

main_test.go

@@ -6,10 +6,12 @@ import (
 	"testing"
 
 	_ "github.com/anacrolix/envpprof"
+	analog "github.com/anacrolix/log"
 )
 
 func init() {
 	log.SetFlags(log.LstdFlags | log.Lshortfile)
+	analog.DefaultTimeFormatter = analog.TimeFormatSecondsSinceInit
 }
 
 func TestMain(m *testing.M) {

testing.go

@@ -20,7 +20,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.Logger = log.Default.WithContextText(t.Name())
 	//cfg.Debug = true
 	//cfg.Logger = cfg.Logger.WithText(func(m log.Msg) string {
 	//	t := m.Text()

torrent.go

@@ -1071,7 +1071,7 @@ func (t *Torrent) maybeDropMutuallyCompletePeer(
 	if p.useful() {
 		return
 	}
-	t.logger.WithDefaultLevel(log.Debug).Printf("dropping %v, which is mutually complete", p)
+	p.logger.Levelf(log.Debug, "is mutually complete; dropping")
 	p.drop()
 }
 

ut-holepunching_test.go

@@ -43,6 +43,7 @@ func TestHolepunchConnect(t *testing.T) {
 	// Ensure that responding to holepunch connects don't wait around for the dial limit. We also
 	// have to allow the initial connection to the leecher though, so it can rendezvous for us.
 	cfg.DialRateLimiter = rate.NewLimiter(0, 1)
+	cfg.Logger = cfg.Logger.WithContextText("seeder")
 	seeder, err := NewClient(cfg)
 	require.NoError(t, err)
 	defer seeder.Close()
@@ -56,10 +57,11 @@ func TestHolepunchConnect(t *testing.T) {
 	cfg.Seed = true
 	cfg.DataDir = t.TempDir()
 	cfg.AlwaysWantConns = true
+	cfg.Logger = cfg.Logger.WithContextText("leecher")
 	// This way the leecher leecher will still try to use this peer as a relay, but won't be told
 	// about the seeder via PEX.
 	//cfg.DisablePEX = true
-	//cfg.Debug = true
+	cfg.Debug = true
 	leecher, err := NewClient(cfg)
 	require.NoError(t, err)
 	defer leecher.Close()
@@ -69,8 +71,9 @@ func TestHolepunchConnect(t *testing.T) {
 	cfg.Seed = false
 	cfg.DataDir = t.TempDir()
 	cfg.MaxAllocPeerRequestDataPerConn = 4
-	//cfg.Debug = true
+	cfg.Debug = true
 	cfg.NominalDialTimeout = time.Second
+	cfg.Logger = cfg.Logger.WithContextText("leecher-leecher")
 	//cfg.DisableUTP = true
 	leecherLeecher, _ := NewClient(cfg)
 	require.NoError(t, err)