[dbnode] Add tracing for bootstrap process

src/dbnode/storage/bootstrap.go

@@ -28,6 +28,7 @@ import (
 
 	"github.com/m3db/m3/src/dbnode/clock"
 	"github.com/m3db/m3/src/dbnode/storage/bootstrap"
+	"github.com/m3db/m3/src/x/context"
 	xerrors "github.com/m3db/m3/src/x/errors"
 	"github.com/m3db/m3/src/x/instrument"
 
@@ -215,6 +216,9 @@ type bootstrapNamespace struct {
 }
 
 func (m *bootstrapManager) bootstrap() error {
+	ctx := context.NewContext()
+	defer ctx.Close()
+
 	// NB(r): construct new instance of the bootstrap process to avoid
 	// state being kept around by bootstrappers.
 	process, err := m.processProvider.Provide()
@@ -256,7 +260,7 @@ func (m *bootstrapManager) bootstrap() error {
 		i, namespace := i, namespace
 		prepareWg.Add(1)
 		go func() {
-			shards, err := namespace.PrepareBootstrap()
+			shards, err := namespace.PrepareBootstrap(ctx)
 
 			prepareLock.Lock()
 			defer func() {
@@ -338,7 +342,7 @@ func (m *bootstrapManager) bootstrap() error {
 	m.log.Info("bootstrap started", logFields...)
 
 	// Run the bootstrap.
-	bootstrapResult, err := process.Run(start, targets)
+	bootstrapResult, err := process.Run(ctx, start, targets)
 
 	bootstrapDuration := m.nowFn().Sub(start)
 	m.bootstrapDuration.Record(bootstrapDuration)
@@ -369,7 +373,7 @@ func (m *bootstrapManager) bootstrap() error {
 			return err
 		}
 
-		if err := namespace.Bootstrap(result); err != nil {
+		if err := namespace.Bootstrap(ctx, result); err != nil {
 			m.log.Info("bootstrap error", append(logFields, []zapcore.Field{
 				zap.String("namespace", id.String()),
 				zap.Error(err),

src/dbnode/storage/bootstrap/bootstrapper/base.go

@@ -25,6 +25,7 @@ import (
 
 	"github.com/m3db/m3/src/dbnode/storage/bootstrap"
 	"github.com/m3db/m3/src/dbnode/storage/bootstrap/result"
+	"github.com/m3db/m3/src/x/context"
 
 	"go.uber.org/zap"
 	"go.uber.org/zap/zapcore"
@@ -75,6 +76,7 @@ func (b baseBootstrapper) String() string {
 }
 
 func (b baseBootstrapper) Bootstrap(
+	ctx context.Context,
 	namespaces bootstrap.Namespaces,
 ) (bootstrap.NamespaceResults, error) {
 	logFields := []zapcore.Field{
@@ -135,7 +137,7 @@ func (b baseBootstrapper) Bootstrap(
 	b.log.Info("bootstrap from source started", logFields...)
 
 	// Run the bootstrap source.
-	currResults, err := b.src.Read(curr)
+	currResults, err := b.src.Read(ctx, curr)
 
 	logFields = append(logFields, zap.Duration("took", nowFn().Sub(begin)))
 	if err != nil {
@@ -164,7 +166,7 @@ func (b baseBootstrapper) Bootstrap(
 	// If there are some time ranges the current bootstrapper could not fulfill,
 	// that we can attempt then pass it along to the next bootstrapper.
 	if next.Namespaces.Len() > 0 {
-		nextResults, err := b.next.Bootstrap(next)
+		nextResults, err := b.next.Bootstrap(ctx, next)
 		if err != nil {
 			return bootstrap.NamespaceResults{}, err
 		}

src/dbnode/storage/bootstrap/bootstrapper/commitlog/source.go

@@ -37,6 +37,7 @@ import (
 	"github.com/m3db/m3/src/dbnode/storage/bootstrap/result"
 	"github.com/m3db/m3/src/dbnode/storage/series"
 	"github.com/m3db/m3/src/dbnode/topology"
+	"github.com/m3db/m3/src/dbnode/tracepoint"
 	"github.com/m3db/m3/src/dbnode/ts"
 	"github.com/m3db/m3/src/x/checked"
 	"github.com/m3db/m3/src/x/context"
@@ -168,8 +169,12 @@ type readNamespaceResult struct {
 // TODO(rartoul): Make this take the SnapshotMetadata files into account to reduce the
 // number of commitlogs / snapshots that we need to read.
 func (s *commitLogSource) Read(
+	ctx context.Context,
 	namespaces bootstrap.Namespaces,
 ) (bootstrap.NamespaceResults, error) {
+	ctx, span, _ := ctx.StartSampledTraceSpan(tracepoint.BootstrapperCommitLogSourceRead)
+	defer span.Finish()
+
 	timeRangesEmpty := true
 	for _, elem := range namespaces.Namespaces.Iter() {
 		namespace := elem.Value()
@@ -202,6 +207,8 @@ func (s *commitLogSource) Read(
 
 	startSnapshotsRead := s.nowFn()
 	s.log.Info("read snapshots start")
+	span.LogEvent("read_snapshots_start")
+
 	for _, elem := range namespaceIter {
 		ns := elem.Value()
 		accumulator := ns.DataAccumulator
@@ -252,6 +259,7 @@ func (s *commitLogSource) Read(
 
 	s.log.Info("read snapshots done",
 		zap.Duration("took", s.nowFn().Sub(startSnapshotsRead)))
+	span.LogEvent("read_snapshots_done")
 
 	// Setup the series accumulator pipeline.
 	var (
@@ -294,17 +302,19 @@ func (s *commitLogSource) Read(
 		startCommitLogsRead                        = s.nowFn()
 	)
 	s.log.Info("read commit logs start")
+	span.LogEvent("read_commitlogs_start")
 	defer func() {
 		datapointsRead := 0
 		for _, worker := range workers {
 			datapointsRead += worker.datapointsRead
 		}
-		s.log.Info("read finished",
+		s.log.Info("read commit logs done",
 			zap.Stringer("took", s.nowFn().Sub(startCommitLogsRead)),
 			zap.Int("datapointsRead", datapointsRead),
 			zap.Int("datapointsSkippedNotBootstrappingNamespace", datapointsSkippedNotBootstrappingNamespace),
 			zap.Int("datapointsSkippedNotBootstrappingShard", datapointsSkippedNotBootstrappingShard),
 			zap.Int("datapointsSkippedShardNoLongerOwned", datapointsSkippedShardNoLongerOwned))
+		span.LogEvent("read_commitlogs_done")
 	}()
 
 	iter, corruptFiles, err := s.newIteratorFn(iterOpts)

src/dbnode/storage/bootstrap/bootstrapper/fs/source.go

@@ -36,10 +36,12 @@ import (
 	"github.com/m3db/m3/src/dbnode/storage/index"
 	"github.com/m3db/m3/src/dbnode/storage/index/convert"
 	"github.com/m3db/m3/src/dbnode/storage/series"
+	"github.com/m3db/m3/src/dbnode/tracepoint"
 	"github.com/m3db/m3/src/dbnode/ts"
 	"github.com/m3db/m3/src/m3ninx/doc"
 	"github.com/m3db/m3/src/m3ninx/index/segment"
 	"github.com/m3db/m3/src/x/checked"
+	"github.com/m3db/m3/src/x/context"
 	"github.com/m3db/m3/src/x/ident"
 	"github.com/m3db/m3/src/x/instrument"
 	"github.com/m3db/m3/src/x/pool"
@@ -136,8 +138,12 @@ func (s *fileSystemSource) AvailableIndex(
 }
 
 func (s *fileSystemSource) Read(
+	ctx context.Context,
 	namespaces bootstrap.Namespaces,
 ) (bootstrap.NamespaceResults, error) {
+	ctx, span, _ := ctx.StartSampledTraceSpan(tracepoint.BootstrapperFilesystemSourceRead)
+	defer span.Finish()
+
 	results := bootstrap.NamespaceResults{
 		Results: bootstrap.NewNamespaceResultsMap(bootstrap.NamespaceResultsMapOptions{}),
 	}
@@ -151,6 +157,7 @@ func (s *fileSystemSource) Read(
 	}
 	s.log.Info("bootstrapping time series data start",
 		dataLogFields...)
+	span.LogEvent("bootstrap_data_start")
 	for _, elem := range namespaces.Namespaces.Iter() {
 		namespace := elem.Value()
 		md := namespace.Metadata
@@ -170,9 +177,11 @@ func (s *fileSystemSource) Read(
 	}
 	s.log.Info("bootstrapping time series data success",
 		append(dataLogFields, zap.Duration("took", nowFn().Sub(start)))...)
+	span.LogEvent("bootstrap_data_done")
 
 	start = nowFn()
 	s.log.Info("bootstrapping index metadata start")
+	span.LogEvent("bootstrap_index_start")
 	for _, elem := range namespaces.Namespaces.Iter() {
 		namespace := elem.Value()
 		md := namespace.Metadata
@@ -202,6 +211,7 @@ func (s *fileSystemSource) Read(
 	}
 	s.log.Info("bootstrapping index metadata success",
 		zap.Stringer("took", nowFn().Sub(start)))
+	span.LogEvent("bootstrap_index_done")
 
 	return results, nil
 }

src/dbnode/storage/bootstrap/bootstrapper/noop.go

@@ -24,6 +24,7 @@ import (
 	"fmt"
 
 	"github.com/m3db/m3/src/dbnode/storage/bootstrap"
+	"github.com/m3db/m3/src/x/context"
 )
 
 const (
@@ -61,6 +62,7 @@ func (noop noOpNoneBootstrapper) String() string {
 }
 
 func (noop noOpNoneBootstrapper) Bootstrap(
+	ctx context.Context,
 	namespaces bootstrap.Namespaces,
 ) (bootstrap.NamespaceResults, error) {
 	results := bootstrap.NewNamespaceResults(namespaces)
@@ -117,6 +119,7 @@ func (noop noOpAllBootstrapper) String() string {
 }
 
 func (noop noOpAllBootstrapper) Bootstrap(
+	ctx context.Context,
 	namespaces bootstrap.Namespaces,
 ) (bootstrap.NamespaceResults, error) {
 	return bootstrap.NewNamespaceResults(namespaces), nil

src/dbnode/storage/bootstrap/bootstrapper/peers/source.go

@@ -39,7 +39,9 @@ import (
 	"github.com/m3db/m3/src/dbnode/storage/index/convert"
 	"github.com/m3db/m3/src/dbnode/storage/series"
 	"github.com/m3db/m3/src/dbnode/topology"
+	"github.com/m3db/m3/src/dbnode/tracepoint"
 	"github.com/m3db/m3/src/m3ninx/doc"
+	"github.com/m3db/m3/src/x/context"
 	"github.com/m3db/m3/src/x/ident"
 
 	"github.com/m3db/m3/src/x/instrument"
@@ -120,8 +122,12 @@ func (s *peersSource) AvailableIndex(
 }
 
 func (s *peersSource) Read(
+	ctx context.Context,
 	namespaces bootstrap.Namespaces,
 ) (bootstrap.NamespaceResults, error) {
+	ctx, span, _ := ctx.StartSampledTraceSpan(tracepoint.BootstrapperPeersSourceRead)
+	defer span.Finish()
+
 	results := bootstrap.NamespaceResults{
 		Results: bootstrap.NewNamespaceResultsMap(bootstrap.NamespaceResultsMapOptions{}),
 	}
@@ -131,6 +137,7 @@ func (s *peersSource) Read(
 	nowFn := s.opts.ResultOptions().ClockOptions().NowFn()
 	start := nowFn()
 	s.log.Info("bootstrapping time series data start")
+	span.LogEvent("bootstrap_data_start")
 	for _, elem := range namespaces.Namespaces.Iter() {
 		namespace := elem.Value()
 		md := namespace.Metadata
@@ -150,9 +157,11 @@ func (s *peersSource) Read(
 	}
 	s.log.Info("bootstrapping time series data success",
 		zap.Duration("took", nowFn().Sub(start)))
+	span.LogEvent("bootstrap_data_done")
 
 	start = nowFn()
 	s.log.Info("bootstrapping index metadata start")
+	span.LogEvent("bootstrap_index_start")
 	for _, elem := range namespaces.Namespaces.Iter() {
 		namespace := elem.Value()
 		md := namespace.Metadata
@@ -184,6 +193,7 @@ func (s *peersSource) Read(
 	}
 	s.log.Info("bootstrapping index metadata success",
 		zap.Duration("took", nowFn().Sub(start)))
+	span.LogEvent("bootstrap_index_done")
 
 	return results, nil
 }

src/dbnode/storage/bootstrap/bootstrapper/uninitialized/source.go

@@ -28,6 +28,8 @@ import (
 	"github.com/m3db/m3/src/dbnode/storage/bootstrap"
 	"github.com/m3db/m3/src/dbnode/storage/bootstrap/result"
 	"github.com/m3db/m3/src/dbnode/topology"
+	"github.com/m3db/m3/src/dbnode/tracepoint"
+	"github.com/m3db/m3/src/x/context"
 )
 
 // The purpose of the unitializedSource is to succeed bootstraps for any
@@ -136,8 +138,12 @@ func (s *uninitializedTopologySource) availability(
 }
 
 func (s *uninitializedTopologySource) Read(
+	ctx context.Context,
 	namespaces bootstrap.Namespaces,
 ) (bootstrap.NamespaceResults, error) {
+	ctx, span, _ := ctx.StartSampledTraceSpan(tracepoint.BootstrapperUninitializedSourceRead)
+	defer span.Finish()
+
 	results := bootstrap.NamespaceResults{
 		Results: bootstrap.NewNamespaceResultsMap(bootstrap.NamespaceResultsMapOptions{}),
 	}

src/dbnode/storage/bootstrap/noop.go

@@ -22,6 +22,8 @@ package bootstrap
 
 import (
 	"time"
+
+	"github.com/m3db/m3/src/x/context"
 )
 
 type noOpBootstrapProcessProvider struct{}
@@ -45,6 +47,7 @@ func (b noOpBootstrapProcessProvider) Provide() (Process, error) {
 type noOpBootstrapProcess struct{}
 
 func (b noOpBootstrapProcess) Run(
+	ctx context.Context,
 	start time.Time,
 	namespaces []ProcessNamespace,
 ) (NamespaceResults, error) {