Redshift - not showing changes to schemas

alexremn · April 3, 2024, 10:53am

Good day!

Some weeks ago we made a huge deletion of columns in one of our schema tables in Redshift.
After this deletion, we started to oversee troubles with updates of Redshift schema / data.

We tried all found troubleshooting steps:

Rescan schema / values
Discard saved values & rescan
Updates
etc

All data is queryable from Metabase, but not showing up in Browse Data.
Service user in redshift has all required privileges to access schemas / data.

We are using latest available today version: 0.49.3

Here is diagnostic info:

{
  "browser-info": {
    "language": "en-GB",
    "platform": "MacIntel",
    "userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.5 Safari/605.1.15",
    "vendor": "Apple Computer, Inc."
  },
  "system-info": {
    "file.encoding": "UTF-8",
    "java.runtime.name": "OpenJDK Runtime Environment",
    "java.runtime.version": "11.0.22+7",
    "java.vendor": "Eclipse Adoptium",
    "java.vendor.url": "https://adoptium.net/",
    "java.version": "11.0.22",
    "java.vm.name": "OpenJDK 64-Bit Server VM",
    "java.vm.version": "11.0.22+7",
    "os.name": "Linux",
    "os.version": "5.10.210-201.855.amzn2.x86_64",
    "user.language": "en",
    "user.timezone": "GMT"
  },
  "metabase-info": {
    "databases": [
      "postgres",
      "redshift"
    ],
    "hosting-env": "unknown",
    "application-database": "postgres",
    "application-database-details": {
      "database": {
        "name": "PostgreSQL",
        "version": "11.17"
      },
      "jdbc-driver": {
        "name": "PostgreSQL JDBC Driver",
        "version": "42.7.2"
      }
    },
    "run-mode": "prod",
    "version": {
      "date": "2024-04-02",
      "tag": "v0.49.3",
      "hash": "dba0992"
    },
    "settings": {
      "report-timezone": "UTC"
    }
  }
}

Also we tried to add Redshift extra database connection, but in logs it shows an error with initial sync:

WARN sync.util :: Error in sync step Sync metadata for redshift Database 113 ''Redshift''
com.amazon.redshift.util.RedshiftException: This connection has been closed.
	at com.amazon.redshift.jdbc.RedshiftConnectionImpl.checkClosed(RedshiftConnectionImpl.java:1123)
	at com.amazon.redshift.jdbc.RedshiftConnectionImpl.getAutoCommit(RedshiftConnectionImpl.java:1071)
	at com.mchange.v2.c3p0.impl.NewProxyConnection.getAutoCommit(NewProxyConnection.java:1227)
	at metabase.driver.sql_jdbc.sync.describe_database$fn__81223.invokeStatic(describe_database.clj:91)
	at metabase.driver.sql_jdbc.sync.describe_database$fn__81223.invoke(describe_database.clj:75)
	at clojure.lang.MultiFn.invoke(MultiFn.java:244)
	at metabase.driver.sql_jdbc.sync.describe_database$have_select_privilege_fn$fn__81243.invoke(describe_database.clj:143)
	at clojure.core$filter$fn__5962.invoke(core.clj:2834)
	at clojure.lang.LazySeq.sval(LazySeq.java:42)
	at clojure.lang.LazySeq.seq(LazySeq.java:51)
	at clojure.lang.RT.seq(RT.java:535)
	at clojure.core$seq__5467.invokeStatic(core.clj:139)
	at clojure.core$map$fn__5935.invoke(core.clj:2763)
	at clojure.lang.LazySeq.sval(LazySeq.java:42)
	at clojure.lang.LazySeq.seq(LazySeq.java:51)
	at clojure.lang.ChunkedCons.chunkedNext(ChunkedCons.java:59)
	at clojure.core$chunk_next.invokeStatic(core.clj:710)
	at clojure.core.protocols$fn__8244.invokeStatic(protocols.clj:137)
	at clojure.core.protocols$fn__8244.invoke(protocols.clj:124)
	at clojure.core.protocols$fn__8204$G__8199__8213.invoke(protocols.clj:19)
	at clojure.core.protocols$seq_reduce.invokeStatic(protocols.clj:31)
	at clojure.core.protocols$fn__8236.invokeStatic(protocols.clj:75)
	at clojure.core.protocols$fn__8236.invoke(protocols.clj:75)
	at clojure.core.protocols$fn__8178$G__8173__8191.invoke(protocols.clj:13)
	at clojure.core$reduce.invokeStatic(core.clj:6887)
	at clojure.core$cat$fn__8851.invoke(core.clj:7694)
	at clojure.core$map$fn__5931$fn__5932.invoke(core.clj:2759)
	at clojure.core$completing$fn__8528.invoke(core.clj:6932)
	at clojure.core$filter$fn__5958$fn__5959.invoke(core.clj:2823)
	at clojure.core$completing$fn__8528.invoke(core.clj:6932)
	at clojure.core$filter$fn__5958$fn__5959.invoke(core.clj:2823)
	at clojure.core$filter$fn__5958$fn__5959.invoke(core.clj:2823)
	at clojure.core$filter$fn__5958$fn__5959.invoke(core.clj:2823)
	at clojure.core$take_while$fn__5982$fn__5983.invoke(core.clj:2918)
	at clojure.core.protocols$fn__8249.invokeStatic(protocols.clj:168)
	at clojure.core.protocols$fn__8249.invoke(protocols.clj:124)
	at clojure.core.protocols$fn__8204$G__8199__8213.invoke(protocols.clj:19)
	at clojure.core.protocols$seq_reduce.invokeStatic(protocols.clj:31)
	at clojure.core.protocols$fn__8236.invokeStatic(protocols.clj:75)
	at clojure.core.protocols$fn__8236.invoke(protocols.clj:75)
	at clojure.core.protocols$fn__8178$G__8173__8191.invoke(protocols.clj:13)
	at clojure.core$reduce.invokeStatic(core.clj:6887)
	at clojure.core$reduce.invoke(core.clj:6869)
	at metabase.driver.sql_jdbc.sync.common$reducible_results$reify__80771.reduce(common.clj:39)
	at clojure.core$transduce.invokeStatic(core.clj:6947)
	at clojure.core.Eduction.reduce(core.clj:7751)
	at clojure.core$transduce.invokeStatic(core.clj:6947)
	at clojure.core.Eduction.reduce(core.clj:7751)
	at clojure.core$reduce.invokeStatic(core.clj:6886)
	at clojure.core$reduce.invoke(core.clj:6869)
	at metabase.driver.redshift$reducible_schemas_with_usage_permissions$reify__120486.reduce(redshift.clj:379)
	at clojure.core$transduce.invokeStatic(core.clj:6947)
	at clojure.core.Eduction.reduce(core.clj:7751)
	at clojure.core$reduce.invokeStatic(core.clj:6886)
	at clojure.core$into.invokeStatic(core.clj:6959)
	at clojure.core$into.invoke(core.clj:6951)
	at metabase.driver.sql_jdbc.sync.describe_database$describe_database$fn__81280.invoke(describe_database.clj:218)
	at metabase.driver.redshift$fn__120391$fn__120393.invoke(redshift.clj:180)
	at metabase.driver.sql_jdbc.execute$do_with_resolved_connection.invokeStatic(execute.clj:334)
	at metabase.driver.sql_jdbc.execute$do_with_resolved_connection.invoke(execute.clj:317)
	at metabase.driver.redshift$fn__120391.invokeStatic(redshift.clj:165)
	at metabase.driver.redshift$fn__120391.invoke(redshift.clj:163)
	at clojure.lang.MultiFn.invoke(MultiFn.java:244)
	at metabase.driver.sql_jdbc.sync.describe_database$describe_database.invokeStatic(describe_database.clj:201)
	at metabase.driver.sql_jdbc.sync.describe_database$describe_database.invoke(describe_database.clj:196)
	at metabase.driver.sql_jdbc$fn__106644.invokeStatic(sql_jdbc.clj:90)
	at metabase.driver.sql_jdbc$fn__106644.invoke(sql_jdbc.clj:88)
	at clojure.lang.MultiFn.invoke(MultiFn.java:234)
	at metabase.sync.fetch_metadata$db_metadata.invokeStatic(fetch_metadata.clj:16)
	at metabase.sync.fetch_metadata$db_metadata.invoke(fetch_metadata.clj:13)
	at metabase.sync.sync_metadata$sync_db_metadata_BANG_$fn__82369.invoke(sync_metadata.clj:69)
	at metabase.sync.util$do_with_error_handling.invokeStatic(util.clj:190)
	at metabase.sync.util$do_with_error_handling.invoke(util.clj:183)
	at clojure.core$partial$fn__5910.invoke(core.clj:2647)
	at metabase.driver$fn__49798.invokeStatic(driver.clj:778)
	at metabase.driver$fn__49798.invoke(driver.clj:778)
	at clojure.lang.MultiFn.invoke(MultiFn.java:239)
	at metabase.sync.util$sync_in_context$fn__60218.invoke(util.clj:166)
	at metabase.sync.util$with_db_logging_disabled$fn__60215.invoke(util.clj:158)
	at metabase.sync.util$with_start_and_finish_logging_STAR_.invokeStatic(util.clj:131)
	at metabase.sync.util$with_start_and_finish_logging_STAR_.invoke(util.clj:125)
	at metabase.sync.util$with_start_and_finish_logging$fn__60202.invoke(util.clj:143)
	at metabase.sync.util$with_sync_events$fn__60197.invoke(util.clj:117)
	at metabase.sync.util$with_duplicate_ops_prevented$fn__60184.invoke(util.clj:89)
	at metabase.sync.util$do_sync_operation.invokeStatic(util.clj:215)
	at metabase.sync.util$do_sync_operation.invoke(util.clj:209)
	at metabase.sync.sync_metadata$sync_db_metadata_BANG_.invokeStatic(sync_metadata.clj:68)
	at metabase.sync.sync_metadata$sync_db_metadata_BANG_.invoke(sync_metadata.clj:65)
	at metabase.sync$sync_database_BANG_$fn__82379.invoke(sync.clj:52)
	at metabase.sync.util$do_with_error_handling.invokeStatic(util.clj:190)
	at metabase.sync.util$do_with_error_handling.invoke(util.clj:183)
	at clojure.core$partial$fn__5910.invoke(core.clj:2647)
	at metabase.driver$fn__49798.invokeStatic(driver.clj:778)
	at metabase.driver$fn__49798.invoke(driver.clj:778)
	at clojure.lang.MultiFn.invoke(MultiFn.java:239)
	at metabase.sync.util$sync_in_context$fn__60218.invoke(util.clj:166)
	at metabase.sync.util$with_db_logging_disabled$fn__60215.invoke(util.clj:158)
	at metabase.sync.util$with_start_and_finish_logging_STAR_.invokeStatic(util.clj:131)
	at metabase.sync.util$with_start_and_finish_logging_STAR_.invoke(util.clj:125)
	at metabase.sync.util$with_start_and_finish_logging$fn__60202.invoke(util.clj:143)
	at metabase.sync.util$with_sync_events$fn__60197.invoke(util.clj:117)
	at metabase.sync.util$with_duplicate_ops_prevented$fn__60184.invoke(util.clj:89)
	at metabase.sync.util$do_sync_operation.invokeStatic(util.clj:215)
	at metabase.sync.util$do_sync_operation.invoke(util.clj:209)
	at metabase.sync$sync_database_BANG_.invokeStatic(sync.clj:51)
	at metabase.sync$sync_database_BANG_.invoke(sync.clj:37)
	at metabase.sync$sync_database_BANG_.invokeStatic(sync.clj:46)
	at metabase.sync$sync_database_BANG_.invoke(sync.clj:37)
	at metabase.events.sync_database$publish_event_BANG__primary_method_metabase_events_sync_database_event$fn__104093.invoke(sync_database.clj:24)
	at clojure.core$binding_conveyor_fn$fn__5823.invoke(core.clj:2047)
	at clojure.lang.AFn.call(AFn.java:18)
	at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.base/java.lang.Thread.run(Unknown Source)
2024-04-03 10:43:57,087 INFO sync.util :: e[35mFINISHED: Sync metadata for redshift Database 113 ''Redshift'' (21.3 mins)e[0m
2024-04-03 10:43:57,087 WARN sync.util :: Error in sync step Sync redshift Database 113 ''Redshift''
java.lang.ClassCastException: class com.amazon.redshift.util.RedshiftException cannot be cast to class clojure.lang.Associative (com.amazon.redshift.util.RedshiftException is in unnamed module of loader clojure.lang.DynamicClassLoader @617d697; clojure.lang.Associative is in unnamed module of loader 'app')
	at clojure.lang.RT.assoc(RT.java:827)
	at clojure.core$assoc__5481.invokeStatic(core.clj:193)
	at clojure.core$assoc__5481.invoke(core.clj:192)
	at metabase.sync$sync_database_BANG_$fn__82379.invoke(sync.clj:52)
	at metabase.sync.util$do_with_error_handling.invokeStatic(util.clj:190)
	at metabase.sync.util$do_with_error_handling.invoke(util.clj:183)
	at clojure.core$partial$fn__5910.invoke(core.clj:2647)
	at metabase.driver$fn__49798.invokeStatic(driver.clj:778)
	at metabase.driver$fn__49798.invoke(driver.clj:778)
	at clojure.lang.MultiFn.invoke(MultiFn.java:239)
	at metabase.sync.util$sync_in_context$fn__60218.invoke(util.clj:166)
	at metabase.sync.util$with_db_logging_disabled$fn__60215.invoke(util.clj:158)
	at metabase.sync.util$with_start_and_finish_logging_STAR_.invokeStatic(util.clj:131)
	at metabase.sync.util$with_start_and_finish_logging_STAR_.invoke(util.clj:125)
	at metabase.sync.util$with_start_and_finish_logging$fn__60202.invoke(util.clj:143)
	at metabase.sync.util$with_sync_events$fn__60197.invoke(util.clj:117)
	at metabase.sync.util$with_duplicate_ops_prevented$fn__60184.invoke(util.clj:89)
	at metabase.sync.util$do_sync_operation.invokeStatic(util.clj:215)
	at metabase.sync.util$do_sync_operation.invoke(util.clj:209)
	at metabase.sync$sync_database_BANG_.invokeStatic(sync.clj:51)
	at metabase.sync$sync_database_BANG_.invoke(sync.clj:37)
	at metabase.sync$sync_database_BANG_.invokeStatic(sync.clj:46)
	at metabase.sync$sync_database_BANG_.invoke(sync.clj:37)
	at metabase.events.sync_database$publish_event_BANG__primary_method_metabase_events_sync_database_event$fn__104093.invoke(sync_database.clj:24)
	at clojure.core$binding_conveyor_fn$fn__5823.invoke(core.clj:2047)
	at clojure.lang.AFn.call(AFn.java:18)
	at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.base/java.lang.Thread.run(Unknown Source)

We are using automated WLM on redshift side with log action on statement timeout.

alexremn · April 3, 2024, 10:00pm

New connection to the same redshift worked and all schemas are showing there.
If there is no ideas how to fix caches, can we somehow update in database db_id / tables references to utilise new connection?

TonyC · April 9, 2024, 4:16pm

Can you hit sync schema now and share the whole logs maybe we can find something there.

Also just to confirm, you are saying that the 2 database connections are identical but the old one doesn't sync and the new connection sync fine right?

alexremn · April 12, 2024, 9:00am

@TonyC right.

I've made some success with syncing - both connections (identical completely) were the same.
2 days ago main connection again lost 3 schemas, whereas test connection (the same everything) - has those schemas.

Do I need to enter debug or just to share logs from pod?

TonyC · April 12, 2024, 9:13am

Logs would be enough but it needs to be around the time the sync was running ... if those 3 schemas vanished then you should get "inactive" kind of log in the logs ... are those tables or views the 3 schemas that got lost?

alexremn · April 24, 2024, 1:10pm

@TonyC
Good day!
Sorry for late responses.

So, there are currently two issues:

This one was discovered before 0.49.5 - live tables (which are still in the schema) were marked as inactive in metabase database, though not showing;
This one is discovered even with 0.49.7 - there are 9 tables in redshift schema, but only 4 are visible (4 were discovered initially, 5 tables were added later). When I tried to use Sync database schema now & Re-scan field values now against this redshift connection, I found an error in the log:

Error in sync step Sync metadata for redshift Database 114 ''Redshift (TEST)''
com.amazon.redshift.util.RedshiftException: This connection has been closed.

It happened around 20 minutes after STARTING: Sync metadata for redshift Database 114 ''Redshift (TEST)''. On redshift side, we have WLM configuration, which aborts queries after 120 minutes.

TonyC · April 24, 2024, 1:21pm

How large is that database? I am not expecting the sync for a specific fingerprint column to take so long.

Since you mentioned the schemas are not there then you should be running Sync Schema first since thats more lightweight and the queries are simply a Select 1 form table to get the column names and some DESCRIBE type

alexremn · April 24, 2024, 5:12pm

@TonyC

How large is that database? I am not expecting the sync for a specific fingerprint column to take so long.

It's 25 schemas inside, around 400 GB itself & including some external schemas which are around 4tb.

Since you mentioned the schemas are not there then you should be running Sync Schema first since thats more lightweight and the queries are simply a Select 1 form table to get the column names and some DESCRIBE type

Initial issue was that Metabase refused to determine new schema, current one is that Metabase refuses to determine schema changes. From the perspective of logs view - it throws identical errors.
I just ran Sync database schema now couple of minutes ago, and received same error like before in 20 minutes.

Error in sync step Sync metadata for redshift Database 114 ''Redshift (TEST)''
com.amazon.redshift.util.RedshiftException: This connection has been closed.
	at com.amazon.redshift.jdbc.RedshiftConnectionImpl.checkClosed(RedshiftConnectionImpl.java:1123)
	at com.amazon.redshift.jdbc.RedshiftConnectionImpl.getAutoCommit(RedshiftConnectionImpl.java:1071)
	at com.mchange.v2.c3p0.impl.NewProxyConnection.getAutoCommit(NewProxyConnection.java:1227)
	at metabase.driver.sql_jdbc.sync.describe_database$fn__81367.invokeStatic(describe_database.clj:91)
	at metabase.driver.sql_jdbc.sync.describe_database$fn__81367.invoke(describe_database.clj:75)
	at clojure.lang.MultiFn.invoke(MultiFn.java:244)
	at metabase.driver.sql_jdbc.sync.describe_database$have_select_privilege_fn$fn__81387.invoke(describe_database.clj:143)
	at clojure.core$filter$fn__5962.invoke(core.clj:2834)
	at clojure.lang.LazySeq.sval(LazySeq.java:42)
	at clojure.lang.LazySeq.seq(LazySeq.java:51)
	at clojure.lang.RT.seq(RT.java:535)
	at clojure.core$seq__5467.invokeStatic(core.clj:139)
	at clojure.core$map$fn__5935.invoke(core.clj:2763)
	at clojure.lang.LazySeq.sval(LazySeq.java:42)
	at clojure.lang.LazySeq.seq(LazySeq.java:51)
	at clojure.lang.ChunkedCons.chunkedNext(ChunkedCons.java:59)
	at clojure.core$chunk_next.invokeStatic(core.clj:710)
	at clojure.core.protocols$fn__8244.invokeStatic(protocols.clj:137)
	at clojure.core.protocols$fn__8244.invoke(protocols.clj:124)
	at clojure.core.protocols$fn__8204$G__8199__8213.invoke(protocols.clj:19)
	at clojure.core.protocols$seq_reduce.invokeStatic(protocols.clj:31)
	at clojure.core.protocols$fn__8236.invokeStatic(protocols.clj:75)
	at clojure.core.protocols$fn__8236.invoke(protocols.clj:75)
	at clojure.core.protocols$fn__8178$G__8173__8191.invoke(protocols.clj:13)
	at clojure.core$reduce.invokeStatic(core.clj:6887)
	at clojure.core$cat$fn__8851.invoke(core.clj:7694)
	at clojure.core$map$fn__5931$fn__5932.invoke(core.clj:2759)
	at clojure.core$completing$fn__8528.invoke(core.clj:6932)
	at clojure.core$filter$fn__5958$fn__5959.invoke(core.clj:2823)
	at clojure.core$completing$fn__8528.invoke(core.clj:6932)
	at clojure.core$filter$fn__5958$fn__5959.invoke(core.clj:2823)
	at clojure.core$filter$fn__5958$fn__5959.invoke(core.clj:2823)
	at clojure.core$filter$fn__5958$fn__5959.invoke(core.clj:2823)
	at clojure.core$take_while$fn__5982$fn__5983.invoke(core.clj:2918)
	at clojure.core.protocols$fn__8249.invokeStatic(protocols.clj:168)
	at clojure.core.protocols$fn__8249.invoke(protocols.clj:124)
	at clojure.core.protocols$fn__8204$G__8199__8213.invoke(protocols.clj:19)
	at clojure.core.protocols$seq_reduce.invokeStatic(protocols.clj:31)
	at clojure.core.protocols$fn__8236.invokeStatic(protocols.clj:75)
	at clojure.core.protocols$fn__8236.invoke(protocols.clj:75)
	at clojure.core.protocols$fn__8178$G__8173__8191.invoke(protocols.clj:13)
	at clojure.core$reduce.invokeStatic(core.clj:6887)
	at clojure.core$reduce.invoke(core.clj:6869)
	at metabase.driver.sql_jdbc.sync.common$reducible_results$reify__80915.reduce(common.clj:39)
	at clojure.core$transduce.invokeStatic(core.clj:6947)
	at clojure.core.Eduction.reduce(core.clj:7751)
	at clojure.core$transduce.invokeStatic(core.clj:6947)
	at clojure.core.Eduction.reduce(core.clj:7751)
	at clojure.core$reduce.invokeStatic(core.clj:6886)
	at clojure.core$reduce.invoke(core.clj:6869)
	at metabase.driver.redshift$reducible_schemas_with_usage_permissions$reify__112408.reduce(redshift.clj:379)
	at clojure.core$transduce.invokeStatic(core.clj:6947)
	at clojure.core.Eduction.reduce(core.clj:7751)
	at clojure.core$reduce.invokeStatic(core.clj:6886)
	at clojure.core$into.invokeStatic(core.clj:6959)
	at clojure.core$into.invoke(core.clj:6951)
	at metabase.driver.sql_jdbc.sync.describe_database$describe_database$fn__81424.invoke(describe_database.clj:218)
	at metabase.driver.redshift$fn__112313$fn__112315.invoke(redshift.clj:180)
	at metabase.driver.sql_jdbc.execute$do_with_resolved_connection.invokeStatic(execute.clj:335)
	at metabase.driver.sql_jdbc.execute$do_with_resolved_connection.invoke(execute.clj:318)
	at metabase.driver.redshift$fn__112313.invokeStatic(redshift.clj:165)
	at metabase.driver.redshift$fn__112313.invoke(redshift.clj:163)
	at clojure.lang.MultiFn.invoke(MultiFn.java:244)
	at metabase.driver.sql_jdbc.sync.describe_database$describe_database.invokeStatic(describe_database.clj:201)
	at metabase.driver.sql_jdbc.sync.describe_database$describe_database.invoke(describe_database.clj:196)
	at metabase.driver.sql_jdbc$fn__106755.invokeStatic(sql_jdbc.clj:90)
	at metabase.driver.sql_jdbc$fn__106755.invoke(sql_jdbc.clj:88)
	at clojure.lang.MultiFn.invoke(MultiFn.java:234)
	at metabase.sync.fetch_metadata$db_metadata.invokeStatic(fetch_metadata.clj:16)
	at metabase.sync.fetch_metadata$db_metadata.invoke(fetch_metadata.clj:13)
	at metabase.sync.sync_metadata$sync_db_metadata_BANG_$fn__82515.invoke(sync_metadata.clj:69)
	at metabase.sync.util$do_with_error_handling.invokeStatic(util.clj:190)
	at metabase.sync.util$do_with_error_handling.invoke(util.clj:183)
	at clojure.core$partial$fn__5910.invoke(core.clj:2647)
	at metabase.driver$fn__49865.invokeStatic(driver.clj:778)
	at metabase.driver$fn__49865.invoke(driver.clj:778)
	at clojure.lang.MultiFn.invoke(MultiFn.java:239)
	at metabase.sync.util$sync_in_context$fn__60292.invoke(util.clj:166)
	at metabase.sync.util$with_db_logging_disabled$fn__60289.invoke(util.clj:158)
	at metabase.sync.util$with_start_and_finish_logging_STAR_.invokeStatic(util.clj:131)
	at metabase.sync.util$with_start_and_finish_logging_STAR_.invoke(util.clj:125)
	at metabase.sync.util$with_start_and_finish_logging$fn__60276.invoke(util.clj:143)
	at metabase.sync.util$with_sync_events$fn__60271.invoke(util.clj:117)
	at metabase.sync.util$with_duplicate_ops_prevented$fn__60258.invoke(util.clj:89)
	at metabase.sync.util$do_sync_operation.invokeStatic(util.clj:215)
	at metabase.sync.util$do_sync_operation.invoke(util.clj:209)
	at metabase.sync.sync_metadata$sync_db_metadata_BANG_.invokeStatic(sync_metadata.clj:68)
	at metabase.sync.sync_metadata$sync_db_metadata_BANG_.invoke(sync_metadata.clj:65)
	at metabase.task.sync_databases$sync_and_analyze_database_STAR__BANG_.invokeStatic(sync_databases.clj:93)
	at metabase.task.sync_databases$sync_and_analyze_database_STAR__BANG_.invoke(sync_databases.clj:76)
	at metabase.task.sync_databases$sync_and_analyze_database_BANG_.invokeStatic(sync_databases.clj:112)
	at metabase.task.sync_databases$sync_and_analyze_database_BANG_.invoke(sync_databases.clj:100)
	at metabase.task.sync_databases.SyncAndAnalyzeDatabase.execute(sync_databases.clj:117)
	at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)

Luiggi · April 24, 2024, 5:17pm

How many schemas are in your entire redshift cluster? I would like to send you a query so you can run manually to the information schema. I believe that the problem here is that Metabase is killing the connection using the global query timeout as the query to get the schemas is too big

alexremn · April 24, 2024, 6:53pm

@Luiggi I also hoped so, as we have one big external schema pointing to AWS Aurora, and this aurora has 20min idle_session_timeout & idle_in_transaction_session_timeout. Though, I modified timeout for the user, which is querying data from it to redshift, and still has this error.

We have 25 schemas available for metabase. I assume, somewhere there is a glitchy timeout set at 20 minutes.

alexremn · April 24, 2024, 9:52pm

@TonyC @Luiggi
Just found this in the code of query-processor - could it be related? Cause seems like this one has exact 20 minutes timeout and being referenced by conn pool.

alexremn · April 24, 2024, 10:56pm

Ok, I fixed it.
It was really due to query-timeout hardcoded value. I found that even if query-timeout-ms was hard set to 20 min, actual query wait was controlled by jdbc-data-warehouse-unreturned-connection-timeout-seconds, which is configurable via MB_JDBC_DATA_WAREHOUSE_UNRETURNED_CONNECTION_TIMEOUT_SECONDS env variable. Setting this to 3600 (1 hr) did the trick.
Due to amount of data in one big external schema, overall sync took 37 mins.

Thank you anyway for help. Is it possible to update troubleshooting guide / envs spec to reflect this case?

Luiggi · April 25, 2024, 2:47pm

ok so there's clearly a single query that was taking more than 20 minutes on your end, can you identify what query was?

alexremn · April 26, 2024, 10:27am

@Luiggi yes, sure - this one is related to STARTING: Sync metadata for redshift job, which tries to sync metadata for redshift database with some TB of data.