executor: Add debug logs (pingcap#5083)

enson16855 · Nov 13, 2017 · 1ef93dc · 1ef93dc
1 parent cd5c665
commit 1ef93dc
Showing 1 changed file with 10 additions and 3 deletions.
diff --git a/executor/adapter.go b/executor/adapter.go
@@ -44,6 +44,7 @@ type recordSet struct {
 	stmt        *ExecStmt
 	processinfo processinfoSetter
 	lastErr     error
+	txnStartTS  uint64
 }
 
 func (a *recordSet) Fields() []*ast.ResultField {
@@ -90,7 +91,7 @@ func (a *recordSet) Next() (*ast.Row, error) {
 
 func (a *recordSet) Close() error {
 	err := a.executor.Close()
-	a.stmt.logSlowQuery(a.lastErr == nil)
+	a.stmt.logSlowQuery(a.txnStartTS, a.lastErr == nil)
 	if a.processinfo != nil {
 		a.processinfo.SetProcessInfo("")
 	}
@@ -189,6 +190,7 @@ func (a *ExecStmt) Exec(ctx context.Context) (ast.RecordSet, error) {
 		executor:    e,
 		stmt:        a,
 		processinfo: pi,
+		txnStartTS:  ctx.Txn().StartTS(),
 	}, nil
 }
 
@@ -209,7 +211,11 @@ func (a *ExecStmt) handleNoDelayExecutor(e Executor, ctx context.Context, pi pro
 			pi.SetProcessInfo("")
 		}
 		terror.Log(errors.Trace(e.Close()))
-		a.logSlowQuery(err == nil)
+		txnTS := uint64(0)
+		if ctx.Txn() != nil {
+			txnTS = ctx.Txn().StartTS()
+		}
+		a.logSlowQuery(txnTS, err == nil)
 	}()
 	for {
 		var row Row
@@ -281,7 +287,7 @@ func (a *ExecStmt) buildExecutor(ctx context.Context) (Executor, error) {
 	return e, nil
 }
 
-func (a *ExecStmt) logSlowQuery(succ bool) {
+func (a *ExecStmt) logSlowQuery(txnTS uint64, succ bool) {
 	cfg := config.GetGlobalConfig()
 	costTime := time.Since(a.startTime)
 	sql := a.Text
@@ -296,6 +302,7 @@ func (a *ExecStmt) logSlowQuery(succ bool) {
 		"costTime":     costTime,
 		"database":     currentDB,
 		"sql":          sql,
+		"txnStartTS":   txnTS,
 	}
 	if costTime < time.Duration(cfg.Log.SlowThreshold)*time.Millisecond {
 		logEntry.WithField("type", "query").WithField("succ", succ).Debugf("query")