Skip to content

Commit db4323f

Browse files
committed
telemetry: log all querys used by internal-console
Add a cluster setting to make it possible to log all queries used by our console (application name starts with `$ internal-console`). The console emits just a couple of them, so there should be no concern with performance. This commit also updates querys used by our console to include de `internal-console` on the application name. Fixes cockroachdb#94250 Release note: None
1 parent 93546c2 commit db4323f

File tree

5 files changed

+132
-18
lines changed

5 files changed

+132
-18
lines changed

pkg/server/combined_statement_stats.go

Lines changed: 14 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -218,7 +218,7 @@ FROM crdb_internal.statement_activity
218218
// Format string "2006-01-02 15:04:05.00" is a golang-specific string
219219
it, err := ie.QueryIteratorEx(
220220
ctx,
221-
"activity-min-ts",
221+
"console-combined-stmts-activity-min-ts",
222222
nil,
223223
sessiondata.NodeUserSessionDataOverride,
224224
fmt.Sprintf(queryWithPlaceholders, zeroDate.Format("2006-01-02 15:04:05.00"), testingKnobs.GetAOSTClause()))
@@ -280,7 +280,7 @@ func getTotalRuntimeSecs(
280280
getRuntime := func(table string) (float32, error) {
281281
it, err := ie.QueryIteratorEx(
282282
ctx,
283-
fmt.Sprintf(`%s-total-runtime`, table),
283+
fmt.Sprintf(`console-combined-stmts-%s-total-runtime`, table),
284284
nil,
285285
sessiondata.NodeUserSessionDataOverride,
286286
fmt.Sprintf(`
@@ -740,8 +740,9 @@ func getIterator(
740740
whereClause,
741741
aostClause,
742742
orderAndLimit)
743+
opName := fmt.Sprintf(`console-combined-stmts-%s`, queryInfo)
743744

744-
it, err := ie.QueryIteratorEx(ctx, queryInfo, nil,
745+
it, err := ie.QueryIteratorEx(ctx, opName, nil,
745746
sessiondata.NodeUserSessionDataOverride, query, args...)
746747
if err != nil {
747748
return it, srverrors.ServerError(ctx, err)
@@ -917,7 +918,7 @@ GROUP BY
917918
var err error
918919

919920
if activityTableHasAllData {
920-
it, err = ie.QueryIteratorEx(ctx, "stmts-activity-for-txn", nil,
921+
it, err = ie.QueryIteratorEx(ctx, "console-combined-stmts-activity-for-txn", nil,
921922
sessiondata.NodeUserSessionDataOverride, fmt.Sprintf(`
922923
SELECT fingerprint_id,
923924
transaction_fingerprint_id,
@@ -948,7 +949,7 @@ GROUP BY
948949
queryFormat,
949950
"crdb_internal.statement_statistics_persisted"+tableSuffix,
950951
whereClause)
951-
it, err = ie.QueryIteratorEx(ctx, "stmts-persisted-for-txn", nil,
952+
it, err = ie.QueryIteratorEx(ctx, "console-combined-stmts-persisted-for-txn", nil,
952953
sessiondata.NodeUserSessionDataOverride, query, args...)
953954

954955
if err != nil {
@@ -965,7 +966,7 @@ GROUP BY
965966
}
966967
query = fmt.Sprintf(queryFormat, "crdb_internal.statement_statistics", whereClause)
967968

968-
it, err = ie.QueryIteratorEx(ctx, "stmts-with-memory-for-txn", nil,
969+
it, err = ie.QueryIteratorEx(ctx, "console-combined-stmts-with-memory-for-txn", nil,
969970
sessiondata.NodeUserSessionDataOverride, query, args...)
970971

971972
if err != nil {
@@ -1345,7 +1346,7 @@ LIMIT $%d`
13451346
args = append(args, limit)
13461347

13471348
if activityTableHasAllData {
1348-
it, err = ie.QueryIteratorEx(ctx, "combined-stmts-activity-details-by-aggregated-timestamp", nil,
1349+
it, err = ie.QueryIteratorEx(ctx, "console-combined-stmts-activity-details-by-aggregated-timestamp", nil,
13491350
sessiondata.NodeUserSessionDataOverride,
13501351
fmt.Sprintf(`
13511352
SELECT aggregated_ts,
@@ -1375,7 +1376,7 @@ LIMIT $%d`, whereClause, len(args)),
13751376
whereClause,
13761377
len(args))
13771378

1378-
it, err = ie.QueryIteratorEx(ctx, "combined-stmts-persisted-details-by-aggregated-timestamp", nil,
1379+
it, err = ie.QueryIteratorEx(ctx, "console-combined-stmts-persisted-details-by-aggregated-timestamp", nil,
13791380
sessiondata.NodeUserSessionDataOverride, query, args...)
13801381

13811382
if err != nil {
@@ -1388,7 +1389,7 @@ LIMIT $%d`, whereClause, len(args)),
13881389
if !it.HasResults() {
13891390
err = closeIterator(it, err)
13901391
query = fmt.Sprintf(queryFormat, "crdb_internal.statement_statistics", whereClause, len(args))
1391-
it, err = ie.QueryIteratorEx(ctx, "combined-stmts-details-by-aggregated-timestamp-with-memory", nil,
1392+
it, err = ie.QueryIteratorEx(ctx, "console-combined-stmts-details-by-aggregated-timestamp-with-memory", nil,
13921393
sessiondata.NodeUserSessionDataOverride, query, args...)
13931394
if err != nil {
13941395
return nil, srverrors.ServerError(ctx, err)
@@ -1444,7 +1445,7 @@ func getExplainPlanFromGist(ctx context.Context, ie *sql.InternalExecutor, planG
14441445
const query = `SELECT crdb_internal.decode_plan_gist($1)`
14451446
args = append(args, planGist)
14461447

1447-
it, err := ie.QueryIteratorEx(ctx, "combined-stmts-details-get-explain-plan", nil,
1448+
it, err := ie.QueryIteratorEx(ctx, "console-combined-stmts-details-get-explain-plan", nil,
14481449
sessiondata.NodeUserSessionDataOverride, query, args...)
14491450

14501451
if err != nil {
@@ -1543,7 +1544,7 @@ LIMIT $%d`
15431544
}()
15441545

15451546
if activityTableHasAllData {
1546-
it, iterErr = ie.QueryIteratorEx(ctx, "combined-stmts-activity-details-by-plan-hash", nil,
1547+
it, iterErr = ie.QueryIteratorEx(ctx, "console-combined-stmts-activity-details-by-plan-hash", nil,
15471548
sessiondata.NodeUserSessionDataOverride, fmt.Sprintf(`
15481549
SELECT plan_hash,
15491550
(statistics -> 'statistics' -> 'planGists' ->> 0) AS plan_gist,
@@ -1572,7 +1573,7 @@ LIMIT $%d`, whereClause, len(args)), args...)
15721573
"crdb_internal.statement_statistics_persisted"+tableSuffix,
15731574
whereClause,
15741575
len(args))
1575-
it, iterErr = ie.QueryIteratorEx(ctx, "combined-stmts-persisted-details-by-plan-hash", nil,
1576+
it, iterErr = ie.QueryIteratorEx(ctx, "console-combined-stmts-persisted-details-by-plan-hash", nil,
15761577
sessiondata.NodeUserSessionDataOverride, query, args...)
15771578
if iterErr != nil {
15781579
return nil, srverrors.ServerError(ctx, err)
@@ -1584,7 +1585,7 @@ LIMIT $%d`, whereClause, len(args)), args...)
15841585
if !it.HasResults() {
15851586
err = closeIterator(it, err)
15861587
query = fmt.Sprintf(queryFormat, "crdb_internal.statement_statistics", whereClause, len(args))
1587-
it, iterErr = ie.QueryIteratorEx(ctx, "combined-stmts-details-by-plan-hash-with-memory", nil,
1588+
it, iterErr = ie.QueryIteratorEx(ctx, "console-combined-stmts-details-by-plan-hash-with-memory", nil,
15881589
sessiondata.NodeUserSessionDataOverride, query, args...)
15891590
if iterErr != nil {
15901591
return nil, srverrors.ServerError(ctx, err)

pkg/sql/exec_log.go

Lines changed: 10 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@ package sql
1313
import (
1414
"context"
1515
"sort"
16+
"strings"
1617
"time"
1718

1819
"github.com/cockroachdb/cockroach/pkg/settings"
@@ -162,11 +163,13 @@ func (p *planner) maybeLogStatementInternal(
162163
slowInternalQueryLogEnabled := slowInternalQueryLogEnabled.Get(&p.execCfg.Settings.SV)
163164
auditEventsDetected := len(p.curPlan.auditEventBuilders) != 0
164165
maxEventFrequency := TelemetryMaxEventFrequency.Get(&p.execCfg.Settings.SV)
166+
logConsoleQuery := telemetryInternalConsoleQueriesEnabled.Get(&p.execCfg.Settings.SV) &&
167+
strings.HasPrefix(p.SessionData().ApplicationName, "$ internal-console")
165168

166169
// We only consider non-internal SQL statements for telemetry logging unless
167170
// the telemetryInternalQueriesEnabled is true.
168171
telemetryLoggingEnabled := telemetryLoggingEnabled.Get(&p.execCfg.Settings.SV) &&
169-
(execType == executorTypeExec || telemetryInternalQueriesEnabled.Get(&p.execCfg.Settings.SV))
172+
(execType == executorTypeExec || telemetryInternalQueriesEnabled.Get(&p.execCfg.Settings.SV) || logConsoleQuery)
170173

171174
// If hasAdminRoleCache IsSet is true iff AdminAuditLog is enabled.
172175
shouldLogToAdminAuditLog := hasAdminRoleCache.IsSet && hasAdminRoleCache.HasAdminRole
@@ -278,9 +281,12 @@ func (p *planner) maybeLogStatementInternal(
278281
// the last event emission.
279282
requiredTimeElapsed := 1.0 / float64(maxEventFrequency)
280283
tracingEnabled := telemetryMetrics.isTracing(p.curPlan.instrumentation.Tracing())
281-
// Always sample if the current statement is not of type DML or tracing
282-
// is enabled for this statement.
283-
if p.stmt.AST.StatementType() != tree.TypeDML || tracingEnabled {
284+
// Always sample if one of the scenarios is true:
285+
// - the current statement is not of type DML
286+
// - tracing is enabled for this statement
287+
// - this is a query emitted by our console (application_name starts with `$ internal-console`) and
288+
// the cluster setting to log console queries is enabled
289+
if p.stmt.AST.StatementType() != tree.TypeDML || tracingEnabled || logConsoleQuery {
284290
requiredTimeElapsed = 0
285291
}
286292
if telemetryMetrics.maybeUpdateLastEmittedTime(telemetryMetrics.timeNow(), requiredTimeElapsed) {

pkg/sql/telemetry_logging.go

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -42,6 +42,14 @@ var telemetryInternalQueriesEnabled = settings.RegisterBoolSetting(
4242
false,
4343
).WithPublic()
4444

45+
var telemetryInternalConsoleQueriesEnabled = settings.RegisterBoolSetting(
46+
settings.TenantWritable,
47+
"sql.telemetry.query_sampling.internal_console.enabled",
48+
"when set to true, all internal queries used to populated the UI Console"+
49+
"will be logged into telemetry",
50+
true,
51+
)
52+
4553
// TelemetryLoggingMetrics keeps track of the last time at which an event
4654
// was logged to the telemetry channel, and the number of skipped queries
4755
// since the last logged event.

pkg/sql/telemetry_logging_test.go

Lines changed: 99 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -792,6 +792,105 @@ func TestTelemetryLoggingInternalEnabled(t *testing.T) {
792792
}
793793
}
794794

795+
// TestTelemetryLoggingInternalConsoleEnabled verifies that setting the cluster setting to send
796+
// internal console queries to telemetry works as intended.
797+
func TestTelemetryLoggingInternalConsoleEnabled(t *testing.T) {
798+
defer leaktest.AfterTest(t)()
799+
sc := log.ScopeWithoutShowLogs(t)
800+
defer sc.Close(t)
801+
802+
cleanup := logtestutils.InstallLogFileSink(sc, t, logpb.Channel_TELEMETRY)
803+
defer cleanup()
804+
805+
st := logtestutils.StubTime{}
806+
sts := logtestutils.StubTracingStatus{}
807+
808+
s, sqlDB, _ := serverutils.StartServer(t, base.TestServerArgs{
809+
Knobs: base.TestingKnobs{
810+
EventLog: &EventLogTestingKnobs{
811+
// The sampling checks below need to have a deterministic
812+
// number of statements run by internal executor.
813+
SyncWrites: true,
814+
},
815+
TelemetryLoggingKnobs: &TelemetryLoggingTestingKnobs{
816+
getTimeNow: st.TimeNow,
817+
getTracingStatus: sts.TracingStatus,
818+
},
819+
},
820+
})
821+
stubTime := timeutil.FromUnixMicros(int64(1e6))
822+
st.SetTime(stubTime)
823+
defer s.Stopper().Stop(context.Background())
824+
825+
db := sqlutils.MakeSQLRunner(sqlDB)
826+
db.Exec(t, `SET CLUSTER SETTING sql.telemetry.query_sampling.enabled = true;`)
827+
// Set query internal to `false` to guarantee that if an entry qith `internal-console` is showing
828+
// is because of the setting `sql.telemetry.query_sampling.internal_console.enabled` and not
829+
// being sampled as a regular internal.
830+
db.Exec(t, `SET CLUSTER SETTING sql.telemetry.query_sampling.internal.enabled = false;`)
831+
832+
testData := []struct {
833+
appName string
834+
logInternalConsole bool
835+
errorMessage string
836+
}{
837+
{
838+
"$ internal-console",
839+
false,
840+
"query from internal-console found on logs with internal_console cluster setting disabled",
841+
},
842+
{
843+
"$ internal-console-extra-name",
844+
false,
845+
"query from internal-console-extra-name found on logs with internal_console cluster setting disabled",
846+
},
847+
{
848+
"$ internal-console",
849+
true,
850+
"query from internal-console not found on logs with internal_console cluster setting enabled",
851+
},
852+
{
853+
"$ internal-console-extra-name",
854+
true,
855+
"query from internal-console-extra-name not found on logs with internal_console cluster setting enabled",
856+
},
857+
}
858+
859+
query := `SELECT count(*) FROM crdb_internal.statement_statistics`
860+
for _, tc := range testData {
861+
db.Exec(t, `SET application_name = $1`, tc.appName)
862+
db.Exec(t, `SET CLUSTER SETTING sql.telemetry.query_sampling.internal_console.enabled = $1;`, tc.logInternalConsole)
863+
db.Exec(t, query)
864+
log.Flush()
865+
866+
entries, err := log.FetchEntriesFromFiles(
867+
0,
868+
math.MaxInt64,
869+
10000,
870+
regexp.MustCompile(`"EventType":"sampled_query"`),
871+
log.WithMarkedSensitiveData,
872+
)
873+
if err != nil {
874+
t.Fatal(err)
875+
}
876+
if len(entries) == 0 {
877+
t.Fatal(errors.Newf("no entries found"))
878+
}
879+
880+
found := false
881+
for _, e := range entries {
882+
if strings.Contains(e.Message, tc.appName) && strings.Contains(e.Message, query) {
883+
found = true
884+
break
885+
}
886+
}
887+
888+
if found != tc.logInternalConsole {
889+
t.Errorf(tc.errorMessage)
890+
}
891+
}
892+
}
893+
795894
func TestNoTelemetryLogOnTroubleshootMode(t *testing.T) {
796895
defer leaktest.AfterTest(t)()
797896
sc := log.ScopeWithoutShowLogs(t)

pkg/ui/workspaces/cluster-ui/src/api/sqlApi.ts

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -107,7 +107,7 @@ export const FALLBACK_DB = "system";
107107
export function executeInternalSql<RowType>(
108108
req: SqlExecutionRequest,
109109
): Promise<SqlExecutionResponse<RowType>> {
110-
if (!req.application_name) {
110+
if (!req.application_name || req.application_name === INTERNAL_SQL_API_APP) {
111111
req.application_name = INTERNAL_SQL_API_APP;
112112
} else {
113113
req.application_name = `$ internal-${req.application_name}`;

0 commit comments

Comments
 (0)