From 17ea476a873018ed2dff099a3817d99ac58b85a9 Mon Sep 17 00:00:00 2001 From: irfan sharif Date: Tue, 12 Jan 2021 18:53:11 -0500 Subject: [PATCH] tracing: enable always-on tracing by default This is follow-up work from #58712, where we measured the overhead for always-on tracing and found it to be minimal/acceptable. Lets switch this on by default to shake the implications of doing so. We can reasonably expect two kinds of fallout: (1) Unexpected blow up in memory usage due to resource leakage (which is a can be problem now that we're always maintaining open spans in an internal registry, see #58721) (2) Performance degradataion due to tracing overhead per-request (something #58712) was spot checking for. For (1) we'll introduce a future test in a separate PR. For (2), we'll monitor roachperf over the next few weeks. --- Also moved some of the documentation for the cluster setting into a comment form above. Looking at what's rendered in our other cluster settings (`SHOW ALL CLUSTER SETTINGS`), we default to a very pithy, unwrapped description. Release note: None --- pkg/sql/distsql_running.go | 3 +- pkg/sql/execinfra/processorsbase.go | 2 +- pkg/sql/flowinfra/cluster_test.go | 15 ++++++ pkg/sql/flowinfra/server_test.go | 1 + pkg/sql/physicalplan/aggregator_funcs_test.go | 2 +- pkg/util/tracing/tracer.go | 46 +++++++++---------- 6 files changed, 41 insertions(+), 28 deletions(-) diff --git a/pkg/sql/distsql_running.go b/pkg/sql/distsql_running.go index 278cd82fcdb0..06f396acda47 100644 --- a/pkg/sql/distsql_running.go +++ b/pkg/sql/distsql_running.go @@ -644,8 +644,7 @@ func (r *DistSQLReceiver) Push( if len(meta.TraceData) > 0 { span := tracing.SpanFromContext(r.ctx) if span == nil { - r.resultWriter.SetError( - errors.New("trying to ingest remote spans but there is no recording span set up")) + // Nothing to do. } else if err := span.ImportRemoteSpans(meta.TraceData); err != nil { r.resultWriter.SetError(errors.Errorf("error ingesting remote spans: %s", err)) } diff --git a/pkg/sql/execinfra/processorsbase.go b/pkg/sql/execinfra/processorsbase.go index 726c2dc68edc..0ac102870f33 100644 --- a/pkg/sql/execinfra/processorsbase.go +++ b/pkg/sql/execinfra/processorsbase.go @@ -575,7 +575,7 @@ const ( // returned from now on. In this state, the processor is expected to drain its // inputs (commonly by using DrainHelper()). // -// If the processor has no input (ProcStateOpts.intputToDrain was not specified +// If the processor has no input (ProcStateOpts.inputToDrain was not specified // at init() time), then we move straight to the StateTrailingMeta. // // An error can be optionally passed. It will be the first piece of metadata diff --git a/pkg/sql/flowinfra/cluster_test.go b/pkg/sql/flowinfra/cluster_test.go index f001207c7b7d..b8aa35c4a9c9 100644 --- a/pkg/sql/flowinfra/cluster_test.go +++ b/pkg/sql/flowinfra/cluster_test.go @@ -271,6 +271,7 @@ func TestClusterFlow(t *testing.T) { metas = ignoreMisplannedRanges(metas) metas = ignoreLeafTxnState(metas) metas = ignoreMetricsMeta(metas) + metas = ignoreTraceData(metas) if len(metas) != 0 { t.Fatalf("unexpected metadata (%d): %+v", len(metas), metas) } @@ -327,6 +328,18 @@ func ignoreMetricsMeta(metas []execinfrapb.ProducerMetadata) []execinfrapb.Produ return res } +// ignoreTraceData takes a slice of metadata and returns the entries +// excluding the ones with trace data. +func ignoreTraceData(metas []execinfrapb.ProducerMetadata) []execinfrapb.ProducerMetadata { + res := make([]execinfrapb.ProducerMetadata, 0) + for _, m := range metas { + if m.TraceData == nil { + res = append(res, m) + } + } + return res +} + // TestLimitedBufferingDeadlock sets up a scenario which leads to deadlock if // a single consumer can block the entire router (#17097). func TestLimitedBufferingDeadlock(t *testing.T) { @@ -545,6 +558,7 @@ func TestLimitedBufferingDeadlock(t *testing.T) { metas = ignoreMisplannedRanges(metas) metas = ignoreLeafTxnState(metas) metas = ignoreMetricsMeta(metas) + metas = ignoreTraceData(metas) if len(metas) != 0 { t.Errorf("unexpected metadata (%d): %+v", len(metas), metas) } @@ -852,6 +866,7 @@ func BenchmarkInfrastructure(b *testing.B) { metas = ignoreMisplannedRanges(metas) metas = ignoreLeafTxnState(metas) metas = ignoreMetricsMeta(metas) + metas = ignoreTraceData(metas) if len(metas) != 0 { b.Fatalf("unexpected metadata (%d): %+v", len(metas), metas) } diff --git a/pkg/sql/flowinfra/server_test.go b/pkg/sql/flowinfra/server_test.go index 9d9f909ac0ce..032d036fdd0f 100644 --- a/pkg/sql/flowinfra/server_test.go +++ b/pkg/sql/flowinfra/server_test.go @@ -108,6 +108,7 @@ func TestServer(t *testing.T) { } metas = ignoreLeafTxnState(metas) metas = ignoreMetricsMeta(metas) + metas = ignoreTraceData(metas) if len(metas) != 0 { t.Errorf("unexpected metadata: %v", metas) } diff --git a/pkg/sql/physicalplan/aggregator_funcs_test.go b/pkg/sql/physicalplan/aggregator_funcs_test.go index 05b922133af8..c780fdf34bb0 100644 --- a/pkg/sql/physicalplan/aggregator_funcs_test.go +++ b/pkg/sql/physicalplan/aggregator_funcs_test.go @@ -92,7 +92,7 @@ func runTestFlow( for { row, meta := rowBuf.Next() if meta != nil { - if meta.LeafTxnFinalState != nil || meta.Metrics != nil { + if meta.LeafTxnFinalState != nil || meta.Metrics != nil || meta.TraceData != nil { continue } t.Fatalf("unexpected metadata: %v", meta) diff --git a/pkg/util/tracing/tracer.go b/pkg/util/tracing/tracer.go index 6782151126ce..74135dba8448 100644 --- a/pkg/util/tracing/tracer.go +++ b/pkg/util/tracing/tracer.go @@ -62,32 +62,30 @@ const ( modeBackground ) -// tracingMode informs the creation of noop spans -// and the default recording mode of created spans. +// tracingMode informs the creation of noop spans and the default recording mode +// of created spans. +// +// If set to 'background', trace spans will be created for all operations, but +// these will record sparse structured information, unless an operation +// explicitly requests the verbose from. It's optimized for low overhead, and +// powers fine-grained statistics and alerts. +// +// If set to 'legacy', trace spans will not be created by default. This is +// unless an internal code path explicitly requests for it, or if an auxiliary +// tracer (such as lightstep or zipkin) is configured. This tracing mode always +// records in the verbose form. Using this mode has two effects: the +// observability of the cluster may be degraded (as most trace spans are elided) +// and where trace spans are created, they may consume large amounts of memory. +// +// Note that regardless of this setting, configuring an auxiliary trace sink +// will cause verbose traces to be created for all operations, which may lead to +// high memory consumption. It is not currently possible to send non-verbose +// traces to auxiliary sinks. var tracingMode = settings.RegisterEnumSetting( "trace.mode", - `configures the CockroachDB-internal tracing subsystem. - -If set to 'background', trace spans will be created for all operations, but -these trace spans will only be recording sparse structured information, -unless an operation explicitly requests verbose recording. This is -optimized for low overhead, and powers fine-grained statistics and alerts. - -If set to 'legacy', trace spans will not be created (unless an -auxiliary tracer such as Lightstep or Zipkin, is configured, or an -internal code path explicitly requests a trace to be created) but -when they are, they record verbose information. This has two effects: -the observability of the cluster may be degraded (as some trace spans -are elided) and where trace spans are created, they may consume large -amounts of memory. This mode should not be used with auxiliary tracing -sinks as that leads to expensive trace spans being created throughout. - -Note that regardless of this setting, configuring an auxiliary -trace sink will cause verbose traces to be created for all -operations, which may lead to high memory consumption. It is not -currently possible to send non-verbose traces to auxiliary sinks. -`, - "legacy", + "if set to 'background', traces will be created for all operations (in"+ + "'legacy' mode it's created when explicitly requested or when auxiliary tracers are configured)", + "background", map[int64]string{ int64(modeLegacy): "legacy", int64(modeBackground): "background",