Skip to content

Commit

Permalink
executor, infoschema, util: add sum_errors and sum_warnings to statem…
Browse files Browse the repository at this point in the history
…ent summary tables (#16456) (#16502)
  • Loading branch information
sre-bot authored Apr 17, 2020
1 parent e404298 commit cb208cd
Show file tree
Hide file tree
Showing 6 changed files with 52 additions and 9 deletions.
5 changes: 3 additions & 2 deletions executor/adapter.go
Original file line number Diff line number Diff line change
Expand Up @@ -150,7 +150,7 @@ func (a *recordSet) Close() error {
err := a.executor.Close()
// `LowSlowQuery` and `SummaryStmt` must be called before recording `PrevStmt`.
a.stmt.LogSlowQuery(a.txnStartTS, a.lastErr == nil, false)
a.stmt.SummaryStmt()
a.stmt.SummaryStmt(a.lastErr == nil)
sessVars := a.stmt.Ctx.GetSessionVars()
pps := types.CloneRow(sessVars.PreparedParams)
sessVars.PrevStmt = FormatSQL(a.stmt.OriginText(), pps)
Expand Down Expand Up @@ -870,7 +870,7 @@ func getPlanDigest(sctx sessionctx.Context, p plannercore.Plan) (normalized, pla
}

// SummaryStmt collects statements for information_schema.statements_summary
func (a *ExecStmt) SummaryStmt() {
func (a *ExecStmt) SummaryStmt(succ bool) {
sessVars := a.Ctx.GetSessionVars()
// Internal SQLs must also be recorded to keep the consistency of `PrevStmt` and `PrevStmtDigest`.
if !stmtsummary.StmtSummaryByDigestMap.Enabled() || (sessVars.InRestrictedSQL && !stmtsummary.StmtSummaryByDigestMap.EnabledInternal()) {
Expand Down Expand Up @@ -938,5 +938,6 @@ func (a *ExecStmt) SummaryStmt() {
MemMax: memMax,
StartTime: sessVars.StartTime,
IsInternal: sessVars.InRestrictedSQL,
Succeed: succ,
})
}
2 changes: 2 additions & 0 deletions infoschema/tables.go
Original file line number Diff line number Diff line change
Expand Up @@ -1139,6 +1139,8 @@ var tableStatementsSummaryCols = []columnInfo{
{name: "INDEX_NAMES", tp: mysql.TypeBlob, size: types.UnspecifiedLength, comment: "Used indices"},
{name: "SAMPLE_USER", tp: mysql.TypeVarchar, size: 64, comment: "Sampled user who executed these statements"},
{name: "EXEC_COUNT", tp: mysql.TypeLonglong, size: 20, flag: mysql.NotNullFlag | mysql.UnsignedFlag, comment: "Count of executions"},
{name: "SUM_ERRORS", tp: mysql.TypeLong, size: 11, flag: mysql.NotNullFlag | mysql.UnsignedFlag, comment: "Sum of errors"},
{name: "SUM_WARNINGS", tp: mysql.TypeLong, size: 11, flag: mysql.NotNullFlag | mysql.UnsignedFlag, comment: "Sum of warnings"},
{name: "SUM_LATENCY", tp: mysql.TypeLonglong, size: 20, flag: mysql.NotNullFlag | mysql.UnsignedFlag, comment: "Sum latency of these statements"},
{name: "MAX_LATENCY", tp: mysql.TypeLonglong, size: 20, flag: mysql.NotNullFlag | mysql.UnsignedFlag, comment: "Max latency of these statements"},
{name: "MIN_LATENCY", tp: mysql.TypeLonglong, size: 20, flag: mysql.NotNullFlag | mysql.UnsignedFlag, comment: "Min latency of these statements"},
Expand Down
26 changes: 26 additions & 0 deletions infoschema/tables_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -1183,3 +1183,29 @@ func (s *testTableSuite) TestStmtSummaryInternalQuery(c *C) {
"1 select original_sql , bind_sql , default_db , status , create_time , update_time , charset , collation from mysql . bind_info" +
" where update_time > ? order by update_time"))
}

// Test error count and warning count.
func (s *testTableSuite) TestStmtSummaryErrorCount(c *C) {
tk := testkit.NewTestKitWithInit(c, s.store)

// Clear summaries.
tk.MustExec("set global tidb_enable_stmt_summary = 0")
tk.MustExec("set global tidb_enable_stmt_summary = 1")
defer tk.MustExec("set global tidb_enable_stmt_summary = ''")

tk.MustExec("use test")
tk.MustExec("drop table if exists stmt_summary_test")
tk.MustExec("create table stmt_summary_test(id int primary key)")
tk.MustExec("insert into stmt_summary_test values(1)")
_, err := tk.Exec("insert into stmt_summary_test values(1)")
c.Assert(err, NotNil)

tk.MustQuery(`select exec_count, sum_errors, sum_warnings
from information_schema.statements_summary
where digest_text like "insert into stmt_summary_test%"`).Check(testkit.Rows("2 1 0"))

tk.MustExec("insert ignore into stmt_summary_test values(1)")
tk.MustQuery(`select exec_count, sum_errors, sum_warnings
from information_schema.statements_summary
where digest_text like "insert ignore into stmt_summary_test%"`).Check(testkit.Rows("1 0 1"))
}
2 changes: 1 addition & 1 deletion session/tidb.go
Original file line number Diff line number Diff line change
Expand Up @@ -268,7 +268,7 @@ func runStmt(ctx context.Context, sctx sessionctx.Context, s sqlexec.Statement)
if rs == nil {
// `LowSlowQuery` and `SummaryStmt` must be called before recording `PrevStmt`.
s.(*executor.ExecStmt).LogSlowQuery(origTxnCtx.StartTS, err == nil, false)
s.(*executor.ExecStmt).SummaryStmt()
s.(*executor.ExecStmt).SummaryStmt(err == nil)
pps := types.CloneRow(sessVars.PreparedParams)
sessVars.PrevStmt = executor.FormatSQL(s.OriginText(), pps)
}
Expand Down
19 changes: 14 additions & 5 deletions util/stmtsummary/statement_summary.go
Original file line number Diff line number Diff line change
Expand Up @@ -103,11 +103,13 @@ type stmtSummaryByDigestElement struct {
beginTime int64
endTime int64
// basic
sampleSQL string
prevSQL string
samplePlan string
indexNames []string
execCount int64
sampleSQL string
prevSQL string
samplePlan string
indexNames []string
execCount int64
sumErrors int
sumWarnings int
// latency
sumLatency time.Duration
maxLatency time.Duration
Expand Down Expand Up @@ -191,6 +193,7 @@ type StmtExecInfo struct {
MemMax int64
StartTime time.Time
IsInternal bool
Succeed bool
}

// newStmtSummaryByDigestMap creates an empty stmtSummaryByDigestMap.
Expand Down Expand Up @@ -609,6 +612,10 @@ func (ssElement *stmtSummaryByDigestElement) add(sei *StmtExecInfo, intervalSeco
// refreshInterval may change anytime, update endTime ASAP.
ssElement.endTime = ssElement.beginTime + intervalSeconds
ssElement.execCount++
if !sei.Succeed {
ssElement.sumErrors += 1
}
ssElement.sumWarnings += int(sei.StmtCtx.WarningCount())

// latency
ssElement.sumLatency += sei.TotalLatency
Expand Down Expand Up @@ -760,6 +767,8 @@ func (ssElement *stmtSummaryByDigestElement) toDatum(ssbd *stmtSummaryByDigest)
convertEmptyToNil(strings.Join(ssElement.indexNames, ",")),
convertEmptyToNil(sampleUser),
ssElement.execCount,
ssElement.sumErrors,
ssElement.sumWarnings,
int64(ssElement.sumLatency),
int64(ssElement.maxLatency),
int64(ssElement.minLatency),
Expand Down
7 changes: 6 additions & 1 deletion util/stmtsummary/statement_summary_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -207,6 +207,7 @@ func (s *testStmtSummarySuite) TestAddStatement(c *C) {
},
MemMax: 20000,
StartTime: time.Date(2019, 1, 1, 10, 10, 20, 10, time.UTC),
Succeed: true,
}
stmtExecInfo2.StmtCtx.AddAffectedRows(200)
expectedSummaryElement.execCount++
Expand Down Expand Up @@ -323,6 +324,7 @@ func (s *testStmtSummarySuite) TestAddStatement(c *C) {
},
MemMax: 200,
StartTime: time.Date(2019, 1, 1, 10, 10, 0, 10, time.UTC),
Succeed: true,
}
stmtExecInfo3.StmtCtx.AddAffectedRows(20000)
expectedSummaryElement.execCount++
Expand Down Expand Up @@ -426,6 +428,8 @@ func matchStmtSummaryByDigest(first, second *stmtSummaryByDigest) bool {
ssElement1.samplePlan != ssElement2.samplePlan ||
ssElement1.prevSQL != ssElement2.prevSQL ||
ssElement1.execCount != ssElement2.execCount ||
ssElement1.sumErrors != ssElement2.sumErrors ||
ssElement1.sumWarnings != ssElement2.sumWarnings ||
ssElement1.sumLatency != ssElement2.sumLatency ||
ssElement1.maxLatency != ssElement2.maxLatency ||
ssElement1.minLatency != ssElement2.minLatency ||
Expand Down Expand Up @@ -569,6 +573,7 @@ func generateAnyExecInfo() *StmtExecInfo {
},
MemMax: 10000,
StartTime: time.Date(2019, 1, 1, 10, 10, 10, 10, time.UTC),
Succeed: true,
}
stmtExecInfo.StmtCtx.AddAffectedRows(10000)
return stmtExecInfo
Expand All @@ -589,7 +594,7 @@ func (s *testStmtSummarySuite) TestToDatum(c *C) {
e := types.NewTime(types.FromGoTime(time.Unix(s.ssMap.beginTimeForCurInterval+1800, 0)), mysql.TypeTimestamp, types.DefaultFsp)
t := types.NewTime(types.FromGoTime(stmtExecInfo1.StartTime), mysql.TypeTimestamp, types.DefaultFsp)
expectedDatum := []interface{}{n, e, "select", stmtExecInfo1.SchemaName, stmtExecInfo1.Digest, stmtExecInfo1.NormalizedSQL,
"db1.tb1,db2.tb2", "a", stmtExecInfo1.User, 1, int64(stmtExecInfo1.TotalLatency),
"db1.tb1,db2.tb2", "a", stmtExecInfo1.User, 1, 0, 0, int64(stmtExecInfo1.TotalLatency),
int64(stmtExecInfo1.TotalLatency), int64(stmtExecInfo1.TotalLatency), int64(stmtExecInfo1.TotalLatency),
int64(stmtExecInfo1.ParseLatency), int64(stmtExecInfo1.ParseLatency), int64(stmtExecInfo1.CompileLatency),
int64(stmtExecInfo1.CompileLatency), stmtExecInfo1.CopTasks.NumCopTasks, int64(stmtExecInfo1.CopTasks.AvgProcessTime),
Expand Down

0 comments on commit cb208cd

Please sign in to comment.