From 790b5d5e3e38ea67483b1e04d706277c006f4947 Mon Sep 17 00:00:00 2001
From: Jack Yu <jackysp@gmail.com>
Date: Tue, 24 Sep 2019 09:59:17 +0800
Subject: [PATCH] session: annotate the previous statement to the error when
 transaction commit failed (#12087) (#12199)

---
 executor/adapter.go     |  5 +++--
 session/session_test.go |  4 ++--
 session/tidb.go         | 16 +++++++++++-----
 3 files changed, 16 insertions(+), 9 deletions(-)

diff --git a/executor/adapter.go b/executor/adapter.go
index 8e7f9bba0e49f..8a27585cd09be 100644
--- a/executor/adapter.go
+++ b/executor/adapter.go
@@ -134,7 +134,8 @@ 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.Ctx.GetSessionVars().PrevStmt = a.stmt.OriginText()
+	sessVars := a.stmt.Ctx.GetSessionVars()
+	sessVars.PrevStmt = FormatSQL(a.stmt.OriginText(), sessVars)
 	a.stmt.logAudit()
 	a.stmt.SummaryStmt()
 	return err
@@ -679,7 +680,7 @@ func (a *ExecStmt) LogSlowQuery(txnTS uint64, succ bool) {
 		Succ:        succ,
 	}
 	if _, ok := a.StmtNode.(*ast.CommitStmt); ok {
-		slowItems.PrevStmt = FormatSQL(sessVars.PrevStmt, sessVars)
+		slowItems.PrevStmt = sessVars.PrevStmt
 	}
 	if costTime < threshold {
 		logutil.SlowQueryLogger.Debug(sessVars.SlowLogFormat(slowItems))
diff --git a/session/session_test.go b/session/session_test.go
index 6a279e80f230d..2bce04245a38d 100644
--- a/session/session_test.go
+++ b/session/session_test.go
@@ -1518,12 +1518,12 @@ func (s *testSessionSuite) TestUnique(c *C) {
 	c.Assert(err, NotNil)
 	// Check error type and error message
 	c.Assert(terror.ErrorEqual(err, kv.ErrKeyExists), IsTrue, Commentf("err %v", err))
-	c.Assert(err.Error(), Equals, "[kv:1062]Duplicate entry '1' for key 'PRIMARY'")
+	c.Assert(err.Error(), Equals, "previous statement: insert into test(id, val) values(1, 1);: [kv:1062]Duplicate entry '1' for key 'PRIMARY'")
 
 	_, err = tk1.Exec("commit")
 	c.Assert(err, NotNil)
 	c.Assert(terror.ErrorEqual(err, kv.ErrKeyExists), IsTrue, Commentf("err %v", err))
-	c.Assert(err.Error(), Equals, "[kv:1062]Duplicate entry '2' for key 'val'")
+	c.Assert(err.Error(), Equals, "previous statement: insert into test(id, val) values(2, 2);: [kv:1062]Duplicate entry '2' for key 'val'")
 
 	// Test for https://github.com/pingcap/tidb/issues/463
 	tk.MustExec("drop table test;")
diff --git a/session/tidb.go b/session/tidb.go
index 8d9edac39f4cb..19e26e299324a 100644
--- a/session/tidb.go
+++ b/session/tidb.go
@@ -161,7 +161,8 @@ func Compile(ctx context.Context, sctx sessionctx.Context, stmtNode ast.StmtNode
 	return stmt, err
 }
 
-func finishStmt(ctx context.Context, sctx sessionctx.Context, se *session, sessVars *variable.SessionVars, meetsErr error) error {
+func finishStmt(ctx context.Context, sctx sessionctx.Context, se *session, sessVars *variable.SessionVars,
+	meetsErr error, sql sqlexec.Statement) error {
 	if meetsErr != nil {
 		if !sessVars.InTxn() {
 			logutil.Logger(context.Background()).Info("rollbackTxn for ddl/autocommit error.")
@@ -174,7 +175,13 @@ func finishStmt(ctx context.Context, sctx sessionctx.Context, se *session, sessV
 	}
 
 	if !sessVars.InTxn() {
-		return se.CommitTxn(ctx)
+		if err := se.CommitTxn(ctx); err != nil {
+			if _, ok := sql.(*executor.ExecStmt).StmtNode.(*ast.CommitStmt); ok {
+				err = errors.Annotatef(err, "previous statement: %s", se.GetSessionVars().PrevStmt)
+			}
+			return err
+		}
+		return nil
 	}
 
 	return checkStmtLimit(ctx, sctx, se, sessVars)
@@ -218,7 +225,7 @@ 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 = s.OriginText()
+			sessVars.PrevStmt = executor.FormatSQL(s.OriginText(), sessVars)
 		}
 	}()
 
@@ -245,8 +252,7 @@ func runStmt(ctx context.Context, sctx sessionctx.Context, s sqlexec.Statement)
 			logutil.Logger(context.Background()).Error("get txn error", zap.Error(err1))
 		}
 	}
-
-	err = finishStmt(ctx, sctx, se, sessVars, err)
+	err = finishStmt(ctx, sctx, se, sessVars, err, s)
 	if se.txn.pending() {
 		// After run statement finish, txn state is still pending means the
 		// statement never need a Txn(), such as: