Hi Folks,
Git a weird one, not sure what’s going on.
So I have docker installed on Debian 9, and I am running Metabase using a docker-compose file, which is as follows.
version: '3'
services:
metabase:
image: metabase/metabase:v0.33.5
ports:
- "3001:3000"
volumes:
- /home/upadmin/metabase:/metabase
environment:
- MB_PASSWORD_COMPLEXITY=strong
- MB_PASSWORD_LENGTH=10
- MB_DB_CONNECTION_URI=postgresql://****
- MB_EMOJI_IN_LOGS=true
- MB_ENCRYPTION_SECRET_KEY=****
- MB_PLUGINS_DIR=/metabase/plugins
- JAVA_TOOL_OPTIONS=-Xmx3g
restart: always
I am loading the Oracle DB driver from a folder outside the docker container, and I see it loaded as expected during the startup.
metabase_1 | Picked up JAVA_TOOL_OPTIONS: -Xmx3g
metabase_1 | 11-11 19:10:32 **DEBUG plugins.classloader** :: Using NEWLY CREATED classloader as shared context classloader: clojure.lang.DynamicClassLoader@52f57666
metabase_1 | 11-11 19:10:32 **DEBUG plugins.classloader** :: Setting current thread context classloader to shared classloader clojure.lang.DynamicClassLoader@52f57666...
metabase_1 | 11-11 19:10:34 **INFO metabase.util** :: Loading Metabase...
metabase_1 | 11-11 19:10:34 **INFO metabase.util** :: Maximum memory available to JVM: 2.9 GB
metabase_1 | 11-11 19:10:52 **INFO util.encryption** :: Saved credentials encryption is ENABLED for this Metabase instance. 🔐
metabase_1 | For more information, see https://metabase.com/docs/latest/operations-guide/encrypting-database-details-at-rest.html
metabase_1 | 11-11 19:11:05 **INFO metabase.driver** :: Registered abstract driver :sql 🚚
metabase_1 | 11-11 19:11:25 **INFO metabase.core** :: Starting Metabase in STANDALONE mode
metabase_1 | 11-11 19:11:26 **INFO metabase.server** :: Launching Embedded Jetty Webserver with config:
metabase_1 | {:port 3000, :host "0.0.0.0"}
metabase_1 |
metabase_1 | 11-11 19:11:26 **INFO metabase.core** :: Starting Metabase version v0.33.5 (bf436b4 release-0.33.x) ...
metabase_1 | 11-11 19:11:26 **INFO metabase.core** :: System info:
metabase_1 | {"java.runtime.name" "OpenJDK Runtime Environment",
metabase_1 | "java.runtime.version" "11.0.4+11",
metabase_1 | "java.vendor" "AdoptOpenJDK",
metabase_1 | "java.vendor.url" "https://adoptopenjdk.net/",
metabase_1 | "java.version" "11.0.4",
metabase_1 | "java.vm.name" "OpenJDK 64-Bit Server VM",
metabase_1 | "java.vm.version" "11.0.4+11",
metabase_1 | "os.name" "Linux",
metabase_1 | "os.version" "4.9.0-11-amd64",
metabase_1 | "user.language" "en",
metabase_1 | "user.timezone" "GMT"}
metabase_1 |
metabase_1 | 11-11 19:11:26 **INFO metabase.plugins** :: Loading plugins in /metabase/plugins...
metabase_1 | 11-11 19:11:29 **INFO plugins.classloader** :: Added URL file:/metabase/plugins/ojdbc8.jar to classpath
metabase_1 | 11-11 19:11:29 **INFO plugins.dependencies** :: Plugin 'Metabase Google Analytics Driver' depends on plugin 'Metabase Google Drivers Shared Dependencies'
metabase_1 | 11-11 19:11:29 **INFO plugins.dependencies** :: Metabase Google Analytics Driver dependency {:plugin Metabase Google Drivers Shared Dependencies} satisfied? false
metabase_1 | 11-11 19:11:29 **INFO plugins.dependencies** :: Plugins with unsatisfied deps: ["Metabase Google Analytics Driver"]
metabase_1 | 11-11 19:11:30 **DEBUG plugins.lazy-loaded-driver** :: Registering lazy loading driver :sqlserver...
metabase_1 | 11-11 19:11:30 **INFO metabase.driver** :: Registered abstract driver :sql-jdbc (parents: [:sql]) 🚚
metabase_1 | Load driver :sql-jdbc took 188.5 ms
metabase_1 | 11-11 19:11:30 **INFO metabase.driver** :: Registered driver :sqlserver (parents: [:sql-jdbc]) 🚚
metabase_1 | 11-11 19:11:30 **INFO plugins.dependencies** :: Metabase cannot initialize plugin Metabase Vertica Driver due to required dependencies. Metabase requires the Vertica JDBC driver in order to connect to Vertica databases, but we can't ship it as part of Metabase due to licensing restrictions. See https://metabase.com/docs/latest/administration-guide/databases/vertica.html for more details.
metabase_1 |
metabase_1 | 11-11 19:11:30 **INFO plugins.dependencies** :: Metabase Vertica Driver dependency {:class com.vertica.jdbc.Driver} satisfied? false
metabase_1 | 11-11 19:11:30 **INFO plugins.dependencies** :: Plugins with unsatisfied deps: ["Metabase Vertica Driver" "Metabase Google Analytics Driver"]
metabase_1 | 11-11 19:11:30 **INFO plugins.dependencies** :: Metabase Oracle Driver dependency {:class oracle.jdbc.OracleDriver} satisfied? true
metabase_1 | 11-11 19:11:30 **DEBUG plugins.lazy-loaded-driver** :: Registering lazy loading driver :oracle...
metabase_1 | 11-11 19:11:30 **INFO metabase.driver** :: Registered driver :oracle (parents: [:sql-jdbc]) 🚚
metabase_1 | 11-11 19:11:30 **DEBUG plugins.lazy-loaded-driver** :: Registering lazy loading driver :hive-like...
metabase_1 | 11-11 19:11:30 **INFO metabase.driver** :: Registered abstract driver :hive-like (parents: [:sql-jdbc]) 🚚
metabase_1 | 11-11 19:11:30 **DEBUG plugins.lazy-loaded-driver** :: Registering lazy loading driver :sparksql...
metabase_1 | 11-11 19:11:30 **INFO metabase.driver** :: Registered driver :sparksql (parents: [:hive-like]) 🚚
metabase_1 | 11-11 19:11:30 **DEBUG plugins.lazy-loaded-driver** :: Registering lazy loading driver :snowflake...
metabase_1 | 11-11 19:11:30 **INFO metabase.driver** :: Registered driver :snowflake (parents: [:sql-jdbc]) 🚚
metabase_1 | 11-11 19:11:30 **DEBUG plugins.lazy-loaded-driver** :: Registering lazy loading driver :redshift...
metabase_1 | 11-11 19:11:30 **INFO metabase.driver** :: Registered driver :postgres (parents: [:sql-jdbc]) 🚚
metabase_1 | Load driver :postgres took 188.6 ms
metabase_1 | 11-11 19:11:30 **INFO metabase.driver** :: Registered driver :redshift (parents: [:postgres]) 🚚
metabase_1 | 11-11 19:11:30 **DEBUG plugins.lazy-loaded-driver** :: Registering lazy loading driver :druid...
metabase_1 | 11-11 19:11:30 **INFO metabase.driver** :: Registered driver :druid 🚚
metabase_1 | 11-11 19:11:30 **DEBUG plugins.lazy-loaded-driver** :: Registering lazy loading driver :presto...
metabase_1 | 11-11 19:11:30 **INFO metabase.driver** :: Registered driver :presto (parents: [:sql]) 🚚
metabase_1 | 11-11 19:11:31 **DEBUG plugins.lazy-loaded-driver** :: Registering lazy loading driver :mongo...
metabase_1 | 11-11 19:11:31 **INFO metabase.driver** :: Registered driver :mongo 🚚
metabase_1 | 11-11 19:11:31 **INFO plugins.dependencies** :: Plugin 'Metabase BigQuery Driver' depends on plugin 'Metabase Google Drivers Shared Dependencies'
metabase_1 | 11-11 19:11:31 **INFO plugins.dependencies** :: Metabase BigQuery Driver dependency {:plugin Metabase Google Drivers Shared Dependencies} satisfied? false
metabase_1 | 11-11 19:11:31 **INFO plugins.dependencies** :: Plugins with unsatisfied deps: ["Metabase Vertica Driver" "Metabase Google Analytics Driver" "Metabase BigQuery Driver"]
metabase_1 | 11-11 19:11:31 **DEBUG plugins.lazy-loaded-driver** :: Registering lazy loading driver :google...
metabase_1 | 11-11 19:11:31 **INFO metabase.driver** :: Registered abstract driver :google 🚚
metabase_1 | 11-11 19:11:31 **INFO plugins.dependencies** :: Metabase Google Analytics Driver dependency {:plugin Metabase Google Drivers Shared Dependencies} satisfied? true
metabase_1 | 11-11 19:11:31 **INFO plugins.dependencies** :: Metabase BigQuery Driver dependency {:plugin Metabase Google Drivers Shared Dependencies} satisfied? true
metabase_1 | 11-11 19:11:31 **DEBUG plugins.initialize** :: Dependencies satisfied; these plugins will now be loaded: ["Metabase BigQuery Driver" "Metabase Google Analytics Driver"]
metabase_1 | 11-11 19:11:31 **DEBUG plugins.lazy-loaded-driver** :: Registering lazy loading driver :bigquery...
metabase_1 | 11-11 19:11:31 **INFO metabase.driver** :: Registered driver :bigquery (parents: [:sql :google]) 🚚
metabase_1 | 11-11 19:11:31 **DEBUG plugins.lazy-loaded-driver** :: Registering lazy loading driver :googleanalytics...
metabase_1 | 11-11 19:11:31 **INFO metabase.driver** :: Registered driver :googleanalytics (parents: [:google]) 🚚
metabase_1 | 11-11 19:11:31 **DEBUG plugins.lazy-loaded-driver** :: Registering lazy loading driver :sqlite...
metabase_1 | 11-11 19:11:31 **INFO metabase.driver** :: Registered driver :sqlite (parents: [:sql-jdbc]) 🚚
metabase_1 | 11-11 19:11:34 **INFO metabase.driver** :: Registered driver :mysql (parents: [:sql-jdbc]) 🚚
metabase_1 | Load driver :mysql took 122.7 ms
metabase_1 | 11-11 19:11:34 **INFO metabase.driver** :: Registered driver :h2 (parents: [:sql-jdbc]) 🚚
metabase_1 | Load driver :h2 took 88.9 ms
metabase_1 | 11-11 19:11:34 **INFO metabase.core** :: Setting up and migrating Metabase DB. Please sit tight, this may take a minute...
metabase_1 | Parsed: postgresql nil nil ###
metabase_1 | 11-11 19:11:34 **INFO metabase.db** :: Verifying postgres Database Connection ...
metabase_1 | 11-11 19:11:34 **INFO metabase.driver** :: Initializing driver :sql...
metabase_1 | 11-11 19:11:34 **INFO metabase.driver** :: Initializing driver :sql-jdbc...
metabase_1 | 11-11 19:11:34 **INFO metabase.driver** :: Initializing driver :postgres...
metabase_1 | 11-11 19:11:35 **INFO metabase.db** :: Verify Database Connection ... ✅
metabase_1 | 11-11 19:11:35 **INFO metabase.db** :: Running Database Migrations...
metabase_1 | 11-11 19:11:35 **INFO metabase.db** :: Setting up Liquibase...
metabase_1 | 11-11 19:11:35 **INFO metabase.db** :: Liquibase is ready.
metabase_1 | 11-11 19:11:35 **INFO metabase.db** :: Checking if Database has unrun migrations...
metabase_1 | 11-11 19:11:42 **INFO metabase.db** :: Database Migrations Current ... ✅
metabase_1 | 11-11 19:11:43 **INFO db.migrations** :: Running all necessary data migrations, this may take a minute.
metabase_1 | 11-11 19:11:43 **INFO db.migrations** :: Finished running data migrations.
metabase_1 | Database setup took 9.5 s
metabase_1 | 11-11 19:11:43 **INFO metabase.events** :: Starting events listener: metabase.events.notifications 👂
metabase_1 | 11-11 19:11:43 **INFO metabase.events** :: Starting events listener: metabase.events.metabot-lifecycle 👂
metabase_1 | 11-11 19:11:43 **INFO metabase.events** :: Starting events listener: metabase.events.dependencies 👂
metabase_1 | 11-11 19:11:43 **INFO metabase.events** :: Starting events listener: metabase.events.activity-feed 👂
metabase_1 | 11-11 19:11:44 **INFO metabase.events** :: Starting events listener: metabase.events.last-login 👂
metabase_1 | 11-11 19:11:44 **INFO metabase.events** :: Starting events listener: metabase.events.revision 👂
metabase_1 | 11-11 19:11:44 **INFO metabase.events** :: Starting events listener: metabase.events.sync-database 👂
metabase_1 | 11-11 19:11:44 **INFO metabase.events** :: Starting events listener: metabase.events.view-log 👂
metabase_1 | 11-11 19:11:44 **INFO metabase.events** :: Starting events listener: metabase.events.driver-notifications 👂
metabase_1 | 11-11 19:11:44 **INFO metabase.task** :: Initializing task SyncDatabases 📆
metabase_1 | 11-11 19:11:45 **INFO metabase.task** :: Initializing task CheckForNewVersions 📆
metabase_1 | 11-11 19:11:46 **INFO metabase.task** :: Initializing task SendAnonymousUsageStats 📆
metabase_1 | 11-11 19:11:46 **INFO metabase.task** :: Initializing task SendAbandomentEmails 📆
metabase_1 | 11-11 19:11:46 **INFO metabase.task** :: Initializing task SendPulses 📆
metabase_1 | 11-11 19:11:46 **INFO metabase.task** :: Initializing task SendFollowUpEmails 📆
metabase_1 | 11-11 19:11:46 **INFO metabase.task** :: Initializing task TaskHistoryCleanup 📆
metabase_1 | 11-11 19:11:47 **INFO metabase.core** :: Metabase Initialization COMPLETE
However, when I add the Oracle DB in Metabase the connection always times out.
If I use exactly the same credentials and ip/port/sid from the command line outside of docker on the same machine it connects fine and I can query the DB.
I haven’t created any extra networks e.t.c for docker, and if I open a shell command within the docker instance I can ping the IP address of the Oracle DB Server.
Here is the error log, which I can’t really get anything useful from, does it mean anything to anybody else? Or anything else I can try to get to the bottom of what’s going on? I have a ping running the whole time and I never get any dropped packets and the time is consistent (6ms), I am also able to run the same query using SQL Developer with no problem, and a response time of just over 1 second.
metabase_1 | 11-11 18:56:28 INFO metabase.driver :: Initializing driver :oracle...
metabase_1 | 11-11 18:56:28 INFO plugins.classloader :: Added URL file:/metabase/plugins/oracle.metabase-driver.jar to classpath
metabase_1 | 11-11 18:56:29 DEBUG plugins.init-steps :: Loading plugin namespace metabase.driver.oracle...
metabase_1 | 11-11 18:56:29 INFO metabase.driver :: Registered driver :oracle (parents: [:sql-jdbc]) 🚚
metabase_1 | 11-11 18:56:31 DEBUG plugins.jdbc-proxy :: Registering JDBC proxy driver for class oracle.jdbc.OracleDriver...
metabase_1 | Load lazy loading driver :oracle took 3.0 s
metabase_1 | 11-11 18:56:32 WARN middleware.process-userland-query :: Query failure {:status :failed,
metabase_1 | :class java.lang.IllegalArgumentException,
metabase_1 | :error "No method in multimethod 'connection-details->spec' for dispatch value: :oracle",
metabase_1 | :stacktrace
metabase_1 | ("clojure.lang.MultiFn.getFn(MultiFn.java:156)"
metabase_1 | "clojure.lang.MultiFn.invoke(MultiFn.java:233)"
metabase_1 | "--> driver.sql_jdbc.connection$create_pool_BANG_.invokeStatic(connection.clj:86)"
metabase_1 | "driver.sql_jdbc.connection$create_pool_BANG_.invoke(connection.clj:80)"
metabase_1 | "driver.sql_jdbc.connection$db__GT_pooled_connection_spec.invokeStatic(connection.clj:139)"
metabase_1 | "driver.sql_jdbc.connection$db__GT_pooled_connection_spec.invoke(connection.clj:121)"
metabase_1 | "driver.sql_jdbc.execute$execute_query$fn__67596.invoke(execute.clj:287)"
metabase_1 | "driver.sql_jdbc.execute$do_with_try_catch.invokeStatic(execute.clj:217)"
metabase_1 | "driver.sql_jdbc.execute$do_with_try_catch.invoke(execute.clj:211)"
metabase_1 | "driver.sql_jdbc.execute$execute_query.invokeStatic(execute.clj:285)"
metabase_1 | "driver.sql_jdbc.execute$execute_query.invoke(execute.clj:279)"
metabase_1 | "driver.sql_jdbc$fn__67840.invokeStatic(sql_jdbc.clj:44)"
metabase_1 | "driver.sql_jdbc$fn__67840.invoke(sql_jdbc.clj:43)"
metabase_1 | "query_processor$fn__44946$execute_query__44951$fn__44952.invoke(query_processor.clj:71)"
metabase_1 | "query_processor$fn__44946$execute_query__44951.invoke(query_processor.clj:65)"
metabase_1 | "query_processor.middleware.mbql_to_native$mbql__GT_native$fn__35224.invoke(mbql_to_native.clj:38)"
metabase_1 | "query_processor.middleware.annotate$result_rows_maps__GT_vectors$fn__37477.invoke(annotate.clj:541)"
metabase_1 | "query_processor.middleware.annotate$add_column_info$fn__37383.invoke(annotate.clj:485)"
metabase_1 | "query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__38418.invoke(cumulative_aggregations.clj:57)"
metabase_1 | "query_processor.middleware.resolve_joins$resolve_joins$fn__42054.invoke(resolve_joins.clj:184)"
metabase_1 | "query_processor.middleware.limit$limit$fn__39019.invoke(limit.clj:19)"
metabase_1 | "query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__44813.invoke(results_metadata.clj:87)"
metabase_1 | "query_processor.middleware.format_rows$format_rows$fn__39007.invoke(format_rows.clj:26)"
metabase_1 | "query_processor.middleware.add_dimension_projections$add_remapping$fn__35983.invoke(add_dimension_projections.clj:232)"
metabase_1 | "query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__36611.invoke(add_source_metadata.clj:107)"
metabase_1 | "query_processor.middleware.resolve_source_table$resolve_source_tables$fn__42104.invoke(resolve_source_table.clj:46)"
metabase_1 | "query_processor.middleware.add_row_count_and_status$add_row_count_and_status$fn__36471.invoke(add_row_count_and_status.clj:16)"
metabase_1 | "query_processor.middleware.driver_specific$process_query_in_context$fn__38494.invoke(driver_specific.clj:12)"
metabase_1 | "query_processor.middleware.resolve_driver$resolve_driver$fn__41718.invoke(resolve_driver.clj:22)"
metabase_1 | "query_processor.middleware.bind_effective_timezone$bind_effective_timezone$fn__37808$fn__37809.invoke(bind_effective_timezone.clj:9)"
metabase_1 | "util.date$call_with_effective_timezone.invokeStatic(date.clj:88)"
metabase_1 | "util.date$call_with_effective_timezone.invoke(date.clj:77)"
metabase_1 | "query_processor.middleware.bind_effective_timezone$bind_effective_timezone$fn__37808.invoke(bind_effective_timezone.clj:8)"
metabase_1 | "query_processor.middleware.store$initialize_store$fn__44838$fn__44839.invoke(store.clj:11)"
metabase_1 | "query_processor.store$do_with_store.invokeStatic(store.clj:46)"
metabase_1 | "query_processor.store$do_with_store.invoke(store.clj:40)"
metabase_1 | "query_processor.middleware.store$initialize_store$fn__44838.invoke(store.clj:10)"
metabase_1 | "query_processor.middleware.async$async__GT_sync$fn__35135.invoke(async.clj:23)"
metabase_1 | "query_processor.middleware.async_wait$runnable$fn__37534.invoke(async_wait.clj:89)"),
metabase_1 | :query
metabase_1 | {:constraints {:max-results 10000, :max-results-bare-rows 2000},
metabase_1 | :type :native,
metabase_1 | :middleware {:userland-query? true},
metabase_1 | :native
metabase_1 | {:query
metabase_1 | "SELECT * FROM \n( \n SELECT * FROM (\n SELECT SUM(\"R2\".\"REP_POHEADERVIEW\".\"SUBTOTAL\") AS \"SUBTOTAL\" from \"R2\".\"REP_POHEADERVIEW\"\n LEFT JOIN (\n SELECT DISTINCT (POID)POID, TRANSACTIONCURRENCYID FROM \"R2\".\"REP_PODETAILVIEW\"\n ORDER BY \"R2\".\"REP_PODETAILVIEW\".\"POID\" DESC\n ) FILTERED_PO_LINES\n ON \"R2\".\"REP_POHEADERVIEW\".\"POID\" = FILTERED_PO_LINES.POID\n WHERE (\"R2\".\"REP_POHEADERVIEW\".\"APPROVEDSTATUS\" = 'Approved'\n AND \"R2\".\"REP_POHEADERVIEW\".\"POSTATUS\" IN ('OPEN', 'RECEIVED') AND \"R2\".\"REP_POHEADERVIEW\".\"AMOUNT\" > 0 AND FILTERED_PO_LINES.TRANSACTIONCURRENCYID = 'EUR')\n [[AND {{PO_TYPE}}]]\n ORDER BY \"R2\".\"REP_POHEADERVIEW\".\"DATECREATED\"\n )\n) WHERE rownum <= 1048576",
metabase_1 | :template-tags {"PO_TYPE" {:id "d3d5bcd4-ec9b-3225-ff1d-9a49104a054e", :name "PO_TYPE", :display-name "PO TYPE", :type :dimension, :dimension [:field-id 10417], :widget-type :category}}},
metabase_1 | :info
metabase_1 | {:executed-by 1,
metabase_1 | :context :question,
metabase_1 | :card-id 16,
metabase_1 | :dashboard-id nil,
metabase_1 | :query-hash [92, 108, 47, -47, -23, 51, 23, -107, 19, 63, 53, -43, -8, -6, 45, -125, 9, -25, 29, -9, 108, 95, 64, 9, 95, 103, 12, -16, 23, -86, 88, 40]},
metabase_1 | :parameters [],
metabase_1 | :async? true,
metabase_1 | :cache-ttl 500}}
metabase_1 |
metabase_1 | 11-11 18:56:32 DEBUG middleware.log :: POST /api/card/16/query 200 [ASYNC: completed] 4.5 s (13 DB calls) Jetty threads: 3/50 (7 idle, 0 queued) (55 total active threads) Queries in flight: 3
metabase_1 | 11-11 18:56:33 WARN middleware.process-userland-query :: Query failure {:status :failed,
metabase_1 | :class java.lang.IllegalArgumentException,
metabase_1 | :error "No method in multimethod 'connection-details->spec' for dispatch value: :oracle",
metabase_1 | :stacktrace
metabase_1 | ("clojure.lang.MultiFn.getFn(MultiFn.java:156)"
metabase_1 | "clojure.lang.MultiFn.invoke(MultiFn.java:233)"
metabase_1 | "--> driver.sql_jdbc.connection$create_pool_BANG_.invokeStatic(connection.clj:86)"
metabase_1 | "driver.sql_jdbc.connection$create_pool_BANG_.invoke(connection.clj:80)"
metabase_1 | "driver.sql_jdbc.connection$db__GT_pooled_connection_spec.invokeStatic(connection.clj:139)"
metabase_1 | "driver.sql_jdbc.connection$db__GT_pooled_connection_spec.invoke(connection.clj:121)"
metabase_1 | "driver.sql_jdbc.execute$execute_query$fn__67596.invoke(execute.clj:287)"
metabase_1 | "driver.sql_jdbc.execute$do_with_try_catch.invokeStatic(execute.clj:217)"
metabase_1 | "driver.sql_jdbc.execute$do_with_try_catch.invoke(execute.clj:211)"
metabase_1 | "driver.sql_jdbc.execute$execute_query.invokeStatic(execute.clj:285)"
metabase_1 | "driver.sql_jdbc.execute$execute_query.invoke(execute.clj:279)"
metabase_1 | "driver.sql_jdbc$fn__67840.invokeStatic(sql_jdbc.clj:44)"
metabase_1 | "driver.sql_jdbc$fn__67840.invoke(sql_jdbc.clj:43)"
metabase_1 | "query_processor$fn__44946$execute_query__44951$fn__44952.invoke(query_processor.clj:71)"
metabase_1 | "query_processor$fn__44946$execute_query__44951.invoke(query_processor.clj:65)"
metabase_1 | "query_processor.middleware.mbql_to_native$mbql__GT_native$fn__35224.invoke(mbql_to_native.clj:38)"
metabase_1 | "query_processor.middleware.annotate$result_rows_maps__GT_vectors$fn__37477.invoke(annotate.clj:541)"
metabase_1 | "query_processor.middleware.annotate$add_column_info$fn__37383.invoke(annotate.clj:485)"
metabase_1 | "query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__38418.invoke(cumulative_aggregations.clj:57)"
metabase_1 | "query_processor.middleware.resolve_joins$resolve_joins$fn__42054.invoke(resolve_joins.clj:184)"
metabase_1 | "query_processor.middleware.limit$limit$fn__39019.invoke(limit.clj:19)"
metabase_1 | "query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__44813.invoke(results_metadata.clj:87)"
metabase_1 | "query_processor.middleware.format_rows$format_rows$fn__39007.invoke(format_rows.clj:26)"
metabase_1 | "query_processor.middleware.add_dimension_projections$add_remapping$fn__35983.invoke(add_dimension_projections.clj:232)"
metabase_1 | "query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__36611.invoke(add_source_metadata.clj:107)"
metabase_1 | "query_processor.middleware.resolve_source_table$resolve_source_tables$fn__42104.invoke(resolve_source_table.clj:46)"
metabase_1 | "query_processor.middleware.add_row_count_and_status$add_row_count_and_status$fn__36471.invoke(add_row_count_and_status.clj:16)"
metabase_1 | "query_processor.middleware.driver_specific$process_query_in_context$fn__38494.invoke(driver_specific.clj:12)"
metabase_1 | "query_processor.middleware.resolve_driver$resolve_driver$fn__41718.invoke(resolve_driver.clj:22)"
metabase_1 | "query_processor.middleware.bind_effective_timezone$bind_effective_timezone$fn__37808$fn__37809.invoke(bind_effective_timezone.clj:9)"
metabase_1 | "util.date$call_with_effective_timezone.invokeStatic(date.clj:88)"
metabase_1 | "util.date$call_with_effective_timezone.invoke(date.clj:77)"
metabase_1 | "query_processor.middleware.bind_effective_timezone$bind_effective_timezone$fn__37808.invoke(bind_effective_timezone.clj:8)"
metabase_1 | "query_processor.middleware.store$initialize_store$fn__44838$fn__44839.invoke(store.clj:11)"
metabase_1 | "query_processor.store$do_with_store.invokeStatic(store.clj:46)"
metabase_1 | "query_processor.store$do_with_store.invoke(store.clj:40)"
metabase_1 | "query_processor.middleware.store$initialize_store$fn__44838.invoke(store.clj:10)"
metabase_1 | "query_processor.middleware.async$async__GT_sync$fn__35135.invoke(async.clj:23)"
metabase_1 | "query_processor.middleware.async_wait$runnable$fn__37534.invoke(async_wait.clj:89)"),
metabase_1 | :query
metabase_1 | {:constraints {:max-results 10000, :max-results-bare-rows 2000},
metabase_1 | :type :native,
metabase_1 | :middleware {:userland-query? true},
metabase_1 | :native
metabase_1 | {:query
metabase_1 | "SELECT * FROM \n(\n SELECT * FROM \n (\n SELECT * FROM \n (\n SELECT \"R2\".\"REP_POHEADERVIEW\".\"POID\" AS \"POID\", \"R2\".\"REP_POHEADERVIEW\".\"DESCRIPTION\" AS \"DESCRIPTION\", \n \"R2\".\"REP_POHEADERVIEW\".\"COMPANYNAME\" AS \"COMPANYNAME\", \"R2\".\"REP_POHEADERVIEW\".\"SUBTOTAL\" AS \"SUBTOTAL\",\n \"R2\".\"REP_POHEADERVIEW\".\"TAXAMOUNT\" AS \"TAXAMOUNT\", \"R2\".\"REP_POHEADERVIEW\".\"CREATEDBY\" AS \"CREATEDBY\",\n CAST(\"R2\".\"REP_POHEADERVIEW\".\"DATECREATED\" AS date) AS \"DATECREATED\", \"R2\".\"REP_POHEADERVIEW\".\"ORDERID\" AS \"ORDERID\", \n \"R2\".\"REP_POHEADERVIEW\".\"POSTATUS\" AS \"POSTATUS\", \"R2\".\"REP_POHEADERVIEW\".\"POTYPE\" AS \"POTYPE\", \"R2\".\"REP_POHEADERVIEW\".\"PROFITCENTRE\" AS \"PROFITCENTRE\", \n FILTERED_PO_LINES.TRANSACTIONCURRENCYID,\n (\n CASE FILTERED_PO_LINES.TRANSACTIONCURRENCYID\n WHEN 'USD'\n THEN \"R2\".\"REP_POHEADERVIEW\".\"SUBTOTAL\" * {{USD_RATE}}\n WHEN 'EUR'\n THEN \"R2\".\"REP_POHEADERVIEW\".\"SUBTOTAL\" * {{EUR_RATE}}\n ELSE\n \"R2\".\"REP_POHEADERVIEW\".\"SUBTOTAL\"\n END\n ) \"GBP SUBTOTAL\",\n (\n CASE FILTERED_PO_LINES.TRANSACTIONCURRENCYID\n WHEN 'USD'\n THEN \"R2\".\"REP_POHEADERVIEW\".\"TAXAMOUNT\" * {{USD_RATE}}\n WHEN 'EUR'\n THEN \"R2\".\"REP_POHEADERVIEW\".\"TAXAMOUNT\" * {{EUR_RATE}}\n ELSE\n \"R2\".\"REP_POHEADERVIEW\".\"TAXAMOUNT\"\n END\n ) \"GBP VAT\",\n (\n CASE FILTERED_PO_LINES.TRANSACTIONCURRENCYID\n WHEN 'USD'\n THEN {{USD_RATE}}\n WHEN 'EUR'\n THEN {{EUR_RATE}}\n ELSE\n 1\n END\n ) \"RATE USED\",\n \"R2\".\"REP_ORDERHEADERVIEW\".\"CONTRACTDESCRIPTION\"\n from \"R2\".\"REP_POHEADERVIEW\"\n LEFT JOIN (\n SELECT DISTINCT (POID)POID, TRANSACTIONCURRENCYID FROM \"R2\".\"REP_PODETAILVIEW\"\n ORDER BY \"R2\".\"REP_PODETAILVIEW\".\"POID\" DESC\n ) FILTERED_PO_LINES\n ON \"R2\".\"REP_POHEADERVIEW\".\"POID\" = FILTERED_PO_LINES.POID\n LEFT JOIN \"R2\".\"REP_ORDERHEADERVIEW\" ON \"R2\".\"REP_POHEADERVIEW\".\"ORDERID\" = \"R2\".\"REP_ORDERHEADERVIEW\".\"CONTRACTID\"\n WHERE (\"R2\".\"REP_POHEADERVIEW\".\"APPROVEDSTATUS\" = 'Approved'\n AND \"R2\".\"REP_POHEADERVIEW\".\"POSTATUS\" IN ('OPEN', 'RECEIVED') AND \"R2\".\"REP_POHEADERVIEW\".\"AMOUNT\" > 0 )\n [[AND {{PO_TYPE}}]]\n ORDER BY \"R2\".\"REP_POHEADERVIEW\".\"DATECREATED\"\n ) \n )\n) \nWHERE rownum <= 1048576\n\n\n\n",
metabase_1 | :template-tags
metabase_1 | {"PO_TYPE" {:id "1ceeef4a-8d9d-8e30-1371-8a8031cb594f", :name "PO_TYPE", :display-name "PO Type", :type :dimension, :dimension [:field-id 10417], :widget-type :category},
metabase_1 | "USD_RATE" {:id "19d97472-4836-ff8f-7baf-e8013d50af52", :name "USD_RATE", :display-name "USD Rate", :type :number, :required true, :default "0.8"},
metabase_1 | "EUR_RATE" {:id "fdd0aa77-60e5-f1df-fa70-aa361a68d5a2", :name "EUR_RATE", :display-name "Euro Rate", :type :number, :required true, :default "0.9"}}},
metabase_1 | :info
metabase_1 | {:executed-by 1,
metabase_1 | :context :question,
metabase_1 | :card-id 17,
metabase_1 | :dashboard-id nil,
metabase_1 | :query-hash [28, 127, -16, 52, 20, -73, 63, -30, -81, 115, 122, 93, 7, -89, -112, 97, -16, 48, 22, 16, -110, -11, -6, -12, -14, -98, 66, 85, 103, 76, -116, -126]},
metabase_1 | :parameters [{:type "category", :target ["variable" ["template-tag" "USD_RATE"]], :value "0.8"} {:type "category", :target ["variable" ["template-tag" "EUR_RATE"]], :value "0.9"}],
metabase_1 | :async? true,
metabase_1 | :cache-ttl 369}}
metabase_1 |
metabase_1 | 11-11 18:56:33 DEBUG middleware.log :: POST /api/card/17/query 200 [ASYNC: completed] 5.5 s (14 DB calls) Jetty threads: 3/50 (7 idle, 0 queued) (58 total active threads) Queries in flight: 2
metabase_1 | 11-11 18:56:38 DEBUG middleware.log :: GET /api/database/2/metadata 200 10.7 s (7 DB calls) Jetty threads: 3/50 (7 idle, 0 queued) (58 total active threads) Queries in flight: 2
metabase_1 | 11-11 18:57:11 DEBUG middleware.log :: POST /api/card/15/query 200 [ASYNC: canceled] 43.0 s (9 DB calls) Jetty threads: 2/50 (8 idle, 0 queued) (58 total active threads) Queries in flight: 1
metabase_1 | 11-11 18:57:11 DEBUG middleware.log :: POST /api/card/14/query 200 [ASYNC: canceled] 43.0 s (9 DB calls) Jetty threads: 2/50 (8 idle, 0 queued) (58 total active threads) Queries in flight: 1
metabase_1 | 11-11 18:57:11 ERROR sql-jdbc.execute :: Failed to set timezone:
metabase_1 | SQLException:
metabase_1 | Message: An SQLException was provoked by the following failure: java.lang.InterruptedException
metabase_1 | SQLState: null
metabase_1 | Error Code: 0
metabase_1 |
metabase_1 | 11-11 18:57:11 ERROR sql-jdbc.execute :: Failed to set timezone:
metabase_1 | SQLException:
metabase_1 | Message: An SQLException was provoked by the following failure: java.lang.InterruptedException
metabase_1 | SQLState: null
metabase_1 | Error Code: 0
metabase_1 |
metabase_1 | 11-11 18:57:11 DEBUG middleware.log :: GET /api/session/properties 200 34.5 ms (1 DB calls) Jetty threads: 4/50 (6 idle, 0 queued) (58 total active threads) Queries in flight: 0
metabase_1 | 11-11 18:57:11 DEBUG middleware.log :: GET /api/setting 200 14.7 ms (0 DB calls) Jetty threads: 4/50 (6 idle, 0 queued) (58 total active threads) Queries in flight: 0
metabase_1 | 11-11 18:57:11 DEBUG middleware.log :: GET /api/setup/admin_checklist 200 146.3 ms (11 DB calls) Jetty threads: 4/50 (6 idle, 0 queued) (58 total active threads) Queries in flight: 0
Thanks
Gareth
