diff --git a/executor/adapter.go b/executor/adapter.go index 1e728668f43a2..3001bda1567b7 100644 --- a/executor/adapter.go +++ b/executor/adapter.go @@ -111,7 +111,7 @@ func (a *recordSet) NewChunk() *chunk.Chunk { func (a *recordSet) Close() error { err := a.executor.Close() - a.stmt.logSlowQuery(a.txnStartTS, a.lastErr == nil) + a.stmt.LogSlowQuery(a.txnStartTS, a.lastErr == nil) if a.processinfo != nil { a.processinfo.SetProcessInfo("") } @@ -133,8 +133,9 @@ type ExecStmt struct { StmtNode ast.StmtNode - Ctx sessionctx.Context - startTime time.Time + Ctx sessionctx.Context + // StartTime stands for the starting time when executing the statement. + StartTime time.Time isPreparedStmt bool } @@ -179,7 +180,7 @@ func (a *ExecStmt) RebuildPlan() error { // like the INSERT, UPDATE statements, it executes in this function, if the Executor returns // result, execution is done after this function returns, in the returned ast.RecordSet Next method. func (a *ExecStmt) Exec(ctx context.Context) (ast.RecordSet, error) { - a.startTime = time.Now() + a.StartTime = time.Now() sctx := a.Ctx if _, ok := a.Plan.(*plan.Analyze); ok && sctx.GetSessionVars().InRestrictedSQL { oriStats, _ := sctx.GetSessionVars().GetSystemVar(variable.TiDBBuildStatsConcurrency) @@ -260,7 +261,7 @@ func (a *ExecStmt) handleNoDelayExecutor(ctx context.Context, sctx sessionctx.Co if sctx.Txn() != nil { txnTS = sctx.Txn().StartTS() } - a.logSlowQuery(txnTS, err == nil) + a.LogSlowQuery(txnTS, err == nil) }() err = e.Next(ctx, e.newChunk()) @@ -328,13 +329,14 @@ func (a *ExecStmt) buildExecutor(ctx sessionctx.Context) (Executor, error) { // QueryReplacer replaces new line and tab for grep result including query string. var QueryReplacer = strings.NewReplacer("\r", " ", "\n", " ", "\t", " ") -func (a *ExecStmt) logSlowQuery(txnTS uint64, succ bool) { +// LogSlowQuery is used to print the slow query in the log files. +func (a *ExecStmt) LogSlowQuery(txnTS uint64, succ bool) { level := log.GetLevel() if level < log.WarnLevel { return } cfg := config.GetGlobalConfig() - costTime := time.Since(a.startTime) + costTime := time.Since(a.StartTime) threshold := time.Duration(cfg.Log.SlowThreshold) * time.Millisecond if costTime < threshold && level < log.DebugLevel { return diff --git a/session/session.go b/session/session.go index ca3940dc770b4..242e7089fd9aa 100644 --- a/session/session.go +++ b/session/session.go @@ -390,7 +390,13 @@ func (s *session) CommitTxn(ctx context.Context) error { defer span.Finish() } + stmt := executor.ExecStmt{ + Text: "commit", + Ctx: s, + StartTime: time.Now(), + } err := s.doCommitWithRetry(ctx) + stmt.LogSlowQuery(s.sessionVars.TxnCtx.StartTS, err == nil) label := metrics.LblOK if err != nil { label = metrics.LblError