More development of the new logging interface

client.go

@@ -42,6 +42,7 @@ type Client struct {
 	closed missinggo.Event
 
 	config Config
+	logger *log.Logger
 
 	halfOpenLimit  int
 	peerID         PeerID
@@ -222,6 +223,20 @@ func listen(tcp, utp bool, networkSuffix, addr string) (tcpL net.Listener, utpSo
 	return
 }
 
+const debugLogValue = "debug"
+
+func (cl *Client) debugLogFilter(m *log.Msg) bool {
+	if !cl.config.Debug {
+		_, ok := m.Values()[debugLogValue]
+		return !ok
+	}
+	return true
+}
+
+func (cl *Client) initLogger() {
+	cl.logger = log.Default.Clone().AddValue(cl).AddFilter(log.NewFilter(cl.debugLogFilter))
+}
+
 // Creates a new client.
 func NewClient(cfg *Config) (cl *Client, err error) {
 	if cfg == nil {
@@ -247,6 +262,7 @@ func NewClient(cfg *Config) (cl *Client, err error) {
 		dopplegangerAddrs: make(map[string]struct{}),
 		torrents:          make(map[metainfo.Hash]*Torrent),
 	}
+	cl.initLogger()
 	defer func() {
 		if err == nil {
 			return
@@ -1041,7 +1057,7 @@ func (cl *Client) newTorrent(ih metainfo.Hash, specStorage storage.ClientImpl) (
 			L: &cl.mu,
 		},
 	}
-	t.logger = log.Default.Clone().AddValue(t)
+	t.logger = cl.logger.Clone().AddValue(t)
 	t.setChunkSize(defaultChunkSize)
 	return
 }

client_test.go

@@ -100,6 +100,7 @@ func TestTorrentInitialState(t *testing.T) {
 	dir, mi := testutil.GreetingTestTorrent()
 	defer os.RemoveAll(dir)
 	cl := &Client{}
+	cl.initLogger()
 	tor := cl.newTorrent(
 		mi.HashInfoBytes(),
 		storage.NewFileWithCompletion(tempDir(), storage.NewMapPieceCompletion()),
@@ -1081,7 +1082,6 @@ func TestMultipleTorrentsWithEncryption(t *testing.T) {
 	cfg.DisableUTP = true
 	cfg.Seed = true
 	cfg.DataDir = filepath.Join(cfg.DataDir, "server")
-	cfg.Debug = true
 	cfg.ForceEncryption = true
 	os.Mkdir(cfg.DataDir, 0755)
 	server, err := NewClient(cfg)
@@ -1093,7 +1093,6 @@ func TestMultipleTorrentsWithEncryption(t *testing.T) {
 	cfg = TestingConfig()
 	cfg.DisableUTP = true
 	cfg.DataDir = filepath.Join(cfg.DataDir, "client")
-	cfg.Debug = true
 	cfg.ForceEncryption = true
 	client, err := NewClient(cfg)
 	require.NoError(t, err)

portfwd.go

@@ -30,7 +30,7 @@ func (cl *Client) forwardPort() {
 	cl.mu.Unlock()
 	ds := upnp.Discover(0, 2*time.Second)
 	cl.mu.Lock()
-	flog.Default.Emit(flog.Fmsg("discovered %d upnp devices", len(ds)))
+	flog.Default.Handle(flog.Fmsg("discovered %d upnp devices", len(ds)))
 	port := cl.incomingPeerPort()
 	cl.mu.Unlock()
 	for _, d := range ds {

torrent.go

@@ -1008,6 +1008,7 @@ func (t *Torrent) pendRequest(req request) {
 }
 
 func (t *Torrent) pieceCompletionChanged(piece int) {
+	log.Call().Add("piece", piece).AddValue(debugLogValue).Log(t.logger)
 	t.cl.event.Broadcast()
 	if t.pieceComplete(piece) {
 		t.onPieceCompleted(piece)
@@ -1040,6 +1041,7 @@ func (t *Torrent) updatePieceCompletion(piece int) {
 	pcu := t.pieceCompleteUncached(piece)
 	p := &t.pieces[piece]
 	changed := t.completedPieces.Get(piece) != pcu.Complete || p.storageCompletionOk != pcu.Ok
+	log.Fmsg("piece %d completion: %v", piece, pcu.Ok).AddValue(debugLogValue).Log(t.logger)
 	p.storageCompletionOk = pcu.Ok
 	t.completedPieces.Set(piece, pcu.Complete)
 	// log.Printf("piece %d uncached completion: %v", piece, pcu.Complete)
@@ -1470,6 +1472,7 @@ func (t *Torrent) mu() missinggo.RWLocker {
 }
 
 func (t *Torrent) pieceHashed(piece int, correct bool) {
+	log.Fmsg("hashed piece %d", piece).Add("piece", piece).Add("passed", correct).AddValue(debugLogValue).Log(t.logger)
 	if t.closed.IsSet() {
 		return
 	}

torrent_test.go

@@ -147,6 +147,7 @@ func TestEmptyFilesAndZeroPieceLengthWithMMapStorage(t *testing.T) {
 func TestPieceHashFailed(t *testing.T) {
 	mi := testutil.GreetingMetaInfo()
 	cl := new(Client)
+	cl.initLogger()
 	tt := cl.newTorrent(mi.HashInfoBytes(), badStorage{})
 	tt.setChunkSize(2)
 	require.NoError(t, tt.setInfoBytes(mi.InfoBytes))