diff --git a/executor/adapter.go b/executor/adapter.go index 7321a2c710893..b77f2a68e16ad 100644 --- a/executor/adapter.go +++ b/executor/adapter.go @@ -41,10 +41,12 @@ import ( "github.com/pingcap/tidb/sessionctx" "github.com/pingcap/tidb/sessionctx/variable" "github.com/pingcap/tidb/store/tikv" + "github.com/pingcap/tidb/types" "github.com/pingcap/tidb/util/chunk" "github.com/pingcap/tidb/util/logutil" "github.com/pingcap/tidb/util/sqlexec" "github.com/pingcap/tidb/util/stmtsummary" + "github.com/pingcap/tidb/util/stringutil" "go.uber.org/zap" "go.uber.org/zap/zapcore" ) @@ -134,7 +136,8 @@ func (a *recordSet) Close() error { err := a.executor.Close() a.stmt.LogSlowQuery(a.txnStartTS, a.lastErr == nil) sessVars := a.stmt.Ctx.GetSessionVars() - sessVars.PrevStmt = FormatSQL(a.stmt.OriginText(), sessVars) + pps := types.CloneRow(sessVars.PreparedParams) + sessVars.PrevStmt = FormatSQL(a.stmt.OriginText(), pps) a.stmt.logAudit() a.stmt.SummaryStmt() return err @@ -618,13 +621,15 @@ func (a *ExecStmt) logAudit() { } // FormatSQL is used to format the original SQL, e.g. truncating long SQL, appending prepared arguments. -func FormatSQL(sql string, sessVars *variable.SessionVars) string { - cfg := config.GetGlobalConfig() - length := len(sql) - if maxQueryLen := atomic.LoadUint64(&cfg.Log.QueryLogMaxLen); uint64(length) > maxQueryLen { - sql = fmt.Sprintf("%.*q(len:%d)", maxQueryLen, sql, length) +func FormatSQL(sql string, pps variable.PreparedParams) stringutil.StringerFunc { + return func() string { + cfg := config.GetGlobalConfig() + length := len(sql) + if maxQueryLen := atomic.LoadUint64(&cfg.Log.QueryLogMaxLen); uint64(length) > maxQueryLen { + sql = fmt.Sprintf("%.*q(len:%d)", maxQueryLen, sql, length) + } + return QueryReplacer.Replace(sql) + pps.String() } - return QueryReplacer.Replace(sql) + sessVars.GetExecuteArgumentsInfo() } // LogSlowQuery is used to print the slow query in the log files. @@ -637,7 +642,7 @@ func (a *ExecStmt) LogSlowQuery(txnTS uint64, succ bool) { if costTime < threshold && level > zapcore.DebugLevel { return } - sql := FormatSQL(a.Text, sessVars) + sql := FormatSQL(a.Text, sessVars.PreparedParams) var tableIDs, indexNames string if len(sessVars.StmtCtx.TableIDs) > 0 { @@ -653,7 +658,7 @@ func (a *ExecStmt) LogSlowQuery(txnTS uint64, succ bool) { _, digest := sessVars.StmtCtx.SQLDigest() slowItems := &variable.SlowQueryLogItems{ TxnTS: txnTS, - SQL: sql, + SQL: sql.String(), Digest: digest, TimeTotal: costTime, TimeParse: a.Ctx.GetSessionVars().DurationParse, @@ -666,7 +671,7 @@ func (a *ExecStmt) LogSlowQuery(txnTS uint64, succ bool) { Succ: succ, } if _, ok := a.StmtNode.(*ast.CommitStmt); ok { - slowItems.PrevStmt = sessVars.PrevStmt + slowItems.PrevStmt = sessVars.PrevStmt.String() } if costTime < threshold { logutil.SlowQueryLogger.Debug(sessVars.SlowLogFormat(slowItems)) @@ -680,7 +685,7 @@ func (a *ExecStmt) LogSlowQuery(txnTS uint64, succ bool) { userString = sessVars.User.String() } domain.GetDomain(a.Ctx).LogSlowQuery(&domain.SlowQueryInfo{ - SQL: sql, + SQL: sql.String(), Digest: digest, Start: a.Ctx.GetSessionVars().StartTime, Duration: costTime, diff --git a/server/conn_stmt.go b/server/conn_stmt.go index 29b2d120b5037..28acbb02666a8 100644 --- a/server/conn_stmt.go +++ b/server/conn_stmt.go @@ -577,7 +577,7 @@ func (cc *clientConn) handleSetOption(data []byte) (err error) { func (cc *clientConn) preparedStmt2String(stmtID uint32) string { sv := cc.ctx.GetSessionVars() if prepared, ok := sv.PreparedStmts[stmtID]; ok { - return prepared.Stmt.Text() + sv.GetExecuteArgumentsInfo() + return prepared.Stmt.Text() + sv.PreparedParams.String() } return "prepared statement not found, ID: " + strconv.FormatUint(uint64(stmtID), 10) } diff --git a/session/session.go b/session/session.go index 10fb854c0c487..913a71095f021 100644 --- a/session/session.go +++ b/session/session.go @@ -615,7 +615,7 @@ func (s *session) retry(ctx context.Context, maxCnt uint) (err error) { zap.Int64("schemaVersion", schemaVersion), zap.Uint("retryCnt", retryCnt), zap.Int("queryNum", i), - zap.String("sql", sqlForLog(st.OriginText())+sessVars.GetExecuteArgumentsInfo())) + zap.String("sql", sqlForLog(st.OriginText())+sessVars.PreparedParams.String())) } else { logutil.Logger(ctx).Warn("retrying", zap.Int64("schemaVersion", schemaVersion), @@ -1891,7 +1891,7 @@ func logQuery(query string, vars *variable.SessionVars) { zap.Int64("schemaVersion", vars.TxnCtx.SchemaVersion), zap.Uint64("txnStartTS", vars.TxnCtx.StartTS), zap.String("current_db", vars.CurrentDB), - zap.String("sql", query+vars.GetExecuteArgumentsInfo())) + zap.String("sql", query+vars.PreparedParams.String())) } } diff --git a/session/tidb.go b/session/tidb.go index 19e26e299324a..60edbdf90629d 100644 --- a/session/tidb.go +++ b/session/tidb.go @@ -35,6 +35,7 @@ import ( "github.com/pingcap/tidb/kv" "github.com/pingcap/tidb/sessionctx" "github.com/pingcap/tidb/sessionctx/variable" + "github.com/pingcap/tidb/types" "github.com/pingcap/tidb/util" "github.com/pingcap/tidb/util/chunk" "github.com/pingcap/tidb/util/logutil" @@ -225,7 +226,8 @@ func runStmt(ctx context.Context, sctx sessionctx.Context, s sqlexec.Statement) if rs == nil { s.(*executor.ExecStmt).LogSlowQuery(origTxnCtx.StartTS, err == nil) s.(*executor.ExecStmt).SummaryStmt() - sessVars.PrevStmt = executor.FormatSQL(s.OriginText(), sessVars) + pps := types.CloneRow(sessVars.PreparedParams) + sessVars.PrevStmt = executor.FormatSQL(s.OriginText(), pps) } }() diff --git a/sessionctx/variable/session.go b/sessionctx/variable/session.go index 5c23852238799..c004dd1d80825 100644 --- a/sessionctx/variable/session.go +++ b/sessionctx/variable/session.go @@ -206,7 +206,7 @@ type SessionVars struct { // preparedStmtID is id of prepared statement. preparedStmtID uint32 // PreparedParams params for prepared statements - PreparedParams []types.Datum + PreparedParams PreparedParams // ActiveRoles stores active roles for current user ActiveRoles []*auth.RoleIdentity @@ -409,6 +409,16 @@ type SessionVars struct { PrevStmt string } +// PreparedParams contains the parameters of the current prepared statement when executing it. +type PreparedParams []types.Datum + +func (pps PreparedParams) String() string { + if len(pps) == 0 { + return "" + } + return " [arguments: " + types.DatumsToStrNoErr(pps) + "]" +} + // ConnectionInfo present connection used by audit. type ConnectionInfo struct { ConnectionID uint32 @@ -584,26 +594,6 @@ func (s *SessionVars) Location() *time.Location { return loc } -// GetExecuteArgumentsInfo gets the argument list as a string of execute statement. -func (s *SessionVars) GetExecuteArgumentsInfo() string { - if len(s.PreparedParams) == 0 { - return "" - } - args := make([]string, 0, len(s.PreparedParams)) - for _, v := range s.PreparedParams { - if v.IsNull() { - args = append(args, "") - } else { - str, err := v.ToString() - if err != nil { - terror.Log(err) - } - args = append(args, str) - } - } - return fmt.Sprintf(" [arguments: %s]", strings.Join(args, ", ")) -} - // GetSystemVar gets the string value of a system variable. func (s *SessionVars) GetSystemVar(name string) (string, bool) { val, ok := s.systems[name] diff --git a/util/stringutil/string_util.go b/util/stringutil/string_util.go index 6e69f61d2bd52..b6e472b5a40e4 100644 --- a/util/stringutil/string_util.go +++ b/util/stringutil/string_util.go @@ -252,23 +252,18 @@ func Copy(src string) string { return string(hack.Slice(src)) } -// stringerFunc defines string func implement fmt.Stringer. -type stringerFunc func() string +// StringerFunc defines string func implement fmt.Stringer. +type StringerFunc func() string // String implements fmt.Stringer -func (l stringerFunc) String() string { +func (l StringerFunc) String() string { return l() } // MemoizeStr returns memoized version of stringFunc. func MemoizeStr(l func() string) fmt.Stringer { - var result string - return stringerFunc(func() string { - if result != "" { - return result - } - result = l() - return result + return StringerFunc(func() string { + return l() }) }