Merge pull request #190 from cshuaimin/master

Some key-value is missing in the log

handlers.go

@@ -12,7 +12,6 @@ import (
 	ds "github.com/ipfs/go-datastore"
 	u "github.com/ipfs/go-ipfs-util"
 	pb "github.com/libp2p/go-libp2p-kad-dht/pb"
-	lgbl "github.com/libp2p/go-libp2p-loggables"
 	inet "github.com/libp2p/go-libp2p-net"
 	peer "github.com/libp2p/go-libp2p-peer"
 	pstore "github.com/libp2p/go-libp2p-peerstore"
@@ -46,13 +45,9 @@ func (dht *IpfsDHT) handlerForMsgType(t pb.Message_MessageType) dhtHandler {
 }
 
 func (dht *IpfsDHT) handleGetValue(ctx context.Context, p peer.ID, pmes *pb.Message) (_ *pb.Message, err error) {
-	eip := log.EventBegin(ctx, "handleGetValue", p)
-	defer func() {
-		if err != nil {
-			eip.SetError(err)
-		}
-		eip.Done()
-	}()
+	ctx = log.Start(ctx, "handleGetValue")
+	log.SetTag(ctx, "peer", p)
+	defer func() { log.FinishWithErr(ctx, err) }()
 	log.Debugf("%s handleGetValue for key: %s", dht.self, pmes.GetKey())
 
 	// setup response
@@ -151,13 +146,9 @@ func cleanRecord(rec *recpb.Record) {
 
 // Store a value in this peer local storage
 func (dht *IpfsDHT) handlePutValue(ctx context.Context, p peer.ID, pmes *pb.Message) (_ *pb.Message, err error) {
-	eip := log.EventBegin(ctx, "handlePutValue", p)
-	defer func() {
-		if err != nil {
-			eip.SetError(err)
-		}
-		eip.Done()
-	}()
+	ctx = log.Start(ctx, "handlePutValue")
+	log.SetTag(ctx, "peer", p)
+	defer func() { log.FinishWithErr(ctx, err) }()
 
 	rec := pmes.GetRecord()
 	if rec == nil {
@@ -248,8 +239,10 @@ func (dht *IpfsDHT) handlePing(_ context.Context, p peer.ID, pmes *pb.Message) (
 	return pmes, nil
 }
 
-func (dht *IpfsDHT) handleFindPeer(ctx context.Context, p peer.ID, pmes *pb.Message) (*pb.Message, error) {
-	defer log.EventBegin(ctx, "handleFindPeer", p).Done()
+func (dht *IpfsDHT) handleFindPeer(ctx context.Context, p peer.ID, pmes *pb.Message) (_ *pb.Message, _err error) {
+	ctx = log.Start(ctx, "handleFindPeer")
+	defer func() { log.FinishWithErr(ctx, _err) }()
+	log.SetTag(ctx, "peer", p)
 	resp := pb.NewMessage(pmes.GetType(), nil, pmes.GetClusterLevel())
 	var closest []peer.ID
 
@@ -297,20 +290,17 @@ func (dht *IpfsDHT) handleFindPeer(ctx context.Context, p peer.ID, pmes *pb.Mess
 	return resp, nil
 }
 
-func (dht *IpfsDHT) handleGetProviders(ctx context.Context, p peer.ID, pmes *pb.Message) (*pb.Message, error) {
-	lm := make(lgbl.DeferredMap)
-	lm["peer"] = func() interface{} { return p.Pretty() }
-	eip := log.EventBegin(ctx, "handleGetProviders", lm)
-	defer eip.Done()
+func (dht *IpfsDHT) handleGetProviders(ctx context.Context, p peer.ID, pmes *pb.Message) (_ *pb.Message, _err error) {
+	ctx = log.Start(ctx, "handleGetProviders")
+	defer func() { log.FinishWithErr(ctx, _err) }()
+	log.SetTag(ctx, "peer", p)
 
 	resp := pb.NewMessage(pmes.GetType(), pmes.GetKey(), pmes.GetClusterLevel())
 	c, err := cid.Cast([]byte(pmes.GetKey()))
 	if err != nil {
-		eip.SetError(err)
 		return nil, err
 	}
-
-	lm["key"] = func() interface{} { return c.String() }
+	log.SetTag(ctx, "key", c)
 
 	// debug logging niceness.
 	reqDesc := fmt.Sprintf("%s handleGetProviders(%s, %s): ", dht.self, p, c)
@@ -348,19 +338,16 @@ func (dht *IpfsDHT) handleGetProviders(ctx context.Context, p peer.ID, pmes *pb.
 	return resp, nil
 }
 
-func (dht *IpfsDHT) handleAddProvider(ctx context.Context, p peer.ID, pmes *pb.Message) (*pb.Message, error) {
-	lm := make(lgbl.DeferredMap)
-	lm["peer"] = func() interface{} { return p.Pretty() }
-	eip := log.EventBegin(ctx, "handleAddProvider", lm)
-	defer eip.Done()
+func (dht *IpfsDHT) handleAddProvider(ctx context.Context, p peer.ID, pmes *pb.Message) (_ *pb.Message, _err error) {
+	ctx = log.Start(ctx, "handleAddProvider")
+	defer func() { log.FinishWithErr(ctx, _err) }()
+	log.SetTag(ctx, "peer", p)
 
 	c, err := cid.Cast([]byte(pmes.GetKey()))
 	if err != nil {
-		eip.SetError(err)
 		return nil, err
 	}
-
-	lm["key"] = func() interface{} { return c.String() }
+	log.SetTag(ctx, "key", c)
 
 	log.Debugf("%s adding %s as a provider for '%s'\n", dht.self, p, c)