Merge pull request #4135 from ipfs/feat/gc/events

gc: add events for profiling GC

pin/gc/gc.go

@@ -9,10 +9,13 @@ import (
 	dag "github.com/ipfs/go-ipfs/merkledag"
 	pin "github.com/ipfs/go-ipfs/pin"
 
+	logging "gx/ipfs/QmSpJByNKFX1sCsHBEp3R73FL4NF6FnQTEGyNAXHm2GS52/go-log"
 	cid "gx/ipfs/QmTprEaAA2A9bst5XH7exuyi5KzNMK3SEDNN8rBDnKWcUS/go-cid"
 	node "gx/ipfs/QmYNyRZJBUYPNrLszFmrBrPJbsBh2vMsefz5gnDpB5M1P6/go-ipld-format"
 )
 
+var log = logging.Logger("gc")
+
 // Result represents an incremental output from a garbage collection
 // run.  It contains either an error, or the cid of a removed object.
 type Result struct {
@@ -31,7 +34,13 @@ type Result struct {
 // deletes any block that is not found in the marked set.
 //
 func GC(ctx context.Context, bs bstore.GCBlockstore, ls dag.LinkService, pn pin.Pinner, bestEffortRoots []*cid.Cid) <-chan Result {
+
+	elock := log.EventBegin(ctx, "GC.lockWait")
 	unlocker := bs.GCLock()
+	elock.Done()
+	elock = log.EventBegin(ctx, "GC.locked")
+	emark := log.EventBegin(ctx, "GC.mark")
+
 	ls = ls.GetOfflineLinkService()
 
 	output := make(chan Result, 128)
@@ -39,12 +48,18 @@ func GC(ctx context.Context, bs bstore.GCBlockstore, ls dag.LinkService, pn pin.
 	go func() {
 		defer close(output)
 		defer unlocker.Unlock()
+		defer elock.Done()
 
 		gcs, err := ColoredSet(ctx, pn, ls, bestEffortRoots, output)
 		if err != nil {
 			output <- Result{Error: err}
 			return
 		}
+		emark.Append(logging.LoggableMap{
+			"blackSetSize": fmt.Sprintf("%d", gcs.Len()),
+		})
+		emark.Done()
+		esweep := log.EventBegin(ctx, "GC.sweep")
 
 		keychan, err := bs.AllKeysChan(ctx)
 		if err != nil {
@@ -53,6 +68,7 @@ func GC(ctx context.Context, bs bstore.GCBlockstore, ls dag.LinkService, pn pin.
 		}
 
 		errors := false
+		var removed uint64
 
 	loop:
 		for {
@@ -63,6 +79,7 @@ func GC(ctx context.Context, bs bstore.GCBlockstore, ls dag.LinkService, pn pin.
 				}
 				if !gcs.Has(k) {
 					err := bs.DeleteBlock(k)
+					removed++
 					if err != nil {
 						errors = true
 						output <- Result{Error: &CannotDeleteBlockError{k, err}}
@@ -80,6 +97,10 @@ func GC(ctx context.Context, bs bstore.GCBlockstore, ls dag.LinkService, pn pin.
 				break loop
 			}
 		}
+		esweep.Append(logging.LoggableMap{
+			"whiteSetSize": fmt.Sprintf("%d", removed),
+		})
+		esweep.Done()
 		if errors {
 			output <- Result{Error: ErrCannotDeleteSomeBlocks}
 		}