From b6812a7cebeac14b99e6672ecef62ae8497de2cc Mon Sep 17 00:00:00 2001 From: Tim Vaillancourt Date: Sat, 1 Jun 2024 03:11:49 +0200 Subject: [PATCH] `slack-15.0`: backport vitessio/vitess#15897 (#389) * Add sql text counts stats to `vtcombo`,`vtgate`+`vttablet` Signed-off-by: Tim Vaillancourt * initialize sqlTextCounts where missed Signed-off-by: Harshit Gangal * missing fix Signed-off-by: Tim Vaillancourt * fix accidental line delete Signed-off-by: Tim Vaillancourt --------- Signed-off-by: Tim Vaillancourt Signed-off-by: Harshit Gangal Co-authored-by: Harshit Gangal --- go/vt/vtgate/vtgate.go | 12 ++++-- go/vt/vttablet/tabletserver/query_engine.go | 12 ++++-- .../tabletserver/query_engine_test.go | 42 ++++++++++++++----- go/vt/vttablet/tabletserver/query_executor.go | 4 +- 4 files changed, 51 insertions(+), 19 deletions(-) diff --git a/go/vt/vtgate/vtgate.go b/go/vt/vtgate/vtgate.go index d7efe707f2f..ccffa853000 100644 --- a/go/vt/vtgate/vtgate.go +++ b/go/vt/vtgate/vtgate.go @@ -184,9 +184,10 @@ type VTGate struct { // stats objects. // TODO(sougou): This needs to be cleaned up. There // are global vars that depend on this member var. - timings *stats.MultiTimings - rowsReturned *stats.CountersWithMultiLabels - rowsAffected *stats.CountersWithMultiLabels + timings *stats.MultiTimings + rowsReturned *stats.CountersWithMultiLabels + rowsAffected *stats.CountersWithMultiLabels + sqlTextCounts *stats.CountersWithMultiLabels // the throttled loggers for all errors, one per API entry logExecute *logutil.ThrottledLogger @@ -304,6 +305,10 @@ func Init( "VtgateApiRowsAffected", "Rows affected by a write (DML) operation through the VTgate API", []string{"Operation", "Keyspace", "DbType"}), + sqlTextCounts: stats.NewCountersWithMultiLabels( + "VtgateSQLTextCounts", + "Vtgate API query SQL text counts", + []string{"Operation", "Keyspace", "DbType"}), logExecute: logutil.NewThrottledLogger("Execute", 5*time.Second), logStreamExecute: logutil.NewThrottledLogger("StreamExecute", 5*time.Second), @@ -433,6 +438,7 @@ func (vtg *VTGate) Execute(ctx context.Context, session *vtgatepb.Session, sql s if err == nil { vtg.rowsReturned.Add(statsKey, int64(len(qr.Rows))) vtg.rowsAffected.Add(statsKey, int64(qr.RowsAffected)) + vtg.sqlTextCounts.Add(statsKey, int64(len(sql))) return session, qr, nil } diff --git a/go/vt/vttablet/tabletserver/query_engine.go b/go/vt/vttablet/tabletserver/query_engine.go index e18b6a66ffd..9c306bc447f 100644 --- a/go/vt/vttablet/tabletserver/query_engine.go +++ b/go/vt/vttablet/tabletserver/query_engine.go @@ -171,7 +171,7 @@ type QueryEngine struct { consolidatorMode sync2.AtomicString // stats - queryCounts, queryTimes, queryRowCounts, queryErrorCounts, queryRowsAffected, queryRowsReturned *stats.CountersWithMultiLabels + queryCounts, queryTimes, queryRowCounts, queryErrorCounts, queryRowsAffected, queryRowsReturned, querySQLTextCounts *stats.CountersWithMultiLabels // stats flags enablePerWorkloadTableMetrics bool @@ -261,6 +261,7 @@ func NewQueryEngine(env tabletenv.Env, se *schema.Engine) *QueryEngine { qe.queryRowCounts = env.Exporter().NewCountersWithMultiLabels("QueryRowCounts", "(DEPRECATED - use QueryRowsAffected and QueryRowsReturned instead) query row counts", labels) qe.queryRowsAffected = env.Exporter().NewCountersWithMultiLabels("QueryRowsAffected", "query rows affected", labels) qe.queryRowsReturned = env.Exporter().NewCountersWithMultiLabels("QueryRowsReturned", "query rows returned", labels) + qe.querySQLTextCounts = env.Exporter().NewCountersWithMultiLabels("QuerySQLTextCounts", "query sql text counts", labels) qe.queryErrorCounts = env.Exporter().NewCountersWithMultiLabels("QueryErrorCounts", "query error counts", labels) env.Exporter().HandleFunc("/debug/hotrows", qe.txSerializer.ServeHTTP) @@ -489,9 +490,9 @@ func (qe *QueryEngine) QueryPlanCacheLen() int { } // AddStats adds the given stats for the planName.tableName -func (qe *QueryEngine) AddStats(planType planbuilder.PlanType, tableName, workload string, queryCount int64, duration, mysqlTime time.Duration, rowsAffected, rowsReturned, errorCount int64) { +func (qe *QueryEngine) AddStats(plan *TabletPlan, tableName, workload string, queryCount int64, duration, mysqlTime time.Duration, rowsAffected, rowsReturned, errorCount int64) { // table names can contain "." characters, replace them! - keys := []string{tableName, planType.String()} + keys := []string{tableName, plan.PlanID.String()} // Only use the workload as a label if that's enabled in the configuration. if qe.enablePerWorkloadTableMetrics { keys = append(keys, workload) @@ -500,11 +501,14 @@ func (qe *QueryEngine) AddStats(planType planbuilder.PlanType, tableName, worklo qe.queryTimes.Add(keys, int64(duration)) qe.queryRowCounts.Add(keys, rowsAffected) qe.queryErrorCounts.Add(keys, errorCount) + if plan.FullQuery != nil { + qe.querySQLTextCounts.Add(keys, int64(len(plan.FullQuery.Query))) + } // For certain plan types like select, we only want to add their metrics to rows returned // But there are special cases like `SELECT ... INTO OUTFILE ''` which return positive rows affected // So we check if it is positive and add that too. - switch planType { + switch plan.PlanID { case planbuilder.PlanSelect, planbuilder.PlanSelectStream, planbuilder.PlanSelectImpossible, planbuilder.PlanShow, planbuilder.PlanOtherRead: qe.queryRowsReturned.Add(keys, rowsReturned) if rowsAffected > 0 { diff --git a/go/vt/vttablet/tabletserver/query_engine_test.go b/go/vt/vttablet/tabletserver/query_engine_test.go index 34994e4d800..093f8971141 100644 --- a/go/vt/vttablet/tabletserver/query_engine_test.go +++ b/go/vt/vttablet/tabletserver/query_engine_test.go @@ -573,9 +573,21 @@ func TestPlanCachePollution(t *testing.T) { } func TestAddQueryStats(t *testing.T) { + fakeSelectPlan := &TabletPlan{ + Plan: &planbuilder.Plan{ + PlanID: planbuilder.PlanSelect, + FullQuery: &sqlparser.ParsedQuery{Query: `select * from something where something=123`}, // 43 length + }, + } + fakeInsertPlan := &TabletPlan{ + Plan: &planbuilder.Plan{ + PlanID: planbuilder.PlanInsert, + FullQuery: &sqlparser.ParsedQuery{Query: `insert into something (id, msg) values(123, 'hello world!')`}, // 59 length + }, + } testcases := []struct { name string - planType planbuilder.PlanType + plan *TabletPlan tableName string queryCount int64 duration time.Duration @@ -590,12 +602,13 @@ func TestAddQueryStats(t *testing.T) { expectedQueryTimes string expectedQueryRowsAffected string expectedQueryRowsReturned string + expectedQuerySQLTextCounts string expectedQueryErrorCounts string expectedQueryRowCounts string }{ { name: "select query", - planType: planbuilder.PlanSelect, + plan: fakeSelectPlan, tableName: "A", queryCount: 1, duration: 10, @@ -609,11 +622,12 @@ func TestAddQueryStats(t *testing.T) { expectedQueryTimes: `{"A.Select": 10}`, expectedQueryRowsAffected: `{}`, expectedQueryRowsReturned: `{"A.Select": 15}`, + expectedQuerySQLTextCounts: `{"A.Select": 43}`, expectedQueryRowCounts: `{"A.Select": 0}`, expectedQueryErrorCounts: `{"A.Select": 0}`, }, { name: "select into query", - planType: planbuilder.PlanSelect, + plan: fakeSelectPlan, tableName: "A", queryCount: 1, duration: 10, @@ -627,11 +641,12 @@ func TestAddQueryStats(t *testing.T) { expectedQueryTimes: `{"A.Select": 10}`, expectedQueryRowsAffected: `{"A.Select": 15}`, expectedQueryRowsReturned: `{"A.Select": 0}`, + expectedQuerySQLTextCounts: `{"A.Select": 43}`, expectedQueryRowCounts: `{"A.Select": 15}`, expectedQueryErrorCounts: `{"A.Select": 0}`, }, { name: "error", - planType: planbuilder.PlanSelect, + plan: fakeSelectPlan, tableName: "A", queryCount: 1, duration: 10, @@ -645,11 +660,12 @@ func TestAddQueryStats(t *testing.T) { expectedQueryTimes: `{"A.Select": 10}`, expectedQueryRowsAffected: `{}`, expectedQueryRowsReturned: `{"A.Select": 0}`, + expectedQuerySQLTextCounts: `{"A.Select": 43}`, expectedQueryRowCounts: `{"A.Select": 0}`, expectedQueryErrorCounts: `{"A.Select": 1}`, }, { name: "insert query", - planType: planbuilder.PlanInsert, + plan: fakeInsertPlan, tableName: "A", queryCount: 1, duration: 10, @@ -663,11 +679,12 @@ func TestAddQueryStats(t *testing.T) { expectedQueryTimes: `{"A.Insert": 10}`, expectedQueryRowsAffected: `{"A.Insert": 15}`, expectedQueryRowsReturned: `{}`, + expectedQuerySQLTextCounts: `{"A.Insert": 59}`, expectedQueryRowCounts: `{"A.Insert": 15}`, expectedQueryErrorCounts: `{"A.Insert": 0}`, }, { name: "select query with per workload metrics", - planType: planbuilder.PlanSelect, + plan: fakeSelectPlan, tableName: "A", queryCount: 1, duration: 10, @@ -681,11 +698,12 @@ func TestAddQueryStats(t *testing.T) { expectedQueryTimes: `{"A.Select.some-workload": 10}`, expectedQueryRowsAffected: `{}`, expectedQueryRowsReturned: `{"A.Select.some-workload": 15}`, + expectedQuerySQLTextCounts: `{"A.Select.some-workload": 43}`, expectedQueryRowCounts: `{"A.Select.some-workload": 0}`, expectedQueryErrorCounts: `{"A.Select.some-workload": 0}`, }, { name: "select into query with per workload metrics", - planType: planbuilder.PlanSelect, + plan: fakeSelectPlan, tableName: "A", queryCount: 1, duration: 10, @@ -699,11 +717,12 @@ func TestAddQueryStats(t *testing.T) { expectedQueryTimes: `{"A.Select.some-workload": 10}`, expectedQueryRowsAffected: `{"A.Select.some-workload": 15}`, expectedQueryRowsReturned: `{"A.Select.some-workload": 0}`, + expectedQuerySQLTextCounts: `{"A.Select.some-workload": 43}`, expectedQueryRowCounts: `{"A.Select.some-workload": 15}`, expectedQueryErrorCounts: `{"A.Select.some-workload": 0}`, }, { name: "error with per workload metrics", - planType: planbuilder.PlanSelect, + plan: fakeSelectPlan, tableName: "A", queryCount: 1, duration: 10, @@ -717,11 +736,12 @@ func TestAddQueryStats(t *testing.T) { expectedQueryTimes: `{"A.Select.some-workload": 10}`, expectedQueryRowsAffected: `{}`, expectedQueryRowsReturned: `{"A.Select.some-workload": 0}`, + expectedQuerySQLTextCounts: `{"A.Select.some-workload": 43}`, expectedQueryRowCounts: `{"A.Select.some-workload": 0}`, expectedQueryErrorCounts: `{"A.Select.some-workload": 1}`, }, { name: "insert query with per workload metrics", - planType: planbuilder.PlanInsert, + plan: fakeInsertPlan, tableName: "A", queryCount: 1, duration: 10, @@ -735,6 +755,7 @@ func TestAddQueryStats(t *testing.T) { expectedQueryTimes: `{"A.Insert.some-workload": 10}`, expectedQueryRowsAffected: `{"A.Insert.some-workload": 15}`, expectedQueryRowsReturned: `{}`, + expectedQuerySQLTextCounts: `{"A.Insert.some-workload": 59}`, expectedQueryRowCounts: `{"A.Insert.some-workload": 15}`, expectedQueryErrorCounts: `{"A.Insert.some-workload": 0}`, }, @@ -749,12 +770,13 @@ func TestAddQueryStats(t *testing.T) { env := tabletenv.NewEnv(config, "TestAddQueryStats_"+testcase.name) se := schema.NewEngine(env) qe := NewQueryEngine(env, se) - qe.AddStats(testcase.planType, testcase.tableName, testcase.workload, testcase.queryCount, testcase.duration, testcase.mysqlTime, testcase.rowsAffected, testcase.rowsReturned, testcase.errorCount) + qe.AddStats(testcase.plan, testcase.tableName, testcase.workload, testcase.queryCount, testcase.duration, testcase.mysqlTime, testcase.rowsAffected, testcase.rowsReturned, testcase.errorCount) assert.Equal(t, testcase.expectedQueryCounts, qe.queryCounts.String()) assert.Equal(t, testcase.expectedQueryTimes, qe.queryTimes.String()) assert.Equal(t, testcase.expectedQueryRowsAffected, qe.queryRowsAffected.String()) assert.Equal(t, testcase.expectedQueryRowsReturned, qe.queryRowsReturned.String()) assert.Equal(t, testcase.expectedQueryRowCounts, qe.queryRowCounts.String()) + assert.Equal(t, testcase.expectedQuerySQLTextCounts, qe.querySQLTextCounts.String()) assert.Equal(t, testcase.expectedQueryErrorCounts, qe.queryErrorCounts.String()) }) } diff --git a/go/vt/vttablet/tabletserver/query_executor.go b/go/vt/vttablet/tabletserver/query_executor.go index 8e730475c43..f1775833d6a 100644 --- a/go/vt/vttablet/tabletserver/query_executor.go +++ b/go/vt/vttablet/tabletserver/query_executor.go @@ -121,11 +121,11 @@ func (qre *QueryExecutor) Execute() (reply *sqltypes.Result, err error) { } if reply == nil { - qre.tsv.qe.AddStats(qre.plan.PlanID, tableName, qre.options.GetWorkloadName(), 1, duration, mysqlTime, 0, 0, 1) + qre.tsv.qe.AddStats(qre.plan, tableName, qre.options.GetWorkloadName(), 1, duration, mysqlTime, 0, 0, 1) qre.plan.AddStats(1, duration, mysqlTime, 0, 0, 1) return } - qre.tsv.qe.AddStats(qre.plan.PlanID, tableName, qre.options.GetWorkloadName(), 1, duration, mysqlTime, int64(reply.RowsAffected), int64(len(reply.Rows)), 0) + qre.tsv.qe.AddStats(qre.plan, tableName, qre.options.GetWorkloadName(), 1, duration, mysqlTime, int64(reply.RowsAffected), int64(len(reply.Rows)), 0) qre.plan.AddStats(1, duration, mysqlTime, reply.RowsAffected, uint64(len(reply.Rows)), 0) qre.logStats.RowsAffected = int(reply.RowsAffected) qre.logStats.Rows = reply.Rows