adapter: replace query-logs flags with QueryLogMode

This commit removes `--query-log` and `--query-log-ad-hoc`, and replaces
them with the new QueryLogMode enum. The enum value is specified by
the operator via a new cli flag, `--query-log-mode`. The enum is then
plumbed through the adapter.

The `QueryLogger` will now restrict adding the `query` tag (which
contains the SQL query text) to histograms only when the `All` mode
 is selected. Similarly, query parse histograms are only recorded
 in `All` mode, as well. `Cached` mode will only record latencies from
 queries that were serviced by ReadySet (i.e., they were cached).

Also, this commit cleans up the existing uses of the cli flags and
env vars with approporiate conversion to the new `--quer-log-mode`
and `QUERY_LOG_MODE`.

Fixes: REA-3592
Release-Core-Note: `--query-log` and `--query-log-ad-hoc` are replaced
  by `--query-log-mode`.
Change-Id: I6da3f15d77c66d4ed9e1609b1d1915658b4aba30
Reviewed-on: https://gerrit.readyset.name/c/readyset/+/6233
Tested-by: Buildkite CI
Reviewed-by: Luke Osborne <luke@readyset.io>

community-development.md

@@ -77,13 +77,13 @@ This section is for developers who want to build ReadySet from source as they wo
    **Run against Postgres:**
 
    ```bash
-   cargo run --bin readyset --release -- --standalone --database-type=postgresql --upstream-db-url=postgresql://postgres:readyset@127.0.0.1:5432/testdb --username=postgres --password=readyset --address=0.0.0.0:5433 --deployment=<deployment name> --prometheus-metrics --query-log --query-log-ad-hoc
+   cargo run --bin readyset --release -- --standalone --database-type=postgresql --upstream-db-url=postgresql://postgres:readyset@127.0.0.1:5432/testdb --username=postgres --password=readyset --address=0.0.0.0:5433 --deployment=<deployment name> --prometheus-metrics --query-log-mode all-queries
    ```
 
    **Run against MySQL:**
 
    ```bash
-   cargo run --bin readyset --release -- --standalone --database-type=mysql --upstream-db-url=mysql://root:readyset@127.0.0.1:3306/testdb --username=root --password=readyset --address=0.0.0.0:3307 --deployment=<deployment name> --prometheus-metrics --query-log --query-log-ad-hoc
+   cargo run --bin readyset --release -- --standalone --database-type=mysql --upstream-db-url=mysql://root:readyset@127.0.0.1:3306/testdb --username=root --password=readyset --address=0.0.0.0:3307 --deployment=<deployment name> --prometheus-metrics --query-log-mode all-queries
    ```
 
    This runs the ReadySet Server and Adapter as a single process, a simple, standard way to run ReadySet that is also the easiest approach when developing. For production deployments, however, it is possible to run the Server and Adapter as separate processes. See the [scale out deployment pattern](https://docs.readyset.io/guides/deploy/production-notes/#scale-out) in the docs.

development.md

@@ -65,19 +65,17 @@ Then, run the adapter binary. The adapter will communicate with servers that hav
 **MySQL**
 ```
 cargo run --bin readyset --release -- --database-type mysql --upstream-db-url mysql://root:readyset@127.1/readyset  --allow-unauthenticated-connections
-  --address 0.0.0.0:3307 --deployment <deployment name>  --prometheus-metrics --query-log --query-log-ad-hoc
+  --address 0.0.0.0:3307 --deployment <deployment name>  --prometheus-metrics --query-log-mode all-queries
  ```
 
 **Postgres**
 ```
 cargo run --bin readyset --release -- --database-type postgresql --upstream-db-url postgresql://postgres:readyset@127.1/readyset  --allow-unauthenticated-connections
-  --address 0.0.0.0:5433 --deployment <deployment name> --prometheus-metrics --query-log --query-log-ad-hoc
+  --address 0.0.0.0:5433 --deployment <deployment name> --prometheus-metrics --query-log-mode all-queries
 ```
 
 The adapter listens for connections at the address specified in the `address` flag.
 
-The `query-log` and `query-log-ad-hoc` flags ensure that queries are sent to the Prometheus client running in the adapter.
-
 The `prometheus-metrics` flag exposes an HTTP endpoint in the adapter to allow querying of metrics. This can be reached with an HTTP GET request to <adapter-address>:6034/metrics (e.g., `curl -X GET 127.0.0.1:6034/metrics`).
 
 ## Testing

quickstart/compose.mysql.yml

@@ -13,9 +13,8 @@ services:
       DEPLOYMENT_ENV: quickstart_docker
       DB_DIR: /state
       PROMETHEUS_METRICS: true
+      QUERY_LOG_MODE: all-queries
       QUERY_CACHING: explicit
-      QUERY_LOG: true
-      QUERY_LOG_AD_HOC: true
       STANDALONE: true
       DEPLOYMENT: docker_compose_deployment
       LISTEN_ADDRESS: 0.0.0.0:3307

quickstart/compose.postgres.yml

@@ -14,8 +14,7 @@ services:
       DB_DIR: /state
       PROMETHEUS_METRICS: true
       QUERY_CACHING: explicit
-      QUERY_LOG: true
-      QUERY_LOG_AD_HOC: true
+      QUERY_LOG_MODE: all-queries
       STANDALONE: true
       DEPLOYMENT: docker_compose_deployment
       LISTEN_ADDRESS: 0.0.0.0:5433

quickstart/compose.yml

@@ -14,8 +14,7 @@ services:
       DB_DIR: /state
       PROMETHEUS_METRICS: true
       QUERY_CACHING: explicit
-      QUERY_LOG: true
-      QUERY_LOG_AD_HOC: true
+      QUERY_LOG_MODE: all-queries
       STANDALONE: true
       DEPLOYMENT: docker_compose_deployment
       LISTEN_ADDRESS: 0.0.0.0:5433

quickstart/metrics.py

@@ -91,7 +91,7 @@
 			print ("ReadySet Queries")
 			print (tabulate(tabulated_readyset_rows, headers=["query text", "count", "p50 (ms)", "p90 (ms)", "p99 (ms)"], tablefmt="psql", floatfmt=".3f", maxcolwidths=70))
 	else:
-		raise ValueError("Oops! There are no query-specific metrics. Have you run a query yet? Did you pass --query-log and --query-log-ad-hoc flags when running ReadySet?")
+		raise ValueError("Oops! There are no query-specific metrics. Have you run a query yet?")
 except ValueError as err:
 	print (str(err.args[0]))
 

readyset-adapter/src/backend.rs

@@ -91,7 +91,9 @@ use readyset_client::query::*;
 use readyset_client::results::Results;
 use readyset_client::{ColumnSchema, PlaceholderIdx, ViewCreateRequest};
 pub use readyset_client_metrics::QueryDestination;
-use readyset_client_metrics::{recorded, EventType, QueryExecutionEvent, SqlQueryType};
+use readyset_client_metrics::{
+    recorded, EventType, QueryExecutionEvent, QueryLogMode, SqlQueryType,
+};
 use readyset_data::{DfType, DfValue};
 use readyset_errors::ReadySetError::{self, PreparedStatementMissing};
 use readyset_errors::{internal, internal_err, unsupported, unsupported_err, ReadySetResult};
@@ -267,7 +269,7 @@ pub struct BackendBuilder {
     ticket: Option<Timestamp>,
     timestamp_client: Option<TimestampClient>,
     query_log_sender: Option<UnboundedSender<QueryExecutionEvent>>,
-    query_log_ad_hoc_queries: bool,
+    query_log_mode: QueryLogMode,
     unsupported_set_mode: UnsupportedSetMode,
     migration_mode: MigrationMode,
     query_max_failure_seconds: u64,
@@ -289,7 +291,7 @@ impl Default for BackendBuilder {
             ticket: None,
             timestamp_client: None,
             query_log_sender: None,
-            query_log_ad_hoc_queries: false,
+            query_log_mode: Default::default(),
             unsupported_set_mode: UnsupportedSetMode::Error,
             migration_mode: MigrationMode::InRequestPath,
             query_max_failure_seconds: (i64::MAX / 1000) as u64,
@@ -348,7 +350,7 @@ impl BackendBuilder {
                 unsupported_set_mode: self.unsupported_set_mode,
                 migration_mode: self.migration_mode,
                 query_max_failure_duration: Duration::new(self.query_max_failure_seconds, 0),
-                query_log_ad_hoc_queries: self.query_log_ad_hoc_queries,
+                query_log_mode: self.query_log_mode,
                 fallback_recovery_duration: Duration::new(self.fallback_recovery_seconds, 0),
                 enable_experimental_placeholder_inlining: self
                     .enable_experimental_placeholder_inlining,
@@ -379,10 +381,10 @@ impl BackendBuilder {
     pub fn query_log(
         mut self,
         query_log_sender: Option<UnboundedSender<QueryExecutionEvent>>,
-        ad_hoc_queries: bool,
+        mode: QueryLogMode,
     ) -> Self {
         self.query_log_sender = query_log_sender;
-        self.query_log_ad_hoc_queries = ad_hoc_queries;
+        self.query_log_mode = mode;
         self
     }
 
@@ -585,7 +587,7 @@ struct BackendSettings {
     slowlog: bool,
     require_authentication: bool,
     /// Whether to log ad-hoc queries by full query text in the query logger.
-    query_log_ad_hoc_queries: bool,
+    query_log_mode: QueryLogMode,
     /// How to behave when receiving unsupported `SET` statements
     unsupported_set_mode: UnsupportedSetMode,
     /// How this backend handles migrations, See MigrationMode.
@@ -2577,7 +2579,7 @@ where
                 let processed_query_params = processed_query_params?;
                 if noria_should_try {
                     event.sql_type = SqlQueryType::Read;
-                    if self.settings.query_log_ad_hoc_queries {
+                    if self.settings.query_log_mode.allow_ad_hoc() {
                         event.query = Some(Arc::new(SqlQuery::Select(view_request.statement.clone())));
                         event.query_id = Some(QueryId::from_view_create_request(&view_request));
                     }

readyset/src/lib.rs

@@ -43,6 +43,7 @@ use readyset_client::consensus::AuthorityType;
 use readyset_client::failpoints;
 use readyset_client::metrics::recorded;
 use readyset_client::ReadySetHandle;
+use readyset_client_metrics::QueryLogMode;
 use readyset_common::ulimit::maybe_increase_nofile_limit;
 use readyset_dataflow::Readers;
 use readyset_errors::{internal_err, ReadySetError};
@@ -264,22 +265,12 @@ pub struct Options {
     /// Enabled by default if prometheus-metrics is enabled.
     #[clap(
         long,
-        env = "QUERY_LOG",
+        env = "QUERY_LOG_MODE",
         requires = "metrics",
-        default_value_if("prometheus_metrics", "true", Some("true"))
+        default_value = "all-queries",
+        default_value_if("prometheus_metrics", "true", Some("all-queries"))
     )]
-    query_log: bool,
-
-    /// Enables logging ad-hoc queries in the query log. Useful for testing. Enabled by default if
-    /// prometheus-metrics is enabled.
-    #[clap(
-        long,
-        hide = true,
-        env = "QUERY_LOG_AD_HOC",
-        requires = "query_log",
-        default_value_if("prometheus_metrics", "true", Some("true"))
-    )]
-    query_log_ad_hoc: bool,
+    query_log_mode: QueryLogMode,
 
     /// IP address to advertise to other ReadySet instances running in the same deployment.
     ///
@@ -740,7 +731,7 @@ where
         let (shutdown_tx, shutdown_rx) = shutdown::channel();
 
         // Gate query log code path on the log flag existing.
-        let qlog_sender = if options.query_log {
+        let qlog_sender = if options.query_log_mode.is_enabled() {
             rs_connect.in_scope(|| info!("Query logs are enabled. Spawning query logger"));
             let (qlog_sender, qlog_receiver) = tokio::sync::mpsc::unbounded_channel();
 
@@ -752,11 +743,16 @@ where
 
             let shutdown_rx = shutdown_rx.clone();
             // Spawn the actual thread to run the logger
+            let query_log_mode = options.query_log_mode;
             std::thread::Builder::new()
                 .name("Query logger".to_string())
                 .stack_size(2 * 1024 * 1024) // Use the same value tokio is using
                 .spawn_wrapper(move || {
-                    runtime.block_on(query_logger::QueryLogger::run(qlog_receiver, shutdown_rx));
+                    runtime.block_on(query_logger::QueryLogger::run(
+                        qlog_receiver,
+                        shutdown_rx,
+                        query_log_mode,
+                    ));
                     runtime.shutdown_background();
                 })?;
 
@@ -1011,7 +1007,7 @@ where
                 .users(users.clone())
                 .require_authentication(!options.allow_unauthenticated_connections)
                 .dialect(self.parse_dialect)
-                .query_log(qlog_sender.clone(), options.query_log_ad_hoc)
+                .query_log(qlog_sender.clone(), options.query_log_mode)
                 .unsupported_set_mode(if options.allow_unsupported_set {
                     readyset_adapter::backend::UnsupportedSetMode::Allow
                 } else {

readyset/src/query_logger.rs

@@ -5,7 +5,7 @@ use metrics::{register_counter, register_histogram, Counter, Histogram, SharedSt
 use nom_sql::SqlQuery;
 use readyset_client::query::QueryId;
 use readyset_client_metrics::{
-    recorded, DatabaseType, EventType, QueryExecutionEvent, SqlQueryType,
+    recorded, DatabaseType, EventType, QueryExecutionEvent, QueryLogMode, SqlQueryType,
 };
 use readyset_sql_passes::anonymize::anonymize_literals;
 use readyset_util::shutdown::ShutdownReceiver;
@@ -47,18 +47,25 @@ struct QueryCounters {
 }
 
 impl QueryMetrics {
-    fn parse_histogram(&mut self, kind: (EventType, SqlQueryType)) -> &mut Histogram {
+    fn parse_histogram(
+        &mut self,
+        kind: (EventType, SqlQueryType),
+        mode: &QueryLogMode,
+    ) -> &mut Histogram {
         self.histograms
             .entry(kind)
             .or_default()
             .parse_time
             .get_or_insert_with(|| {
                 let mut labels = vec![
-                    ("query", self.query.clone()),
                     ("event_type", SharedString::from(kind.0)),
                     ("query_type", SharedString::from(kind.1)),
                 ];
 
+                if mode.is_verbose() {
+                    labels.push(("query", self.query.clone()));
+                }
+
                 if let Some(id) = &self.query_id {
                     labels.push(("query_id", id.clone()));
                 }
@@ -67,19 +74,26 @@ impl QueryMetrics {
             })
     }
 
-    fn readyset_histogram(&mut self, kind: (EventType, SqlQueryType)) -> &mut Histogram {
+    fn readyset_histogram(
+        &mut self,
+        kind: (EventType, SqlQueryType),
+        mode: &QueryLogMode,
+    ) -> &mut Histogram {
         self.histograms
             .entry(kind)
             .or_default()
             .readyset_exe_time
             .get_or_insert_with(|| {
                 let mut labels = vec![
-                    ("query", self.query.clone()),
                     ("event_type", SharedString::from(kind.0)),
                     ("query_type", SharedString::from(kind.1)),
                     ("database_type", SharedString::from(DatabaseType::ReadySet)),
                 ];
 
+                if mode.is_verbose() {
+                    labels.push(("query", self.query.clone()));
+                }
+
                 if let Some(id) = &self.query_id {
                     labels.push(("query_id", id.clone()));
                 }
@@ -88,19 +102,26 @@ impl QueryMetrics {
             })
     }
 
-    fn upstream_histogram(&mut self, kind: (EventType, SqlQueryType)) -> &mut Histogram {
+    fn upstream_histogram(
+        &mut self,
+        kind: (EventType, SqlQueryType),
+        mode: &QueryLogMode,
+    ) -> &mut Histogram {
         self.histograms
             .entry(kind)
             .or_default()
             .upstream_exe_time
             .get_or_insert_with(|| {
                 let mut labels = vec![
-                    ("query", self.query.clone()),
                     ("event_type", SharedString::from(kind.0)),
                     ("query_type", SharedString::from(kind.1)),
                     ("database_type", SharedString::from(DatabaseType::MySql)),
                 ];
 
+                if mode.is_verbose() {
+                    labels.push(("query", self.query.clone()));
+                }
+
                 if let Some(id) = &self.query_id {
                     labels.push(("query_id", id.clone()));
                 }
@@ -229,6 +250,7 @@ impl QueryLogger {
     pub(crate) async fn run(
         mut receiver: UnboundedReceiver<QueryExecutionEvent>,
         mut shutdown_recv: ShutdownReceiver,
+        mode: QueryLogMode,
     ) {
         let _span = info_span!("query-logger");
 
@@ -304,22 +326,22 @@ impl QueryLogger {
                         }
                     }
 
-                    if let Some(duration) = event.parse_duration {
+                    if mode.is_verbose() && let Some(duration) = event.parse_duration {
                         metrics
-                            .parse_histogram((event.event, event.sql_type))
+                            .parse_histogram((event.event, event.sql_type), &mode)
                             .record(duration);
                     }
 
                     if let Some(duration) = event.readyset_duration {
                         metrics
-                            .readyset_histogram((event.event, event.sql_type))
+                            .readyset_histogram((event.event, event.sql_type), &mode)
                             .record(duration);
                         metrics.readyset_counter((event.event, event.sql_type)).increment(1);
                     }
 
-                    if let Some(duration) = event.upstream_duration {
+                    if mode.allow_proxied_queries() && let Some(duration) = event.upstream_duration {
                         metrics
-                            .upstream_histogram((event.event, event.sql_type))
+                            .upstream_histogram((event.event, event.sql_type), &mode)
                             .record(duration);
                         metrics.upstream_counter((event.event, event.sql_type)).increment(1);
                     }