We are facing an issue related to Oracle connections. Since February 9th, we started to notice a slowdown in using Metabase. We noticed that the CPU usage of the container where Metabase is installed was high.
On investigation we noticed an error only for Oracle connections: "Locale not recognized". We found in forums that when this error occurs in Java applications, it is necessary to check the timezone and language of the environment. We changed the settings in the container. This fixed the problem at first, but it reoccurred after a few days.
An important point is that it occurs gradually, starting with errors in just a few native queries until it is no longer possible to connect to the databases.
Below is a sample of the error in the log and the environment settings.
[fb523f2f-0844-4ef0-a149-881b38558b43] 2023-03-28T14:00:16-03:00 ERROR metabase.query-processor.middleware.catch-exceptions Erro ao processar a consulta: Locale not recognized
{:database_id 99,
:started_at #t "2023-03-28T14:00:12.279248-03:00[America/Sao_Paulo]",
:via
[{:status :failed,
:class com.mchange.v2.resourcepool.CannotAcquireResourceException,
:error "A ResourcePool could not acquire a resource from its primary factory or source.",
:stacktrace
["com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1507)"
"com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:644)"
"com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:554)"
"com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutAndMarkConnectionInUse(C3P0PooledConnectionPool.java:758)"
"com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:685)"
"com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140)"
"--> driver.sql_jdbc.execute$fn__55821.invokeStatic(execute.clj:191)"
"driver.sql_jdbc.execute$fn__55821.invoke(execute.clj:189)"
"driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:496)"
"driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:485)"
"driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:493)"
"driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:485)"
"driver.sql_jdbc$fn__88395.invokeStatic(sql_jdbc.clj:58)"
"driver.sql_jdbc$fn__88395.invoke(sql_jdbc.clj:56)"
"driver.oracle$fn__86065.invokeStatic(oracle.clj:401)"
"driver.oracle$fn__86065.invoke(oracle.clj:399)"
"query_processor.context$executef.invokeStatic(context.clj:59)"
"query_processor.context$executef.invoke(context.clj:48)"
"query_processor.context.default$default_runf.invokeStatic(default.clj:67)"
"query_processor.context.default$default_runf.invoke(default.clj:65)"
"query_processor.context$runf.invokeStatic(context.clj:45)"
"query_processor.context$runf.invoke(context.clj:39)"
"query_processor.reducible$identity_qp.invokeStatic(reducible.clj:12)"
"query_processor.reducible$identity_qp.invoke(reducible.clj:9)"
"query_processor.middleware.cache$maybe_return_cached_results$maybe_return_cached_results_STAR___53529.invoke(cache.clj:220)"
"query_processor.middleware.permissions$check_query_permissions$fn__49184.invoke(permissions.clj:109)"
"query_processor.middleware.mbql_to_native$mbql__GT_native$fn__52474.invoke(mbql_to_native.clj:23)"
"query_processor$fn__55005$combined_post_process__55010$combined_post_process_STAR___55011.invoke(query_processor.clj:212)"
"query_processor$fn__55005$combined_pre_process__55006$combined_pre_process_STAR___55007.invoke(query_processor.clj:209)"
"query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__53450$fn__53455.invoke(resolve_database_and_driver.clj:35)"
"driver$do_with_driver.invokeStatic(driver.clj:76)"
"driver$do_with_driver.invoke(driver.clj:72)"
"query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__53450.invoke(resolve_database_and_driver.clj:34)"
"query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__49450.invoke(fetch_source_query.clj:314)"
"query_processor.middleware.store$initialize_store$fn__49640$fn__49641.invoke(store.clj:11)"
"query_processor.store$do_with_store.invokeStatic(store.clj:45)"
"query_processor.store$do_with_store.invoke(store.clj:39)"
"query_processor.middleware.store$initialize_store$fn__49640.invoke(store.clj:10)"
"query_processor.middleware.normalize_query$normalize$fn__53722.invoke(normalize_query.clj:22)"
"query_processor.middleware.constraints$add_default_userland_constraints$fn__50728.invoke(constraints.clj:53)"
"query_processor.middleware.process_userland_query$process_userland_query$fn__53661.invoke(process_userland_query.clj:145)"
"query_processor.middleware.catch_exceptions$catch_exceptions$fn__54033.invoke(catch_exceptions.clj:167)"
"query_processor.reducible$async_qp$qp_STAR___45482$thunk__45484.invoke(reducible.clj:100)"
"query_processor.reducible$async_qp$qp_STAR___45482.invoke(reducible.clj:106)"
"query_processor.reducible$async_qp$qp_STAR___45482.invoke(reducible.clj:91)"
"query_processor.reducible$async_qp$qp_STAR___45482.invoke(reducible.clj:88)"
"query_processor.reducible$sync_qp$qp_STAR___45493.doInvoke(reducible.clj:126)"
"query_processor$process_userland_query.invokeStatic(query_processor.clj:331)"
"query_processor$process_userland_query.doInvoke(query_processor.clj:327)"
"query_processor$fn__55052$process_query_and_save_execution_BANG___55061$fn__55062.invoke(query_processor.clj:339)"
"query_processor$fn__55052$process_query_and_save_execution_BANG___55061.invoke(query_processor.clj:335)"
"query_processor$fn__55096$process_query_and_save_with_max_results_constraints_BANG___55105$fn__55106.invoke(query_processor.clj:351)"
"query_processor$fn__55096$process_query_and_save_with_max_results_constraints_BANG___55105.invoke(query_processor.clj:347)"
"pulse.util$execute_card$process_query__57790.invoke(util.clj:25)"
"pulse.util$execute_card$fn__57792.invoke(util.clj:34)"
"server.middleware.session$do_with_current_user.invokeStatic(session.clj:310)"
"server.middleware.session$do_with_current_user.invoke(session.clj:299)"
"pulse.util$execute_card.invokeStatic(util.clj:33)"
"pulse.util$execute_card.doInvoke(util.clj:14)"
"pulse$pulse__GT_notifications$iter__80703__80707$fn__80708.invoke(pulse.clj:373)"
"pulse$fn__80655.invokeStatic(pulse.clj:304)"
"pulse$fn__80655.invoke(pulse.clj:298)"
"pulse$results__GT_notifications$iter__80685__80689$fn__80690.invoke(pulse.clj:361)"
"pulse$send_notifications_BANG_.invokeStatic(pulse.clj:481)"
"pulse$send_notifications_BANG_.invoke(pulse.clj:480)"
"pulse$send_pulse_BANG_.invokeStatic(pulse.clj:508)"
"pulse$send_pulse_BANG_.doInvoke(pulse.clj:489)"
"task.send_pulses$fn__85764$send_pulses_BANG___85773$fn__85776$fn__85794$fn__85795.invoke(send_pulses.clj:56)"
"models.task_history$fn__42678$do_with_task_history__42683$fn__42684.invoke(task_history.clj:110)"
"models.task_history$fn__42678$do_with_task_history__42683.invoke(task_history.clj:105)"
"task.send_pulses$fn__85764$send_pulses_BANG___85773$fn__85776$fn__85794.invoke(send_pulses.clj:52)"
"task.send_pulses$fn__85764$send_pulses_BANG___85773$fn__85776.invoke(send_pulses.clj:51)"
"task.send_pulses$fn__85764$send_pulses_BANG___85773.invoke(send_pulses.clj:38)"
"task.send_pulses$fn__85764$send_pulses_BANG___85773$fn__85774.invoke(send_pulses.clj:45)"
"task.send_pulses$fn__85764$send_pulses_BANG___85773.invoke(send_pulses.clj:38)"
"task.send_pulses.SendPulses$fn__85830.invoke(send_pulses.clj:96)"
"models.task_history$fn__42678$do_with_task_history__42683$fn__42684.invoke(task_history.clj:110)"
"models.task_history$fn__42678$do_with_task_history__42683.invoke(task_history.clj:105)"
"task.send_pulses.SendPulses.execute(send_pulses.clj:82)"]}
{:status :failed,
:class java.sql.SQLException,
:error "Connections could not be acquired from the underlying database!",
:stacktrace
["com.mchange.v2.sql.SqlUtils.toSQLException(SqlUtils.java:118)"
"com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:692)"
"com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140)"
"--> driver.sql_jdbc.execute$fn__55821.invokeStatic(execute.clj:191)"
"driver.sql_jdbc.execute$fn__55821.invoke(execute.clj:189)"
"driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:496)"
"driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:485)"
"driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:493)"
"driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:485)"
"driver.sql_jdbc$fn__88395.invokeStatic(sql_jdbc.clj:58)"
"driver.sql_jdbc$fn__88395.invoke(sql_jdbc.clj:56)"
"driver.oracle$fn__86065.invokeStatic(oracle.clj:401)"
"driver.oracle$fn__86065.invoke(oracle.clj:399)"
"query_processor.context$executef.invokeStatic(context.clj:59)"
"query_processor.context$executef.invoke(context.clj:48)"
"query_processor.context.default$default_runf.invokeStatic(default.clj:67)"
"query_processor.context.default$default_runf.invoke(default.clj:65)"
"query_processor.context$runf.invokeStatic(context.clj:45)"
"query_processor.context$runf.invoke(context.clj:39)"
"query_processor.reducible$identity_qp.invokeStatic(reducible.clj:12)"
"query_processor.reducible$identity_qp.invoke(reducible.clj:9)"
"query_processor.middleware.cache$maybe_return_cached_results$maybe_return_cached_results_STAR___53529.invoke(cache.clj:220)"
"query_processor.middleware.permissions$check_query_permissions$fn__49184.invoke(permissions.clj:109)"
"query_processor.middleware.mbql_to_native$mbql__GT_native$fn__52474.invoke(mbql_to_native.clj:23)"
"query_processor$fn__55005$combined_post_process__55010$combined_post_process_STAR___55011.invoke(query_processor.clj:212)"
"query_processor$fn__55005$combined_pre_process__55006$combined_pre_process_STAR___55007.invoke(query_processor.clj:209)"
"query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__53450$fn__53455.invoke(resolve_database_and_driver.clj:35)"
"driver$do_with_driver.invokeStatic(driver.clj:76)"
"driver$do_with_driver.invoke(driver.clj:72)"
"query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__53450.invoke(resolve_database_and_driver.clj:34)"
"query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__49450.invoke(fetch_source_query.clj:314)"
"query_processor.middleware.store$initialize_store$fn__49640$fn__49641.invoke(store.clj:11)"
"query_processor.store$do_with_store.invokeStatic(store.clj:45)"
"query_processor.store$do_with_store.invoke(store.clj:39)"
"query_processor.middleware.store$initialize_store$fn__49640.invoke(store.clj:10)"
"query_processor.middleware.normalize_query$normalize$fn__53722.invoke(normalize_query.clj:22)"
"query_processor.middleware.constraints$add_default_userland_constraints$fn__50728.invoke(constraints.clj:53)"
"query_processor.middleware.process_userland_query$process_userland_query$fn__53661.invoke(process_userland_query.clj:145)"
"query_processor.middleware.catch_exceptions$catch_exceptions$fn__54033.invoke(catch_exceptions.clj:167)"
"query_processor.reducible$async_qp$qp_STAR___45482$thunk__45484.invoke(reducible.clj:100)"
"query_processor.reducible$async_qp$qp_STAR___45482.invoke(reducible.clj:106)"
"query_processor.reducible$async_qp$qp_STAR___45482.invoke(reducible.clj:91)"
"query_processor.reducible$async_qp$qp_STAR___45482.invoke(reducible.clj:88)"
"query_processor.reducible$sync_qp$qp_STAR___45493.doInvoke(reducible.clj:126)"
"query_processor$process_userland_query.invokeStatic(query_processor.clj:331)"
"query_processor$process_userland_query.doInvoke(query_processor.clj:327)"
"query_processor$fn__55052$process_query_and_save_execution_BANG___55061$fn__55062.invoke(query_processor.clj:339)"
"query_processor$fn__55052$process_query_and_save_execution_BANG___55061.invoke(query_processor.clj:335)"
"query_processor$fn__55096$process_query_and_save_with_max_results_constraints_BANG___55105$fn__55106.invoke(query_processor.clj:351)"
"query_processor$fn__55096$process_query_and_save_with_max_results_constraints_BANG___55105.invoke(query_processor.clj:347)"
"pulse.util$execute_card$process_query__57790.invoke(util.clj:25)"
"pulse.util$execute_card$fn__57792.invoke(util.clj:34)"
"server.middleware.session$do_with_current_user.invokeStatic(session.clj:310)"
"server.middleware.session$do_with_current_user.invoke(session.clj:299)"
"pulse.util$execute_card.invokeStatic(util.clj:33)"
"pulse.util$execute_card.doInvoke(util.clj:14)"
"pulse$pulse__GT_notifications$iter__80703__80707$fn__80708.invoke(pulse.clj:373)"
"pulse$fn__80655.invokeStatic(pulse.clj:304)"
"pulse$fn__80655.invoke(pulse.clj:298)"
"pulse$results__GT_notifications$iter__80685__80689$fn__80690.invoke(pulse.clj:361)"
"pulse$send_notifications_BANG_.invokeStatic(pulse.clj:481)"
"pulse$send_notifications_BANG_.invoke(pulse.clj:480)"
"pulse$send_pulse_BANG_.invokeStatic(pulse.clj:508)"
"pulse$send_pulse_BANG_.doInvoke(pulse.clj:489)"
"task.send_pulses$fn__85764$send_pulses_BANG___85773$fn__85776$fn__85794$fn__85795.invoke(send_pulses.clj:56)"
"models.task_history$fn__42678$do_with_task_history__42683$fn__42684.invoke(task_history.clj:110)"
"models.task_history$fn__42678$do_with_task_history__42683.invoke(task_history.clj:105)"
"task.send_pulses$fn__85764$send_pulses_BANG___85773$fn__85776$fn__85794.invoke(send_pulses.clj:52)"
"task.send_pulses$fn__85764$send_pulses_BANG___85773$fn__85776.invoke(send_pulses.clj:51)"
"task.send_pulses$fn__85764$send_pulses_BANG___85773.invoke(send_pulses.clj:38)"
"task.send_pulses$fn__85764$send_pulses_BANG___85773$fn__85774.invoke(send_pulses.clj:45)"
"task.send_pulses$fn__85764$send_pulses_BANG___85773.invoke(send_pulses.clj:38)"
"task.send_pulses.SendPulses$fn__85830.invoke(send_pulses.clj:96)"
"models.task_history$fn__42678$do_with_task_history__42683$fn__42684.invoke(task_history.clj:110)"
"models.task_history$fn__42678$do_with_task_history__42683.invoke(task_history.clj:105)"
"task.send_pulses.SendPulses.execute(send_pulses.clj:82)"],
:state nil}],
:state "99999",
:json_query
{:native
{:query
"The query that is executed. I hid the code here."},
:type :native,
:database 99,
:async? false,
:middleware {:process-viz-settings? true, :js-int-to-string? false, :add-default-userland-constraints? true}},
:status :failed,
:class java.sql.SQLException,
:stacktrace
["oracle.jdbc.driver.T4CTTIoauthenticate.setSessionFields(T4CTTIoauthenticate.java:1493)"
"oracle.jdbc.driver.T4CTTIoauthenticate.<init>(T4CTTIoauthenticate.java:291)"
"oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:599)"
"oracle.jdbc.driver.PhysicalConnection.connect(PhysicalConnection.java:688)"
"oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:39)"
"oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:691)"
"--> plugins.jdbc_proxy$proxy_driver$reify__62973.connect(jdbc_proxy.clj:33)"
"connection_pool$proxy_data_source$reify__12279.getConnection(connection_pool.clj:29)"],
:card_id 802,
:context :pulse,
:error "Locale not recognized",
:row_count 0,
:running_time 0,
:data {:rows [], :cols []}}
{
"browser-info": {
"language": "pt-BR",
"platform": "Win32",
"userAgent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Safari/537.36",
"vendor": "Google Inc."
},
"system-info": {
"file.encoding": "UTF-8",
"java.runtime.name": "OpenJDK Runtime Environment",
"java.runtime.version": "11.0.17+8",
"java.vendor": "Eclipse Adoptium",
"java.vendor.url": "https://adoptium.net/",
"java.version": "11.0.17",
"java.vm.name": "OpenJDK 64-Bit Server VM",
"java.vm.version": "11.0.17+8",
"os.name": "Linux",
"os.version": "5.4.17-2102.204.4.4.el8uek.x86_64",
"user.language": "en",
"user.timezone": "America/Sao_Paulo"
},
"metabase-info": {
"databases": [
"mysql",
"sqlserver",
"oracle"
],
"hosting-env": "unknown",
"application-database": "mysql",
"application-database-details": {
"database": {
"name": "MySQL",
"version": "8.0.19"
},
"jdbc-driver": {
"name": "MariaDB Connector/J",
"version": "2.7.6"
}
},
"run-mode": "prod",
"version": {
"date": "2022-12-07",
"tag": "v0.45.1",
"branch": "release-x.45.x",
"hash": "019d31c"
},
"settings": {
"report-timezone": "America/Sao_Paulo"
}
}
}
Thanks in advance!