From dbc4a37d8ffd139251d30659018d7e863cf15879 Mon Sep 17 00:00:00 2001
From: dpsutton <dan@dpsutton.com>
Date: Fri, 31 Mar 2023 16:07:42 -0500
Subject: [PATCH] Don't log in bigquery results hotpath (#29727)
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit
* Don't log in bigquery results hotpath
Right now we log in the parser of bigquery results for unrecognized
types. But the problem is that we log for each _value_ and not each
column. This is causing an _enormous_ amount of logs and performance
penalty.
See
- https://github.com/metabase/metabase/issues/29118 (performance)
- https://github.com/metabase/metabase/issues/28868 (filling disk space)
This log was added between 45.1 and 45.3
```diff
⯠git diff v0.45.1..v0.45.3 modules/drivers/bigquery-cloud-sdk/src/metabase/driver/bigquery_cloud_sdk/**
diff --git a/modules/drivers/bigquery-cloud-sdk/src/metabase/driver/bigquery_cloud_sdk/query_processor.clj b/modules/drivers/bigquery-cloud-sdk/src/metabase/driver/bigquery_cloud_sdk/query_processor.clj
index a0d8081c30..f367199b55 100644
--- a/modules/drivers/bigquery-cloud-sdk/src/metabase/driver/bigquery_cloud_sdk/query_processor.clj
+++ b/modules/drivers/bigquery-cloud-sdk/src/metabase/driver/bigquery_cloud_sdk/query_processor.clj
@@ -22,7 +22,7 @@
[metabase.util :as u]
[metabase.util.date-2 :as u.date]
[metabase.util.honeysql-extensions :as hx]
- [metabase.util.i18n :refer [tru]]
+ [metabase.util.i18n :refer [trs tru]]
[pretty.core :refer [PrettyPrintable]]
[schema.core :as s])
(:import [com.google.cloud.bigquery Field$Mode FieldValue]
@@ -88,7 +88,8 @@
(parse-fn v)))
(defmethod parse-result-of-type :default
- [_ column-mode _ v]
+ [column-type column-mode _ v]
+ (log/warn (trs "Warning: missing type mapping for parsing BigQuery results of type {0}." column-type))
(parse-value column-mode v identity))
```
The result is that selecting 50,000 rows for download in excel:
| version | time |
|------------------------------|------------|
| 0.45.1 | 28 seconds |
| 0.45.3 | 52 seconds |
| 0.45.3 with logging disabled | 30 seconds |
(disable logging by adding `<Logger
name="metabase.driver.bigquery-cloud-sdk.query-processor"
level="ERROR"/>` and `-Dlog4j2.configurationFile=log4j2.xml` to jar
startup)
For the query (3 string columns, 5 rows):
```sql
SELECT game_id, first_name, last_name
FROM `bigquery-public-data.ncaa_basketball.mbb_players_games_sr`
LIMIT 5
```
BEFORE:
```
```
2023-03-31 17:17:52,146 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,147 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,147 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,149 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,149 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,149 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,149 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,149 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,149 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,150 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,150 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,150 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,150 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,150 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,150 WARN bigquery-cloud-sdk.query-processor :: Warning: missing type mapping for parsing BigQuery results of type STRING.
2023-03-31 17:17:52,155 DEBUG middleware.log :: POST /api/dataset 202 [ASYNC: completed] 795.2 ms (6 DB calls) App DB connections: 0/10 Jetty threads: 4/50 (2 idle, 0 queued) (192 total active threads) Queries in flight: 0 (0 queued)
```
Note this is 15 logs (3 columns x 5 rows)
AFTER:
```
2023-03-31 17:19:15,694 WARN driver.bigquery-cloud-sdk :: Warning: missing type mapping for parsing BigQuery results column game_id of type STRING.
2023-03-31 17:19:15,694 WARN driver.bigquery-cloud-sdk :: Warning: missing type mapping for parsing BigQuery results column first_name of type STRING.
2023-03-31 17:19:15,694 WARN driver.bigquery-cloud-sdk :: Warning: missing type mapping for parsing BigQuery results column last_name of type STRING.
2023-03-31 17:19:15,757 DEBUG middleware.log :: POST /api/dataset 202 [ASYNC: completed] 973.5 ms (6 DB calls) App DB connections: 0/10 Jetty threads: 4/50 (3 idle, 0 queued) (193 total active threads) Queries in flight: 0 (0 queued)
```
* unused require to appease our overlords
---
.../metabase/driver/bigquery_cloud_sdk.clj | 20 ++++++++++++-------
.../bigquery_cloud_sdk/query_processor.clj | 5 ++---
2 files changed, 15 insertions(+), 10 deletions(-)
diff --git a/modules/drivers/bigquery-cloud-sdk/src/metabase/driver/bigquery_cloud_sdk.clj b/modules/drivers/bigquery-cloud-sdk/src/metabase/driver/bigquery_cloud_sdk.clj
index fcc4746ea04..54250647325 100644
--- a/modules/drivers/bigquery-cloud-sdk/src/metabase/driver/bigquery_cloud_sdk.clj
+++ b/modules/drivers/bigquery-cloud-sdk/src/metabase/driver/bigquery_cloud_sdk.clj
@@ -166,13 +166,19 @@
set)})
(defn- get-field-parsers [^Schema schema]
- (into []
- (map (fn [^Field field]
- (let [column-type (.. field getType name)
- column-mode (.getMode field)
- method (get-method bigquery.qp/parse-result-of-type column-type)]
- (partial method column-type column-mode bigquery.common/*bigquery-timezone-id*))))
- (.getFields schema)))
+ (let [default-parser (get-method bigquery.qp/parse-result-of-type :default)]
+ (into []
+ (map (fn [^Field field]
+ (let [column-type (.. field getType name)
+ column-mode (.getMode field)
+ method (get-method bigquery.qp/parse-result-of-type column-type)]
+ (when (= method default-parser)
+ (let [column-name (.getName field)]
+ (log/warn (trs "Warning: missing type mapping for parsing BigQuery results column {0} of type {1}."
+ column-name
+ column-type))))
+ (partial method column-type column-mode bigquery.common/*bigquery-timezone-id*))))
+ (.getFields schema))))
(defn- parse-field-value [^FieldValue cell parser]
(when-let [v (.getValue cell)]
diff --git a/modules/drivers/bigquery-cloud-sdk/src/metabase/driver/bigquery_cloud_sdk/query_processor.clj b/modules/drivers/bigquery-cloud-sdk/src/metabase/driver/bigquery_cloud_sdk/query_processor.clj
index c84ad749c2d..bcba1a59c27 100644
--- a/modules/drivers/bigquery-cloud-sdk/src/metabase/driver/bigquery_cloud_sdk/query_processor.clj
+++ b/modules/drivers/bigquery-cloud-sdk/src/metabase/driver/bigquery_cloud_sdk/query_processor.clj
@@ -22,7 +22,7 @@
[metabase.util :as u]
[metabase.util.date-2 :as u.date]
[metabase.util.honeysql-extensions :as hx]
- [metabase.util.i18n :refer [trs tru]]
+ [metabase.util.i18n :refer [tru]]
[metabase.util.log :as log]
[pretty.core :refer [PrettyPrintable]]
[schema.core :as s])
@@ -92,8 +92,7 @@
(parse-fn v)))
(defmethod parse-result-of-type :default
- [column-type column-mode _ v]
- (log/warn (trs "Warning: missing type mapping for parsing BigQuery results of type {0}." column-type))
+ [_column-type column-mode _ v]
(parse-value column-mode v identity))
(defmethod parse-result-of-type "STRING"
--
GitLab