adapter: Refactor query log metrics

This commit makes a few changes related to the query logger used in the
adapter. It:
1. Adds query logging for parsed select statements that require fallback
   (this was missing previously)
2. Adds query logging for parsed select statements that don't *require*
   fallback but should not be executed against Readyset (this was
   missing previously)
3. Removes checks in readyset_adapter::backend as to whether log
   information should be added to the query execution event, deferring
   deferring to the query logger to determine what information should be
   logged based on the query logging mode
4. Changes the possible query logging modes to be "disabled", "enabled",
   and "verbose," where "enabled" logs metrics about both proxied and
   cached queries but "verbose" includes the query string and query ID
   as metric labels

In addition, this commit updates the query logging mode to "verbose" in
the quickstart Docker compose files to ensure that the Grafana
dashboards don't break.

Release-Note-Core: Fixed an issue where query log metrics were not being
  emitted for certain proxied queries
Change-Id: Iba0f6ab295cb01758e1e26176acf6ecaf3523a7e
Reviewed-on: https://gerrit.readyset.name/c/readyset/+/6858
Tested-by: Buildkite CI
Reviewed-by: Jason Brown <jason.b@readyset.io>

.buildkite/test-demo.sh

@@ -166,6 +166,7 @@ run_script() {
       # If we are going to fail, dump some debug information that may be useful to look at
       show_docker_info
       docker logs readyset-cache-1
+      docker-compose -f readyset.compose.yml down -v > /dev/null 2>&1
       # The return code could have been 0, so exit with 1 explicitly
       exit 1
     fi

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 -- --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
+   cargo run --bin readyset --release -- --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
    ```
 
    **Run against MySQL:**
 
    ```bash
-   cargo run --bin readyset --release -- --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
+   cargo run --bin readyset --release -- --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
    ```
 
    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,13 +65,13 @@ 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-mode all-queries
+  --address 0.0.0.0:3307 --deployment <deployment name>  --prometheus-metrics
  ```
 
 **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-mode all-queries
+  --address 0.0.0.0:5433 --deployment <deployment name> --prometheus-metrics
 ```
 
 The adapter listens for connections at the address specified in the `address` flag.

quickstart/compose.mysql.yml

@@ -13,7 +13,7 @@ services:
       DEPLOYMENT_ENV: quickstart_docker
       DB_DIR: /state
       PROMETHEUS_METRICS: true
-      QUERY_LOG_MODE: all-queries
+      QUERY_LOG_MODE: verbose
       QUERY_CACHING: explicit
       STANDALONE: true
       DEPLOYMENT: docker_compose_deployment

quickstart/compose.postgres.yml

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

quickstart/compose.yml

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

readyset-adapter/src/backend.rs

@@ -93,9 +93,7 @@ use readyset_client::results::Results;
 use readyset_client::utils::retry_with_exponential_backoff;
 use readyset_client::{ColumnSchema, PlaceholderIdx, ViewCreateRequest};
 pub use readyset_client_metrics::QueryDestination;
-use readyset_client_metrics::{
-    recorded, EventType, QueryExecutionEvent, QueryLogMode, SqlQueryType,
-};
+use readyset_client_metrics::{recorded, EventType, QueryExecutionEvent, SqlQueryType};
 use readyset_data::{DfType, DfValue};
 use readyset_errors::ReadySetError::{self, PreparedStatementMissing};
 use readyset_errors::{internal, internal_err, unsupported, unsupported_err, ReadySetResult};
@@ -278,7 +276,6 @@ pub struct BackendBuilder {
     ticket: Option<Timestamp>,
     timestamp_client: Option<TimestampClient>,
     query_log_sender: Option<UnboundedSender<QueryExecutionEvent>>,
-    query_log_mode: QueryLogMode,
     unsupported_set_mode: UnsupportedSetMode,
     migration_mode: MigrationMode,
     query_max_failure_seconds: u64,
@@ -301,7 +298,6 @@ impl Default for BackendBuilder {
             ticket: None,
             timestamp_client: None,
             query_log_sender: None,
-            query_log_mode: Default::default(),
             unsupported_set_mode: UnsupportedSetMode::Error,
             migration_mode: MigrationMode::InRequestPath,
             query_max_failure_seconds: (i64::MAX / 1000) as u64,
@@ -364,7 +360,6 @@ 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_mode: self.query_log_mode,
                 fallback_recovery_duration: Duration::new(self.fallback_recovery_seconds, 0),
                 enable_experimental_placeholder_inlining: self
                     .enable_experimental_placeholder_inlining,
@@ -398,10 +393,8 @@ impl BackendBuilder {
     pub fn query_log(
         mut self,
         query_log_sender: Option<UnboundedSender<QueryExecutionEvent>>,
-        mode: QueryLogMode,
     ) -> Self {
         self.query_log_sender = query_log_sender;
-        self.query_log_mode = mode;
         self
     }
 
@@ -621,8 +614,6 @@ struct BackendSettings {
     dialect: Dialect,
     slowlog: bool,
     require_authentication: bool,
-    /// Whether to log ad-hoc queries by full query text in the query logger.
-    query_log_mode: QueryLogMode,
     /// How to behave when receiving unsupported `SET` statements
     unsupported_set_mode: UnsupportedSetMode,
     /// How this backend handles migrations, See MigrationMode.
@@ -2903,6 +2894,13 @@ where
             }
             Ok(ref parsed_query) if Handler::requires_fallback(parsed_query) => {
                 if self.has_fallback() {
+                    if let SqlQuery::Select(stmt) = parsed_query {
+                        event.sql_type = SqlQueryType::Read;
+                        event.query = Some(Arc::new(parsed_query.clone()));
+                        event.query_id =
+                            Some(QueryId::from_select(stmt, self.noria.schema_search_path()));
+                    }
+
                     // Query requires a fallback and we can send it to fallback
                     Self::query_fallback(self.upstream.as_mut(), query, &mut event).await
                 } else {
@@ -2915,16 +2913,16 @@ where
             Ok(SqlQuery::Select(stmt)) => {
                 let mut view_request =
                     ViewCreateRequest::new(stmt, self.noria.schema_search_path().to_owned());
+
+                event.sql_type = SqlQueryType::Read;
+                event.query = Some(Arc::new(SqlQuery::Select(view_request.statement.clone())));
+                event.query_id = Some(QueryId::from(&view_request));
+
                 let (noria_should_try, status, processed_query_params) =
                     self.noria_should_try_select(&mut view_request);
                 let processed_query_params = processed_query_params?;
+
                 if noria_should_try {
-                    event.sql_type = SqlQueryType::Read;
-                    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_request));
-                    }
                     Self::query_adhoc_select(
                         &mut self.noria,
                         self.upstream.as_mut(),

readyset-client-metrics/src/lib.rs

@@ -17,19 +17,17 @@ pub mod recorded;
 /// starting at `Disabled`, includes all of the preceeding (lower) level's metric
 /// details. This gradation attempts to make a reasonable tradeoff of metrics
 /// payload size vs. verbosity/debugability.
-#[derive(Clone, Copy, Debug, Default, Eq, PartialEq, ValueEnum)]
+#[derive(Clone, Copy, Debug, Eq, PartialEq, ValueEnum)]
 pub enum QueryLogMode {
     /// Do not capture query metrics at all.
     Disabled,
-    /// Only record query metrics for queries that are cached by ReadySet.
-    #[default]
-    Cached,
     /// Record query metrics for all queries, including ad-hoc (simple) queries
     /// as well as prepared statements.
-    AllQueries,
+    Enabled,
     /// Expert-mode. Captures the full suite of developer-level query metrics.
-    /// Not advisable for a production environment.
-    All,
+    /// Not advisable for a production environment, since it includes metric
+    /// labels that may have very high cardinality.
+    Verbose,
 }
 
 impl QueryLogMode {
@@ -38,15 +36,7 @@ impl QueryLogMode {
     }
 
     pub fn is_verbose(&self) -> bool {
-        matches!(self, QueryLogMode::All)
-    }
-
-    pub fn allow_ad_hoc(&self) -> bool {
-        matches!(self, QueryLogMode::AllQueries | QueryLogMode::All)
-    }
-
-    pub fn allow_proxied_queries(&self) -> bool {
-        matches!(self, QueryLogMode::AllQueries | QueryLogMode::All)
+        matches!(self, QueryLogMode::Verbose)
     }
 }
 

readyset/src/lib.rs

@@ -297,8 +297,8 @@ pub struct Options {
         long,
         env = "QUERY_LOG_MODE",
         requires = "metrics",
-        default_value = "all-queries",
-        default_value_if("prometheus_metrics", "true", Some("all-queries")),
+        default_value = "enabled",
+        default_value_if("prometheus_metrics", "true", Some("enabled")),
         hide = true
     )]
     query_log_mode: QueryLogMode,
@@ -1090,7 +1090,7 @@ where
                 .allow_cache_ddl(allow_cache_ddl)
                 .require_authentication(!options.allow_unauthenticated_connections)
                 .dialect(self.parse_dialect)
-                .query_log(qlog_sender.clone(), options.query_log_mode)
+                .query_log(qlog_sender.clone())
                 .unsupported_set_mode(if options.allow_unsupported_set {
                     readyset_adapter::backend::UnsupportedSetMode::Allow
                 } else {