From 59aafb3259487ea7ce40881efe99135a92836204 Mon Sep 17 00:00:00 2001 From: Rafi Shamim Date: Sat, 30 Oct 2021 16:56:03 -0400 Subject: [PATCH 1/5] roachtest: pass option to sequelize test correctly Release note: None --- pkg/cmd/roachtest/tests/sequelize.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/cmd/roachtest/tests/sequelize.go b/pkg/cmd/roachtest/tests/sequelize.go index 3ffa7a9fd131..828f18110d21 100644 --- a/pkg/cmd/roachtest/tests/sequelize.go +++ b/pkg/cmd/roachtest/tests/sequelize.go @@ -141,7 +141,7 @@ func registerSequelize(r registry.Registry) { // Version telemetry is already disabled in the sequelize-cockroachdb test suite. t.Status("running Sequelize test suite") rawResults, err := c.RunWithBuffer(ctx, t.L(), node, - fmt.Sprintf(`cd /mnt/data1/sequelize/ && CRDB_VERSION=%s npm test`, version), + fmt.Sprintf(`cd /mnt/data1/sequelize/ && npm test --crdb_version=%s`, version), ) rawResultsStr := string(rawResults) t.L().Printf("Test Results: %s", rawResultsStr) From 297a7762ab0c63539fb1f1d004427ef813383dd6 Mon Sep 17 00:00:00 2001 From: Andrei Matei Date: Thu, 28 Oct 2021 17:22:01 -0400 Subject: [PATCH 2/5] sql: minor comment improvements Release note: None --- pkg/sql/exec_util.go | 9 ++++----- 1 file changed, 4 insertions(+), 5 deletions(-) diff --git a/pkg/sql/exec_util.go b/pkg/sql/exec_util.go index b99b05a2e878..00648b78f880 100644 --- a/pkg/sql/exec_util.go +++ b/pkg/sql/exec_util.go @@ -2032,7 +2032,8 @@ func (st *SessionTracing) StartTracing( } // If we're inside a transaction, hijack the txn's ctx with one that has a - // recording span. + // recording span. The recording of this first transaction will be collected + // separately from the recording of future transactions. if _, ok := st.ex.machine.CurState().(stateNoTxn); !ok { txnCtx := st.ex.state.Ctx if sp := tracing.SpanFromContext(txnCtx); sp == nil { @@ -2051,8 +2052,8 @@ func (st *SessionTracing) StartTracing( st.showResults = showResults st.recordingType = recType - // Now hijack the conn's ctx with one that has a recording span. - + // Now hijack the conn's ctx with one that has a recording span. All future + // transactions will inherit from this span, so they'll all be recorded. connCtx := st.ex.ctxHolder.connCtx opName := "session recording" newConnCtx, sp := tracing.EnsureChildSpan( @@ -2063,8 +2064,6 @@ func (st *SessionTracing) StartTracing( ) sp.SetVerbose(true) st.connSpan = sp - - // Hijack the connections context. st.ex.ctxHolder.hijack(newConnCtx) return nil From a6558fd5e6757bff716943f95e30baeaa1e267d1 Mon Sep 17 00:00:00 2001 From: Andrei Matei Date: Thu, 28 Oct 2021 17:45:15 -0400 Subject: [PATCH 3/5] sql: fix and simplify session tracing span mgmt Before this patch, session tracing was broken in two ways: - it leaked a span, corresponding to the transaction that was ongoing when session tracing is initiated. Session tracing was replacing that span in the connection's tracking, and so nobody was ever Finish()ing it. - it exposed a span to use-after-finish. This is the span that replaced the span discussed above. When session tracing is initiated in a transaction, it overwrote the txn's span. When session tracing was finished, it finished that span. But, in case tracing is finished in the same txn as the one it started in, then that span is still referenced by the connection. This patch fixes these issues and also simplifies how session tracing works. We do away with the special handling of the transaction during which tracing starts. Instead, we just give this transaction a span inheriting from the same recording span that future transactions will inherit from. The SessionTracing struct gets out of the business of owning any spans. Release note: None --- pkg/sql/exec_util.go | 75 ++++++++----------- .../testdata/logic_test/inflight_trace_spans | 3 + 2 files changed, 34 insertions(+), 44 deletions(-) diff --git a/pkg/sql/exec_util.go b/pkg/sql/exec_util.go index 00648b78f880..c4d12249a064 100644 --- a/pkg/sql/exec_util.go +++ b/pkg/sql/exec_util.go @@ -1950,10 +1950,6 @@ type SessionTracing struct { // ex is the connExecutor to which this SessionTracing is tied. ex *connExecutor - // firstTxnSpan is the span of the first txn that was active when session - // tracing was enabled. It is finished and unset in StopTracing. - firstTxnSpan *tracing.Span - // connSpan is the connection's span. This is recording. It is finished and // unset in StopTracing. connSpan *tracing.Span @@ -1970,16 +1966,7 @@ func (st *SessionTracing) getSessionTrace() ([]traceRow, error) { return st.lastRecording, nil } - return generateSessionTraceVTable(st.getRecording()) -} - -// getRecording returns the recorded spans of the current trace. -func (st *SessionTracing) getRecording() []tracingpb.RecordedSpan { - var spans []tracingpb.RecordedSpan - if st.firstTxnSpan != nil { - spans = append(spans, st.firstTxnSpan.GetRecording()...) - } - return append(spans, st.connSpan.GetRecording()...) + return generateSessionTraceVTable(st.connSpan.GetRecording()) } // StartTracing starts "session tracing". From this moment on, everything @@ -2031,20 +2018,36 @@ func (st *SessionTracing) StartTracing( return nil } + // Hijack the conn's ctx with one that has a recording span. All future + // transactions will inherit from this span, so they'll all be recorded. + var newConnCtx context.Context + { + connCtx := st.ex.ctxHolder.connCtx + opName := "session recording" + newConnCtx, st.connSpan = tracing.EnsureChildSpan( + connCtx, + st.ex.server.cfg.AmbientCtx.Tracer, + opName, + tracing.WithForceRealSpan(), + ) + st.connSpan.SetVerbose(true) + st.ex.ctxHolder.hijack(newConnCtx) + } + // If we're inside a transaction, hijack the txn's ctx with one that has a - // recording span. The recording of this first transaction will be collected - // separately from the recording of future transactions. + // recording span. if _, ok := st.ex.machine.CurState().(stateNoTxn); !ok { txnCtx := st.ex.state.Ctx - if sp := tracing.SpanFromContext(txnCtx); sp == nil { + sp := tracing.SpanFromContext(txnCtx) + if sp == nil { return errors.Errorf("no txn span for SessionTracing") } + // We're hijacking this span and we're never going to un-hijack it, so it's + // up to us to finish it. + sp.Finish() - newTxnCtx, sp := tracing.EnsureChildSpan(txnCtx, st.ex.server.cfg.AmbientCtx.Tracer, - "session tracing", tracing.WithForceRealSpan()) - sp.SetVerbose(true) - st.ex.state.Ctx = newTxnCtx - st.firstTxnSpan = sp + st.ex.state.Ctx, _ = tracing.EnsureChildSpan( + newConnCtx, st.ex.server.cfg.AmbientCtx.Tracer, "session tracing") } st.enabled = true @@ -2052,20 +2055,6 @@ func (st *SessionTracing) StartTracing( st.showResults = showResults st.recordingType = recType - // Now hijack the conn's ctx with one that has a recording span. All future - // transactions will inherit from this span, so they'll all be recorded. - connCtx := st.ex.ctxHolder.connCtx - opName := "session recording" - newConnCtx, sp := tracing.EnsureChildSpan( - connCtx, - st.ex.server.cfg.AmbientCtx.Tracer, - opName, - tracing.WithForceRealSpan(), - ) - sp.SetVerbose(true) - st.connSpan = sp - st.ex.ctxHolder.hijack(newConnCtx) - return nil } @@ -2081,19 +2070,17 @@ func (st *SessionTracing) StopTracing() error { st.recordingType = tracing.RecordingOff // Accumulate all recordings and finish the tracing spans. - var spans []tracingpb.RecordedSpan - if st.firstTxnSpan != nil { - spans = append(spans, st.firstTxnSpan.GetRecording()...) - st.firstTxnSpan.Finish() - st.firstTxnSpan = nil - } - spans = append(spans, st.connSpan.GetRecording()...) + rec := st.connSpan.GetRecording() + // We're about to finish this span, but there might be a child that remains + // open - the child corresponding to the current transaction. We don't want + // that span to be recording any more. + st.connSpan.SetVerbose(false) st.connSpan.Finish() st.connSpan = nil st.ex.ctxHolder.unhijack() var err error - st.lastRecording, err = generateSessionTraceVTable(spans) + st.lastRecording, err = generateSessionTraceVTable(rec) return err } diff --git a/pkg/sql/logictest/testdata/logic_test/inflight_trace_spans b/pkg/sql/logictest/testdata/logic_test/inflight_trace_spans index cbe1b280e2e4..bd63f8404ea1 100644 --- a/pkg/sql/logictest/testdata/logic_test/inflight_trace_spans +++ b/pkg/sql/logictest/testdata/logic_test/inflight_trace_spans @@ -40,6 +40,9 @@ statement ok INSERT INTO kv VALUES('k', 'v'); COMMIT +statement ok +SET TRACING = off + # Confirm that the trace and its associated spans are no longer tracked. query B SELECT count(*) = 0 From f08577804d4c264680a384a35c482f599823e1ec Mon Sep 17 00:00:00 2001 From: Nathan Stilwell Date: Wed, 3 Nov 2021 17:55:31 -0400 Subject: [PATCH 4/5] server: Return permission error if one occurs for Events endpoint Events in DB Console (`/#/events`) would show an internal server error to the user if they did not have admin permissions to view events. The error logged in the server is indeed a permissions error, but this is confusing to the user. To accurately show a permission error on the FrontEnd, I added an AND statment to the Events endpoint to only return a server error if an error exists and is not a permission error. Release note (ui change): Node events will now display a permission error rather than an internal server error when user does not have admin priviledges to view events. --- pkg/server/admin.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/server/admin.go b/pkg/server/admin.go index 09edc75990b8..9a6af33206f9 100644 --- a/pkg/server/admin.go +++ b/pkg/server/admin.go @@ -1219,7 +1219,7 @@ func (s *adminServer) Events( // to not use serverError* methods in the body of the function, so we can // just do it here. defer func() { - if retErr != nil { + if retErr != nil && !errors.Is(retErr, errRequiresAdmin) { retErr = s.serverError(retErr) } }() From 365323544a40ac8a73db0252e9c295a2298d7938 Mon Sep 17 00:00:00 2001 From: Andrei Matei Date: Thu, 4 Nov 2021 14:58:06 -0400 Subject: [PATCH 5/5] tracing: fix tracer closing ContextWithRecording span was closing the passed-in Tracer, which is completely wrong. This has been broken since a long time ago; the function originally was written to create its own Tracer but then changed to take in a Tracer and the bad close remained. As a practical consequence, tracing to external tracers stopped whenever one of the debug pages that uses this utility was used. Release note (bug fix): Fixed a bug causing tracing to external tracers to inadvertently stop after the Enqueue Range or the Allocator debug pages was used. --- pkg/util/tracing/tracer.go | 1 - 1 file changed, 1 deletion(-) diff --git a/pkg/util/tracing/tracer.go b/pkg/util/tracing/tracer.go index 865932f5ddd0..cd76cac419eb 100644 --- a/pkg/util/tracing/tracer.go +++ b/pkg/util/tracing/tracer.go @@ -1057,7 +1057,6 @@ func ContextWithRecordingSpan( cancel = func() { cancelCtx() sp.Finish() - tr.Close() } return ctx, sp.GetRecording, cancel }