From 54beca4717b8d3ff6afaa0d12004f041a8d72578 Mon Sep 17 00:00:00 2001 From: Solon Gordon Date: Thu, 1 Mar 2018 13:20:56 -0500 Subject: [PATCH] sql: tag crash reports with relevant statement Our Sentry reports now include an anonymized version of the relevant SQL statement if it is set in the context, and I modified connExecutor to add the statement to the context whenever curStmt is set. This means that "unexpected leftover bytes" reports now include the statement again. (The statement stopped being reported when we changed that from a panic to a warning in 91ed508.) Fixes #22865 Release note: None --- pkg/sql/conn_executor.go | 43 ++++++++++++++++++++++++++++++--- pkg/sql/session.go | 25 +++++-------------- pkg/util/log/crash_reporting.go | 32 +++++++++++++++++++++++- 3 files changed, 76 insertions(+), 24 deletions(-) diff --git a/pkg/sql/conn_executor.go b/pkg/sql/conn_executor.go index d5bee0fb6a0c..4856a11de76e 100644 --- a/pkg/sql/conn_executor.go +++ b/pkg/sql/conn_executor.go @@ -907,7 +907,8 @@ func (ex *connExecutor) run(ctx context.Context) error { ex.phaseTimes[sessionStartParse] = tcmd.ParseStart ex.phaseTimes[sessionEndParse] = tcmd.ParseEnd - ev, payload, err = ex.execStmt(ex.Ctx(), curStmt, stmtRes, nil /* pinfo */, pos) + ctx := withStatement(ex.Ctx(), ex.curStmt) + ev, payload, err = ex.execStmt(ctx, curStmt, stmtRes, nil /* pinfo */, pos) if err != nil { return err } @@ -959,14 +960,16 @@ func (ex *connExecutor) run(ctx context.Context) error { ExpectedTypes: portal.Stmt.Columns, AnonymizedStr: portal.Stmt.AnonymizedStr, } - ev, payload, err = ex.execStmt(ex.Ctx(), curStmt, stmtRes, pinfo, pos) + ctx := withStatement(ex.Ctx(), ex.curStmt) + ev, payload, err = ex.execStmt(ctx, curStmt, stmtRes, pinfo, pos) if err != nil { return err } case PrepareStmt: ex.curStmt = tcmd.Stmt res = ex.clientComm.CreatePrepareResult(pos) - ev, payload = ex.execPrepare(ex.Ctx(), tcmd) + ctx := withStatement(ex.Ctx(), ex.curStmt) + ev, payload = ex.execPrepare(ctx, tcmd) case DescribeStmt: descRes := ex.clientComm.CreateDescribeResult(pos) res = descRes @@ -1632,7 +1635,8 @@ func (ex *connExecutor) txnStateTransitionsApplyWrapper( implicitTxn = os.ImplicitTxn.Get() } - err := ex.machine.ApplyWithPayload(ex.Ctx(), ev, payload) + ctx := withStatement(ex.Ctx(), ex.curStmt) + err := ex.machine.ApplyWithPayload(ctx, ev, payload) if err != nil { if _, ok := err.(fsm.TransitionNotFoundError); ok { panic(err) @@ -1899,3 +1903,34 @@ func (ps connExPrepStmtsAccessor) DeleteAll(ctx context.Context) { portals: make(map[string]portalEntry), } } + +// contextStatementKey is an empty type for the handle associated with the +// statement value (see context.Value). +type contextStatementKey struct{} + +// withStatement adds a SQL statement to the provided context. The statement +// will then be included in crash reports which use that context. +func withStatement(ctx context.Context, stmt tree.Statement) context.Context { + return context.WithValue(ctx, contextStatementKey{}, stmt) +} + +// statementFromCtx returns the statement value from a context, or nil if unset. +func statementFromCtx(ctx context.Context) tree.Statement { + stmt := ctx.Value(contextStatementKey{}) + if stmt == nil { + return nil + } + return stmt.(tree.Statement) +} + +func init() { + // Register a function to include the anonymized statement in crash reports. + log.RegisterTagFn("statement", func(ctx context.Context) string { + stmt := statementFromCtx(ctx) + if stmt == nil { + return "" + } + // Anonymize the statement for reporting. + return anonymizeStmtAndConstants(stmt) + }) +} diff --git a/pkg/sql/session.go b/pkg/sql/session.go index 1cb0218ccec5..ab9b44611ea0 100644 --- a/pkg/sql/session.go +++ b/pkg/sql/session.go @@ -15,7 +15,6 @@ package sql import ( - "bytes" "context" "fmt" "net" @@ -1389,6 +1388,10 @@ func (scc *schemaChangerCollection) execSchemaChanges( const panicLogOutputCutoffChars = 500 +func anonymizeStmtAndConstants(stmt tree.Statement) string { + return tree.AsStringWithFlags(stmt, tree.FmtAnonymize|tree.FmtHideConstants) +} + // AnonymizeStatementsForReporting transforms an action, SQL statements, and a value // (usually a recovered panic) into an error that will be useful when passed to // our error reporting as it exposes a scrubbed version of the statements. @@ -1397,24 +1400,8 @@ func AnonymizeStatementsForReporting(action, sqlStmts string, r interface{}) err { stmts, err := parser.Parse(sqlStmts) if err == nil { - var f struct { - buf bytes.Buffer - anonCtx, hideCtx tree.FmtCtx - } - f.anonCtx = tree.MakeFmtCtx(&f.buf, tree.FmtAnonymize) - f.hideCtx = tree.MakeFmtCtx(&f.buf, tree.FmtHideConstants) - for _, stmt := range NewStatementList(stmts) { - f.anonCtx.FormatNode(stmt.AST) - stmt.AST, err = parser.ParseOne(f.buf.String()) - f.buf.Reset() - if err != nil { - f.buf.WriteString("[unknown]") - } else { - f.hideCtx.FormatNode(stmt.AST) - } - - anonymized = append(anonymized, f.buf.String()) - f.buf.Reset() + for _, stmt := range stmts { + anonymized = append(anonymized, anonymizeStmtAndConstants(stmt)) } } } diff --git a/pkg/util/log/crash_reporting.go b/pkg/util/log/crash_reporting.go index 47c879d31bdd..149572eade8d 100644 --- a/pkg/util/log/crash_reporting.go +++ b/pkg/util/log/crash_reporting.go @@ -437,6 +437,14 @@ func SendCrashReport( tags := map[string]string{ "uptime": uptimeTag(timeutil.Now()), } + + for _, f := range tagFns { + v := f.value(ctx) + if v != "" { + tags[f.key] = maybeTruncate(v) + } + } + eventID, ch := raven.DefaultClient.Capture(packet, tags) select { case <-ch: @@ -460,5 +468,27 @@ func ReportOrPanic( panic(fmt.Sprintf(format, reportables...)) } Warningf(ctx, format, reportables...) - SendCrashReport(ctx, sv, 0 /* depth */, format, reportables) + SendCrashReport(ctx, sv, 1 /* depth */, format, reportables) +} + +const maxTagLen = 500 + +func maybeTruncate(tagValue string) string { + if len(tagValue) > maxTagLen { + return tagValue[:maxTagLen] + " [...]" + } + return tagValue +} + +type tagFn struct { + key string + value func(context.Context) string +} + +var tagFns []tagFn + +// RegisterTagFn adds a function for tagging crash reports based on the context. +// This is intended to be called by other packages at init time. +func RegisterTagFn(key string, value func(context.Context) string) { + tagFns = append(tagFns, tagFn{key, value}) }