Merge #104345

104345: telemetry: add cluster setting to include internal queries r=gtr,mgartner a=xinhaoz

This commit introduces the bool cluster setting
`sql.telemetry.query_sampling.internal.enabled`. False by
default, if set to true we include internal queries in the
sampled query telemetry logs when telemetry logging is
enabled.

Part of: #103518

Release note (sql change): New boolean cluster setting
- sql.telemetry.query_sampling.internal.enabled: if true,
internal app queries will be reported to telemetry when
query sampling to telemetry is enabled

-----------------------
Note to reviewers: Only the 2nd commit is relevant in this review.

Co-authored-by: Xin Hao Zhang <[email protected]>

docs/generated/settings/settings-for-tenants.txt

@@ -280,6 +280,7 @@ sql.stats.response.show_internal.enabled	boolean	false	controls if statistics fo
 sql.stats.system_tables.enabled	boolean	true	when true, enables use of statistics on system tables by the query optimizer	tenant-rw
 sql.stats.system_tables_autostats.enabled	boolean	true	when true, enables automatic collection of statistics on system tables	tenant-rw
 sql.telemetry.query_sampling.enabled	boolean	false	when set to true, executed queries will emit an event on the telemetry logging channel	tenant-rw
+sql.telemetry.query_sampling.internal.enabled	boolean	false	when set to true, internal queries will be sampled in telemetry logging	tenant-rw
 sql.temp_object_cleaner.cleanup_interval	duration	30m0s	how often to clean up orphaned temporary objects	tenant-rw
 sql.temp_object_cleaner.wait_interval	duration	30m0s	how long after creation a temporary object will be cleaned up	tenant-rw
 sql.trace.log_statement_execute	boolean	false	set to true to enable logging of executed statements	tenant-rw

docs/generated/settings/settings.html

@@ -233,6 +233,7 @@
 <tr><td><div id="setting-sql-stats-system-tables-enabled" class="anchored"><code>sql.stats.system_tables.enabled</code></div></td><td>boolean</td><td><code>true</code></td><td>when true, enables use of statistics on system tables by the query optimizer</td><td>Serverless/Dedicated/Self-Hosted</td></tr>
 <tr><td><div id="setting-sql-stats-system-tables-autostats-enabled" class="anchored"><code>sql.stats.system_tables_autostats.enabled</code></div></td><td>boolean</td><td><code>true</code></td><td>when true, enables automatic collection of statistics on system tables</td><td>Serverless/Dedicated/Self-Hosted</td></tr>
 <tr><td><div id="setting-sql-telemetry-query-sampling-enabled" class="anchored"><code>sql.telemetry.query_sampling.enabled</code></div></td><td>boolean</td><td><code>false</code></td><td>when set to true, executed queries will emit an event on the telemetry logging channel</td><td>Serverless/Dedicated/Self-Hosted</td></tr>
+<tr><td><div id="setting-sql-telemetry-query-sampling-internal-enabled" class="anchored"><code>sql.telemetry.query_sampling.internal.enabled</code></div></td><td>boolean</td><td><code>false</code></td><td>when set to true, internal queries will be sampled in telemetry logging</td><td>Serverless/Dedicated/Self-Hosted</td></tr>
 <tr><td><div id="setting-sql-temp-object-cleaner-cleanup-interval" class="anchored"><code>sql.temp_object_cleaner.cleanup_interval</code></div></td><td>duration</td><td><code>30m0s</code></td><td>how often to clean up orphaned temporary objects</td><td>Serverless/Dedicated/Self-Hosted</td></tr>
 <tr><td><div id="setting-sql-temp-object-cleaner-wait-interval" class="anchored"><code>sql.temp_object_cleaner.wait_interval</code></div></td><td>duration</td><td><code>30m0s</code></td><td>how long after creation a temporary object will be cleaned up</td><td>Serverless/Dedicated/Self-Hosted</td></tr>
 <tr><td><div id="setting-sql-trace-log-statement-execute" class="anchored"><code>sql.trace.log_statement_execute</code></div></td><td>boolean</td><td><code>false</code></td><td>set to true to enable logging of executed statements</td><td>Serverless/Dedicated/Self-Hosted</td></tr>

pkg/sql/exec_log.go

@@ -164,8 +164,10 @@ func (p *planner) maybeLogStatementInternal(
 	auditEventsDetected := len(p.curPlan.auditEventBuilders) != 0
 	maxEventFrequency := TelemetryMaxEventFrequency.Get(&p.execCfg.Settings.SV)
 
-	// We only consider non-internal SQL statements for telemetry logging.
-	telemetryLoggingEnabled := telemetryLoggingEnabled.Get(&p.execCfg.Settings.SV) && execType != executorTypeInternal
+	// We only consider non-internal SQL statements for telemetry logging unless
+	// the telemetryInternalQueriesEnabled is true.
+	telemetryLoggingEnabled := telemetryLoggingEnabled.Get(&p.execCfg.Settings.SV) &&
+		(execType == executorTypeExec || telemetryInternalQueriesEnabled.Get(&p.execCfg.Settings.SV))
 
 	// If hasAdminRoleCache IsSet is true iff AdminAuditLog is enabled.
 	shouldLogToAdminAuditLog := hasAdminRoleCache.IsSet && hasAdminRoleCache.HasAdminRole

pkg/sql/telemetry_logging.go

@@ -35,6 +35,13 @@ var TelemetryMaxEventFrequency = settings.RegisterIntSetting(
 	settings.NonNegativeInt,
 )
 
+var telemetryInternalQueriesEnabled = settings.RegisterBoolSetting(
+	settings.TenantWritable,
+	"sql.telemetry.query_sampling.internal.enabled",
+	"when set to true, internal queries will be sampled in telemetry logging",
+	false,
+).WithPublic()
+
 // TelemetryLoggingMetrics keeps track of the last time at which an event
 // was logged to the telemetry channel, and the number of skipped queries
 // since the last logged event.

pkg/sql/telemetry_logging_test.go

@@ -692,6 +692,95 @@ func TestTelemetryLogging(t *testing.T) {
 	}
 }
 
+// TestTelemetryLoggingInternalEnabled verifies that setting the cluster setting to send
+// internal queries to telemetry works as intended.
+func TestTelemetryLoggingInternalEnabled(t *testing.T) {
+	defer leaktest.AfterTest(t)()
+	sc := log.ScopeWithoutShowLogs(t)
+	defer sc.Close(t)
+
+	cleanup := logtestutils.InstallLogFileSink(sc, t, logpb.Channel_TELEMETRY)
+	defer cleanup()
+
+	st := logtestutils.StubTime{}
+	sts := logtestutils.StubTracingStatus{}
+
+	s, sqlDB, _ := serverutils.StartServer(t, base.TestServerArgs{
+		Knobs: base.TestingKnobs{
+			EventLog: &EventLogTestingKnobs{
+				// The sampling checks below need to have a deterministic
+				// number of statements run by internal executor.
+				SyncWrites: true,
+			},
+			TelemetryLoggingKnobs: &TelemetryLoggingTestingKnobs{
+				getTimeNow:       st.TimeNow,
+				getTracingStatus: sts.TracingStatus,
+			},
+		},
+	})
+
+	defer s.Stopper().Stop(context.Background())
+
+	db := sqlutils.MakeSQLRunner(sqlDB)
+	db.Exec(t, `SET application_name = 'telemetry-internal-logging-test'`)
+
+	db.Exec(t, `SET CLUSTER SETTING sql.telemetry.query_sampling.max_event_frequency = 10;`)
+	db.Exec(t, `SET CLUSTER SETTING sql.telemetry.query_sampling.enabled = true;`)
+	db.Exec(t, `SET CLUSTER SETTING sql.telemetry.query_sampling.internal.enabled = true;`)
+
+	// This query should trigger 2 internal TRUNCATE queries.
+	// Since TRUNCATE is not a DML stmt, both should certainly get logged.
+	stubTime := timeutil.FromUnixMicros(int64(1e6))
+	st.SetTime(stubTime)
+	db.Exec(t, `SELECT crdb_internal.reset_sql_stats();`)
+
+	expectedQueries := []string{
+		`TRUNCATE TABLE system.public.statement_statistics`,
+		`TRUNCATE TABLE system.public.transaction_statistics`,
+	}
+
+	log.Flush()
+
+	entries, err := log.FetchEntriesFromFiles(
+		0,
+		math.MaxInt64,
+		10000,
+		regexp.MustCompile(`"EventType":"sampled_query"`),
+		log.WithMarkedSensitiveData,
+	)
+
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	if len(entries) == 0 {
+		t.Fatal(errors.Newf("no entries found"))
+	}
+
+	for _, e := range entries {
+		if strings.Contains(e.Message, "SELECT crdb_internal.reset_sql_stats") {
+			t.Errorf("unexpected query log: %s", e.Message)
+		}
+	}
+
+	// Attempt to find all expected logs.
+	for _, expected := range expectedQueries {
+		found := false
+
+		for _, e := range entries {
+			if strings.Contains(e.Message, `"ExecMode":"`+executorTypeInternal.logLabel()) &&
+				strings.Contains(e.Message, expected) {
+				found = true
+				break
+			}
+		}
+
+		if !found {
+			t.Errorf("did not find expected query log in log entries: %s", expected)
+		}
+	}
+}
+
 func TestNoTelemetryLogOnTroubleshootMode(t *testing.T) {
 	defer leaktest.AfterTest(t)()
 	sc := log.ScopeWithoutShowLogs(t)