search

dacort / metabase-athena-driver

An Amazon Athena driver for Metabase 0.32 and later
Apache License 2.0
225 stars 32 forks source link

sync step failed after upgrading to metabase athena driver(v1.1.0) #55

Closed rudhra13 closed 4 years ago

rudhra13 commented 4 years ago

Hi,

After upgrading to new version(v1.1.0) we are not able to sync the athena to metabase.

Error log.

08-03 15:09:16 INFO sync.util :: STARTING: Sync metadata for athena Database 2 'Athena' 08-03 15:09:16 DEBUG middleware.log :: POST /api/database/2/sync_schema 200 1.5 ms (1 DB calls) App DB connections: 0/15 Jetty threads: 3/50 (6 idle, 0 queued) (112 total active threads) Queries in flight: 0 (0 queued) 08-03 15:09:16 INFO sync.util :: STARTING: step 'sync-timezone' for athena Database 2 'Athena' 08-03 15:09:16 INFO sync.util :: FINISHED: step 'sync-timezone' for athena Database 2 'Athena' (94.0 µs) 08-03 15:09:16 INFO sync.util :: STARTING: step 'sync-tables' for athena Database 2 'Athena' 08-03 15:09:24 ERROR sync.util :: Error running sync step java.sql.SQLException: [Simba]AthenaJDBC An error has been thrown from the AWS Athena client. Failed to invoke lambda function due to Unsupported Arrow Type [Timestamp(MILLISECOND, null)] in Lambda Data Source [Execution ID not available] at com.simba.athena.athena.api.AJClient.checkAndThrowException(Unknown Source) at com.simba.athena.athena.api.AJClient.fetchTablesWithProxyApi(Unknown Source) at com.simba.athena.athena.api.AJClient.getTablesMetadata(Unknown Source) at com.simba.athena.athena.dataengine.metadata.AJTablesMetadataSource.initMetadata(Unknown Source) at com.simba.athena.athena.dataengine.metadata.AJTablesMetadataSource.(Unknown Source) at com.simba.athena.athena.dataengine.AJDataEngine.makeNewMetadataSource(Unknown Source) at com.simba.athena.dsi.dataengine.impl.DSIDataEngine.makeNewMetadataResult(Unknown Source) at com.simba.athena.athena.dataengine.AJDataEngine.makeNewMetadataResult(Unknown Source) at com.simba.athena.jdbc.jdbc42.S42DatabaseMetaData.createMetaDataResult(Unknown Source) at com.simba.athena.jdbc.common.SDatabaseMetaData.getTables(Unknown Source) at com.mchange.v2.c3p0.impl.NewProxyDatabaseMetaData.getTables(NewProxyDatabaseMetaData.java:3010) at metabase.driver.athena$get_tables.invokeStatic(athena.clj:242) at metabase.driver.athena$get_tables.invoke(athena.clj:240) at metabase.driver.athena$fast_active_tables$iter553559$fn560.invoke(athena.clj:253) at clojure.lang.LazySeq.sval(LazySeq.java:42) at clojure.lang.LazySeq.seq(LazySeq.java:58) at clojure.lang.ChunkedCons.chunkedNext(ChunkedCons.java:59) at clojure.core$chunk_next.invokeStatic(core.clj:708) at clojure.core$reduce1.invokeStatic(core.clj:942) at clojure.core$set.invokeStatic(core.clj:4113) at clojure.core$set.invoke(core.clj:4105) at metabase.driver.athena$fast_active_tables.invokeStatic(athena.clj:252) at metabase.driver.athena$fast_active_tables.doInvoke(athena.clj:247) at clojure.lang.RestFn.invoke(RestFn.java:425) at metabase.driver.athena$fn578$fn579.invoke(athena.clj:267) at metabase.driver.athena$fn578.invokeStatic(athena.clj:266) at metabase.driver.athena$fn578.invoke(athena.clj:265) at clojure.lang.MultiFn.invoke(MultiFn.java:234) at metabase.sync.fetch_metadata$fn52935$db_metadata52940$fn52941.invoke(fetch_metadata.clj:13) at metabase.sync.fetch_metadata$fn52935$db_metadata52940.invoke(fetch_metadata.clj:10) at metabase.sync.sync_metadata.tables$fn54361$db_metadata54366$fn54367.invoke(tables.clj:146) at metabase.sync.sync_metadata.tables$fn__54361$db_metadata54366.invoke(tables.clj:143) at metabase.sync.sync_metadata.tables$fn54422$sync_tables_BANG_54427$fn54428.invoke(tables.clj:163) at metabase.sync.sync_metadata.tables$fn54422$sync_tables_BANG_54427.invoke(tables.clj:158) at metabase.sync.util$fn__42218$run_step_with_metadata42223$fn42227$fn42229.invoke(util.clj:345) at metabase.sync.util$with_start_and_finish_loggingSTAR.invokeStatic(util.clj:102) at metabase.sync.util$with_start_and_finish_loggingSTAR.invoke(util.clj:96) at metabase.sync.util$with_start_and_finish_debug_logging.invokeStatic(util.clj:119) at metabase.sync.util$with_start_and_finish_debug_logging.invoke(util.clj:116) at metabase.sync.util$fn42218$run_step_with_metadata42223$fn42227.invoke(util.clj:342) at metabase.sync.util$fn__42218$run_step_with_metadata42223.invoke(util.clj:337) at metabase.sync.util$fn42410$run_sync_operation42415$fn42416$fn42417.invoke(util.clj:430) at clojure.core$mapv$fn8445.invoke(core.clj:6912) at clojure.lang.PersistentVector.reduce(PersistentVector.java:343) at clojure.core$reduce.invokeStatic(core.clj:6827) at clojure.core$mapv.invokeStatic(core.clj:6903) at clojure.core$mapv.invoke(core.clj:6903) at metabase.sync.util$fn42410$run_sync_operation42415$fn42416.invoke(util.clj:430) at metabase.sync.util$fn42410$run_sync_operation42415.invoke(util.clj:424) at metabase.sync.sync_metadata$fn54475$sync_db_metadataBANG54480$fn54481$fn54482.invoke(sync_metadata.clj:51) at metabase.sync.util$do_with_error_handling.invokeStatic(util.clj:149) at metabase.sync.util$do_with_error_handling.invoke(util.clj:142) at metabase.sync.util$do_with_error_handling.invokeStatic(util.clj:145) at metabase.sync.util$do_with_error_handling.invoke(util.clj:142) at clojure.core$partial$fn5839.invoke(core.clj:2623) at metabase.driver$fn22445.invokeStatic(driver.clj:540) at metabase.driver$fn22445.invoke(driver.clj:540) at clojure.lang.MultiFn.invoke(MultiFn.java:239) at metabase.sync.util$sync_in_context$fn42130.invoke(util.clj:138) at metabase.sync.util$with_db_logging_disabled$fn42127.invoke(util.clj:129) at metabase.sync.util$with_start_and_finish_loggingSTAR.invokeStatic(util.clj:102) at metabase.sync.util$with_start_and_finish_loggingSTAR.invoke(util.clj:96) at metabase.sync.util$with_start_and_finish_logging$fn42116.invoke(util.clj:114) at metabase.sync.util$with_sync_events$fn42111.invoke(util.clj:88) at metabase.sync.util$with_duplicate_ops_prevented$fn__42102.invoke(util.clj:67) at metabase.sync.util$do_sync_operation.invokeStatic(util.clj:164) at metabase.sync.util$do_sync_operation.invoke(util.clj:161) at metabase.sync.sync_metadata$fn54475$sync_db_metadata_BANG_54480$fn54481.invoke(sync_metadata.clj:50) at metabase.sync.sync_metadata$fn54475$sync_db_metadata_BANG___54480.invoke(sync_metadata.clj:47) at metabase.api.database$fn55211$fn55213.invoke(database.clj:614) at clojure.core$binding_conveyor_fn$fn5754.invoke(core.clj:2030) at clojure.lang.AFn.call(AFn.java:18) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) Caused by: com.simba.athena.support.exceptions.GeneralException: [Simba]AthenaJDBC An error has been thrown from the AWS Athena client. Failed to invoke lambda function due to Unsupported Arrow Type [Timestamp(MILLISECOND, null)] in Lambda Data Source [Execution ID not available] ... 75 more Caused by: com.simba.athena.amazonaws.services.athena.model.MetadataException: Failed to invoke lambda function due to Unsupported Arrow Type [Timestamp(MILLISECOND, null)] in Lambda Data Source (Service: AmazonAthena; Status Code: 400; Error Code: MetadataException; Request ID: 60dc434f-36d9-41a9-af7a-8e20aaee05f9; Proxy: null) at com.simba.athena.amazonaws.http.AmazonHttpClient$RequestExecutor.handleErrorResponse(AmazonHttpClient.java:1811) at com.simba.athena.amazonaws.http.AmazonHttpClient$RequestExecutor.handleServiceErrorResponse(AmazonHttpClient.java:1395) at com.simba.athena.amazonaws.http.AmazonHttpClient$RequestExecutor.executeOneRequest(AmazonHttpClient.java:1371) at com.simba.athena.amazonaws.http.AmazonHttpClient$RequestExecutor.executeHelper(AmazonHttpClient.java:1145) at com.simba.athena.amazonaws.http.AmazonHttpClient$RequestExecutor.doExecute(AmazonHttpClient.java:802) at com.simba.athena.amazonaws.http.AmazonHttpClient$RequestExecutor.executeWithTimer(AmazonHttpClient.java:770) at com.simba.athena.amazonaws.http.AmazonHttpClient$RequestExecutor.execute(AmazonHttpClient.java:744) at com.simba.athena.amazonaws.http.AmazonHttpClient$RequestExecutor.access$500(AmazonHttpClient.java:704) at com.simba.athena.amazonaws.http.AmazonHttpClient$RequestExecutionBuilderImpl.execute(AmazonHttpClient.java:686) at com.simba.athena.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:550) at com.simba.athena.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:530) at com.simba.athena.amazonaws.services.athena.AmazonAthenaClient.doInvoke(AmazonAthenaClient.java:1948) at com.simba.athena.amazonaws.services.athena.AmazonAthenaClient.invoke(AmazonAthenaClient.java:1915) at com.simba.athena.amazonaws.services.athena.AmazonAthenaClient.invoke(AmazonAthenaClient.java:1904) at com.simba.athena.amazonaws.services.athena.AmazonAthenaClient.executeListTableMetadata(AmazonAthenaClient.java:1380) at com.simba.athena.amazonaws.services.athena.AmazonAthenaClient.listTableMetadata(AmazonAthenaClient.java:1351) at com.simba.athena.athena.api.AJClient.fetchTablesWithProxyApi(Unknown Source) at com.simba.athena.athena.api.AJClient.getTablesMetadata(Unknown Source) at com.simba.athena.athena.dataengine.metadata.AJTablesMetadataSource.initMetadata(Unknown Source) at com.simba.athena.athena.dataengine.metadata.AJTablesMetadataSource.(Unknown Source) at com.simba.athena.athena.dataengine.AJDataEngine.makeNewMetadataSource(Unknown Source) at com.simba.athena.dsi.dataengine.impl.DSIDataEngine.makeNewMetadataResult(Unknown Source) at com.simba.athena.athena.dataengine.AJDataEngine.makeNewMetadataResult(Unknown Source) at com.simba.athena.jdbc.jdbc42.S42DatabaseMetaData.createMetaDataResult(Unknown Source) at com.simba.athena.jdbc.common.SDatabaseMetaData.getTables(Unknown Source) at com.mchange.v2.c3p0.impl.NewProxyDatabaseMetaData.getTables(NewProxyDatabaseMetaData.java:3010) at metabase.driver.athena$get_tables.invokeStatic(athena.clj:242) at metabase.driver.athena$get_tables.invoke(athena.clj:240) at metabase.driver.athena$fast_active_tables$iter553559$fn560.invoke(athena.clj:253) at clojure.lang.LazySeq.sval(LazySeq.java:42) at clojure.lang.LazySeq.seq(LazySeq.java:58) at clojure.lang.ChunkedCons.chunkedNext(ChunkedCons.java:59) at clojure.core$chunk_next.invokeStatic(core.clj:708) at clojure.core$reduce1.invokeStatic(core.clj:942) at clojure.core$set.invokeStatic(core.clj:4113) at clojure.core$set.invoke(core.clj:4105) at metabase.driver.athena$fast_active_tables.invokeStatic(athena.clj:252) at metabase.driver.athena$fast_active_tables.doInvoke(athena.clj:247) at clojure.lang.RestFn.invoke(RestFn.java:425) at metabase.driver.athena$fn578$fn579.invoke(athena.clj:267) at metabase.driver.athena$fn578.invokeStatic(athena.clj:266) at metabase.driver.athena$fn578.invoke(athena.clj:265) at clojure.lang.MultiFn.invoke(MultiFn.java:234) at metabase.sync.fetch_metadata$fn52935$db_metadata52940$fn52941.invoke(fetch_metadata.clj:13) at metabase.sync.fetch_metadata$fn52935$db_metadata52940.invoke(fetch_metadata.clj:10) at metabase.sync.sync_metadata.tables$fn54361$db_metadata54366$fn54367.invoke(tables.clj:146) at metabase.sync.sync_metadata.tables$fn__54361$db_metadata54366.invoke(tables.clj:143) at metabase.sync.sync_metadata.tables$fn54422$sync_tables_BANG_54427$fn54428.invoke(tables.clj:163) at metabase.sync.sync_metadata.tables$fn54422$sync_tables_BANG_54427.invoke(tables.clj:158) at metabase.sync.util$fn__42218$run_step_with_metadata42223$fn42227$fn42229.invoke(util.clj:345) at metabase.sync.util$with_start_and_finish_loggingSTAR.invokeStatic(util.clj:102) at metabase.sync.util$with_start_and_finish_loggingSTAR.invoke(util.clj:96) at metabase.sync.util$with_start_and_finish_debug_logging.invokeStatic(util.clj:119) at metabase.sync.util$with_start_and_finish_debug_logging.invoke(util.clj:116) at metabase.sync.util$fn42218$run_step_with_metadata42223$fn42227.invoke(util.clj:342) at metabase.sync.util$fn__42218$run_step_with_metadata42223.invoke(util.clj:337) at metabase.sync.util$fn42410$run_sync_operation42415$fn42416$fn42417.invoke(util.clj:430) at clojure.core$mapv$fn8445.invoke(core.clj:6912) at clojure.lang.PersistentVector.reduce(PersistentVector.java:343) at clojure.core$reduce.invokeStatic(core.clj:6827) at clojure.core$mapv.invokeStatic(core.clj:6903) at clojure.core$mapv.invoke(core.clj:6903) at metabase.sync.util$fn42410$run_sync_operation42415$fn42416.invoke(util.clj:430) at metabase.sync.util$fn42410$run_sync_operation42415.invoke(util.clj:424) at metabase.sync.sync_metadata$fn54475$sync_db_metadataBANG54480$fn54481$fn54482.invoke(sync_metadata.clj:51) at metabase.sync.util$do_with_error_handling.invokeStatic(util.clj:149) at metabase.sync.util$do_with_error_handling.invoke(util.clj:142) at metabase.sync.util$do_with_error_handling.invokeStatic(util.clj:145) at metabase.sync.util$do_with_error_handling.invoke(util.clj:142) at clojure.core$partial$fn5839.invoke(core.clj:2623) at metabase.driver$fn22445.invokeStatic(driver.clj:540) at metabase.driver$fn22445.invoke(driver.clj:540) at clojure.lang.MultiFn.invoke(MultiFn.java:239) at metabase.sync.util$sync_in_context$fn42130.invoke(util.clj:138) at metabase.sync.util$with_db_logging_disabled$fn42127.invoke(util.clj:129) at metabase.sync.util$with_start_and_finish_loggingSTAR.invokeStatic(util.clj:102) at metabase.sync.util$with_start_and_finish_loggingSTAR.invoke(util.clj:96) at metabase.sync.util$with_start_and_finish_logging$fn42116.invoke(util.clj:114) at metabase.sync.util$with_sync_events$fn42111.invoke(util.clj:88) at metabase.sync.util$with_duplicate_ops_prevented$fn__42102.invoke(util.clj:67) at metabase.sync.util$do_sync_operation.invokeStatic(util.clj:164) at metabase.sync.util$do_sync_operation.invoke(util.clj:161) at metabase.sync.sync_metadata$fn54475$sync_db_metadata_BANG_54480$fn54481.invoke(sync_metadata.clj:50) at metabase.sync.sync_metadata$fn54475$sync_db_metadata_BANG___54480.invoke(sync_metadata.clj:47) at metabase.api.database$fn55211$fn55213.invoke(database.clj:614) at clojure.core$binding_conveyor_fn$fn5754.invoke(core.clj:2030) at clojure.lang.AFn.call(AFn.java:18) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 08-03 15:09:24 INFO sync.util :: FINISHED: Sync metadata for athena Database 2 'Athena' (8.5 s)

rudhra13 commented 4 years ago

diagnostic info:

{ "browser-info": { "language": "en-US", "platform": "MacIntel", "userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/83.0.4103.116 Safari/537.36", "vendor": "Google Inc." }, "system-info": { "file.encoding": "UTF-8", "java.runtime.name": "Java(TM) SE Runtime Environment", "java.runtime.version": "1.8.0_171-b11", "java.vendor": "Oracle Corporation", "java.vendor.url": "http://java.oracle.com/", "java.version": "1.8.0_171", "java.vm.name": "Java HotSpot(TM) 64-Bit Server VM", "java.vm.version": "25.171-b11", "os.name": "Linux", "os.version": "4.14.104-95.84.amzn2.x86_64", "user.language": "en", "user.timezone": "Etc/UTC" }, "metabase-info": { "databases": [ "athena", "mysql", "googleanalytics" ], "hosting-env": "unknown", "application-database": "mysql", "application-database-details": { "database": { "name": "MySQL", "version": "5.7.30" }, "jdbc-driver": { "name": "MariaDB Connector/J", "version": "2.5.1" } }, "run-mode": "prod", "version": { "tag": "v0.36.2", "date": "2020-07-31", "branch": "release-0.36.x", "hash": "13f0225" }, "settings": { "report-timezone": "Asia/Calcutta" } } }

dacort commented 4 years ago

Hi @rudhra13, thanks for reporting the issue!

Sounds like you're using the Athena federation functionality? If so, sounds like there's something there that's failing and causing the entire sync to fail.

Can you confirm if you're using federation and multiple catalogs?

rudhra13 commented 4 years ago

No, we are not using Athena federation functionality, everything was working fine before version 0.36.0 with v1.0.0 athena driver.

dacort commented 4 years ago

Hm that's odd, this error message seems to indicate a lambda function is being called:

Failed to invoke lambda function due to Unsupported Arrow Type [Timestamp(MILLISECOND, null)] in Lambda Data Source

I need to add some graceful failures in the table sync code, but if you can figure out what table that error is coming from and resolve it, that might be a good temporary workaround. I'm pretty sure that error message is coming from Athena.

rudhra13 commented 4 years ago

As soon as i am trying to click the button "sync database schema now" it is directly throwing the error, if the specific table is the issue, i am not able to get any info, as which table is causing the issue.

dacort commented 4 years ago

Got it. It sounds like there's a table in Athena that isn't queryable at all, and when Metabase tries to identify the schema it throws the notes exception and interrupts the sync process.

If you're not using federation or a Hive data catalog, it's likely just a table in your normal data catalog that isn't Athena compatible.

I think I need to make some changes to gracefully fail the sync process if that happens but will probably take me a couple days. Thanks again for opening the issue!

rudhra13 commented 4 years ago

Thats great,

can you tell me, how are you syncing the Athena tables, I can manually run the queries and will try to figure out which table is creating the issue, till the time you can fix/handle it?

Also, is there a possibility that existing table data which is present in metabase db could be causing the issue, because which i am observing in the logs is, some tables are failling to load or something and printing the logs, incompatible type.

Although, if that would be the scenario, it shouldn't have been working before also.

error logs: 08-03 16:02:50 ERROR sync.util :: Error fingerprinting Table 721 'some_table' java.sql.SQLException: [Simba][AthenaJDBC](100071) An error has been thrown from the AWS Athena client. HIVE_PARTITION_SCHEMA_MISMATCH: There is a mismatch between the table and partition schemas. The types are incompatible and cannot be coerced. The column 'teamid' in table 'some_table' is declared as type 'string', but partition 'dt=2020-03-09/partition_1=go.to%3Aflock%3something.json.2020-03-09-02' declared column 'teamid' as type 'double'. [Execution ID: 6c52fb9b-c929-4327-9bfd-ac6f5c4e37a2] at com.simba.athena.athena.api.AJClient.executeQuery(Unknown Source) at com.simba.athena.athena.dataengine.AJQueryExecutor.execute(Unknown Source) at com.simba.athena.jdbc.common.SPreparedStatement.executeWithParams(Unknown Source) at com.simba.athena.jdbc.common.SPreparedStatement.executeQuery(Unknown Source) at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:431) at metabase.driver.sql_jdbc.execute$fn__72531.invokeStatic(execute.clj:267) at metabase.driver.sql_jdbc.execute$fn__72531.invoke(execute.clj:265) at clojure.lang.MultiFn.invoke(MultiFn.java:234) at metabase.driver.sql_jdbc.execute$execute_reducible_query.invokeStatic(execute.clj:389) at metabase.driver.sql_jdbc.execute$execute_reducible_query.invoke(execute.clj:377) at metabase.driver.sql_jdbc$fn__73846.invokeStatic(sql_jdbc.clj:49) at metabase.driver.sql_jdbc$fn__73846.invoke(sql_jdbc.clj:47) at metabase.driver.athena$fn__591.invokeStatic(athena.clj:278) at metabase.driver.athena$fn__591.invoke(athena.clj:276) at clojure.lang.MultiFn.invoke(MultiFn.java:244) at metabase.query_processor.context$executef.invokeStatic(context.clj:59) at metabase.query_processor.context$executef.invoke(context.clj:48) at metabase.query_processor.context.default$default_runf.invokeStatic(default.clj:69) at metabase.query_processor.context.default$default_runf.invoke(default.clj:67) at metabase.query_processor.context$runf.invokeStatic(context.clj:45) at metabase.query_processor.context$runf.invoke(context.clj:39) at metabase.query_processor.reducible$pivot.invokeStatic(reducible.clj:34) at metabase.query_processor.reducible$pivot.invoke(reducible.clj:31) at metabase.query_processor.middleware.mbql_to_native$mbql__GT_native$fn__45532.invoke(mbql_to_native.clj:26) at metabase.query_processor.middleware.check_features$check_features$fn__44834.invoke(check_features.clj:42) at metabase.query_processor.middleware.optimize_datetime_filters$optimize_datetime_filters$fn__45697.invoke(optimize_datetime_filters.clj:133) at metabase.query_processor.middleware.wrap_value_literals$wrap_value_literals$fn__47225.invoke(wrap_value_literals.clj:137) at metabase.query_processor.middleware.annotate$add_column_info$fn__43455.invoke(annotate.clj:574) at metabase.query_processor.middleware.permissions$check_query_permissions$fn__44709.invoke(permissions.clj:64) at metabase.query_processor.middleware.pre_alias_aggregations$pre_alias_aggregations$fn__46215.invoke(pre_alias_aggregations.clj:40) at metabase.query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__44907.invoke(cumulative_aggregations.clj:61) at metabase.query_processor.middleware.resolve_joins$resolve_joins$fn__46747.invoke(resolve_joins.clj:183) at metabase.query_processor.middleware.add_implicit_joins$add_implicit_joins$fn__39185.invoke(add_implicit_joins.clj:245) at metabase.query_processor.middleware.limit$limit$fn__45518.invoke(limit.clj:38) at metabase.query_processor.middleware.format_rows$format_rows$fn__45499.invoke(format_rows.clj:81) at metabase.query_processor.middleware.desugar$desugar$fn__44973.invoke(desugar.clj:22) at metabase.query_processor.middleware.binning$update_binning_strategy$fn__43999.invoke(binning.clj:229) at metabase.query_processor.middleware.resolve_fields$resolve_fields$fn__44515.invoke(resolve_fields.clj:24) at metabase.query_processor.middleware.add_dimension_projections$add_remapping$fn__38734.invoke(add_dimension_projections.clj:272) at metabase.query_processor.middleware.add_implicit_clauses$add_implicit_clauses$fn__38941.invoke(add_implicit_clauses.clj:141) at metabase.query_processor.middleware.add_source_metadata$add_source_metadata_for_source_queries$fn__39334.invoke(add_source_metadata.clj:105) at metabase.query_processor.middleware.reconcile_breakout_and_order_by_bucketing$reconcile_breakout_and_order_by_bucketing$fn__46412.invoke(reconcile_breakout_and_order_by_bucketing.clj:98) at metabase.query_processor.middleware.auto_bucket_datetimes$auto_bucket_datetimes$fn__43640.invoke(auto_bucket_datetimes.clj:125) at metabase.query_processor.middleware.resolve_source_table$resolve_source_tables$fn__44562.invoke(resolve_source_table.clj:46) at metabase.query_processor.middleware.parameters$substitute_parameters$fn__46197.invoke(parameters.clj:114) at metabase.query_processor.middleware.resolve_referenced$resolve_referenced_card_resources$fn__44614.invoke(resolve_referenced.clj:80) at metabase.query_processor.middleware.expand_macros$expand_macros$fn__45229.invoke(expand_macros.clj:158) at metabase.query_processor.middleware.add_timezone_info$add_timezone_info$fn__39365.invoke(add_timezone_info.clj:15) at metabase.query_processor.middleware.splice_params_in_response$splice_params_in_response$fn__47109.invoke(splice_params_in_response.clj:32) at metabase.query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__46423$fn__46427.invoke(resolve_database_and_driver.clj:33) at metabase.driver$do_with_driver.invokeStatic(driver.clj:61) at metabase.driver$do_with_driver.invoke(driver.clj:57) at metabase.query_processor.middleware.resolve_database_and_driver$resolve_database_and_driver$fn__46423.invoke(resolve_database_and_driver.clj:27) at metabase.query_processor.middleware.fetch_source_query$resolve_card_id_source_tables$fn__45447.invoke(fetch_source_query.clj:267) at metabase.query_processor.middleware.store$initialize_store$fn__47118$fn__47119.invoke(store.clj:11) at metabase.query_processor.store$do_with_store.invokeStatic(store.clj:44) at metabase.query_processor.store$do_with_store.invoke(store.clj:40) at metabase.query_processor.middleware.store$initialize_store$fn__47118.invoke(store.clj:10) at metabase.query_processor.middleware.cache$maybe_return_cached_results$fn__44491.invoke(cache.clj:209) at metabase.query_processor.middleware.validate$validate_query$fn__47127.invoke(validate.clj:10) at metabase.query_processor.middleware.normalize_query$normalize$fn__45545.invoke(normalize_query.clj:22) at metabase.query_processor.middleware.add_rows_truncated$add_rows_truncated$fn__39203.invoke(add_rows_truncated.clj:36) at metabase.query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__47094.invoke(results_metadata.clj:143) at metabase.query_processor.reducible$async_qp$qp_STAR___38013$thunk__38014.invoke(reducible.clj:101) at metabase.query_processor.reducible$async_qp$qp_STAR___38013.invoke(reducible.clj:107) at metabase.query_processor.reducible$async_qp$qp_STAR___38013.invoke(reducible.clj:94) at metabase.query_processor.reducible$sync_qp$qp_STAR___38022$fn__38023.invoke(reducible.clj:129) at metabase.query_processor.reducible$sync_qp$qp_STAR___38022.invoke(reducible.clj:128) at clojure.lang.AFn.applyToHelper(AFn.java:154) at clojure.lang.AFn.applyTo(AFn.java:144) at clojure.core$apply.invokeStatic(core.clj:667) at clojure.core$apply.invoke(core.clj:660) at metabase.query_processor$process_query.invokeStatic(query_processor.clj:122) at metabase.query_processor$process_query.doInvoke(query_processor.clj:116) at clojure.lang.RestFn.invoke(RestFn.java:410) at clojure.lang.Var.invoke(Var.java:384) at metabase.db.metadata_queries$fn__52337$table_rows_sample__52342$fn__52343.invoke(metadata_queries.clj:96) at metabase.db.metadata_queries$fn__52337$table_rows_sample__52342.invoke(metadata_queries.clj:92) at metabase.sync.analyze.fingerprint$fn__52403$fingerprint_table_BANG___52408$fn__52409.invoke(fingerprint.clj:63) at metabase.sync.analyze.fingerprint$fn__52403$fingerprint_table_BANG___52408.invoke(fingerprint.clj:43) at metabase.sync.analyze.fingerprint$fn__52576$fingerprint_fields_BANG___52581$fn__52582$fn__52583.invoke(fingerprint.clj:166) at metabase.sync.util$do_with_error_handling.invokeStatic(util.clj:149) at metabase.sync.util$do_with_error_handling.invoke(util.clj:142) at metabase.sync.analyze.fingerprint$fn__52576$fingerprint_fields_BANG___52581$fn__52582.invoke(fingerprint.clj:164) at metabase.sync.analyze.fingerprint$fn__52576$fingerprint_fields_BANG___52581.invoke(fingerprint.clj:160) at metabase.sync.analyze.fingerprint$fn__52604$fingerprint_fields_for_db_BANG___52609$fn__52610$fn__52611$iter__52612__52616$fn__52617$fn__52618.invoke(fingerprint.clj:184) at metabase.sync.analyze.fingerprint$fn__52604$fingerprint_fields_for_db_BANG___52609$fn__52610$fn__52611$iter__52612__52616$fn__52617.invoke(fingerprint.clj:181) 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:708) at clojure.core$reduce1.invokeStatic(core.clj:942) at clojure.core$reduce1.invokeStatic(core.clj:934) at clojure.core$merge_with.invokeStatic(core.clj:3059) at clojure.core$merge_with.doInvoke(core.clj:3051) at clojure.lang.RestFn.applyTo(RestFn.java:139) at clojure.core$apply.invokeStatic(core.clj:667) at clojure.core$apply.invoke(core.clj:660) at metabase.sync.analyze.fingerprint$fn__52604$fingerprint_fields_for_db_BANG___52609$fn__52610$fn__52611.invoke(fingerprint.clj:181) at metabase.query_processor.store$do_with_store.invokeStatic(store.clj:46) at metabase.query_processor.store$do_with_store.invoke(store.clj:40) at metabase.sync.analyze.fingerprint$fn__52604$fingerprint_fields_for_db_BANG___52609$fn__52610.invoke(fingerprint.clj:178) at metabase.sync.analyze.fingerprint$fn__52604$fingerprint_fields_for_db_BANG___52609.invoke(fingerprint.clj:172) at metabase.sync.analyze$make_analyze_steps$fn__52750.invoke(analyze.clj:106) at metabase.sync.util$fn__42218$run_step_with_metadata__42223$fn__42227$fn__42229.invoke(util.clj:345) at metabase.sync.util$with_start_and_finish_logging_STAR_.invokeStatic(util.clj:102) at metabase.sync.util$with_start_and_finish_logging_STAR_.invoke(util.clj:96) at metabase.sync.util$with_start_and_finish_debug_logging.invokeStatic(util.clj:119) at metabase.sync.util$with_start_and_finish_debug_logging.invoke(util.clj:116) at metabase.sync.util$fn__42218$run_step_with_metadata__42223$fn__42227.invoke(util.clj:342) at metabase.sync.util$fn__42218$run_step_with_metadata__42223.invoke(util.clj:337) at metabase.sync.util$fn__42410$run_sync_operation__42415$fn__42416$fn__42417.invoke(util.clj:430) at clojure.core$mapv$fn__8445.invoke(core.clj:6912) at clojure.lang.PersistentVector.reduce(PersistentVector.java:343) at clojure.core$reduce.invokeStatic(core.clj:6827) at clojure.core$mapv.invokeStatic(core.clj:6903) at clojure.core$mapv.invoke(core.clj:6903) at metabase.sync.util$fn__42410$run_sync_operation__42415$fn__42416.invoke(util.clj:430) at metabase.sync.util$fn__42410$run_sync_operation__42415.invoke(util.clj:424) at metabase.sync.analyze$fn__52762$analyze_db_BANG___52767$fn__52768$fn__52769.invoke(analyze.clj:123) at metabase.sync.util$do_with_error_handling.invokeStatic(util.clj:149) at metabase.sync.util$do_with_error_handling.invoke(util.clj:142) at metabase.sync.util$do_with_error_handling.invokeStatic(util.clj:145) at metabase.sync.util$do_with_error_handling.invoke(util.clj:142) at clojure.core$partial$fn__5839.invoke(core.clj:2623) at metabase.driver$fn__22445.invokeStatic(driver.clj:540) at metabase.driver$fn__22445.invoke(driver.clj:540) at clojure.lang.MultiFn.invoke(MultiFn.java:239) at metabase.sync.util$sync_in_context$fn__42130.invoke(util.clj:138) at metabase.sync.util$with_db_logging_disabled$fn__42127.invoke(util.clj:129) at metabase.sync.util$with_start_and_finish_logging_STAR_.invokeStatic(util.clj:102) at metabase.sync.util$with_start_and_finish_logging_STAR_.invoke(util.clj:96) at metabase.sync.util$with_start_and_finish_logging$fn__42116.invoke(util.clj:114) at metabase.sync.util$with_sync_events$fn__42111.invoke(util.clj:88) at metabase.sync.util$with_duplicate_ops_prevented$fn__42102.invoke(util.clj:67) at metabase.sync.util$do_sync_operation.invokeStatic(util.clj:164) at metabase.sync.util$do_sync_operation.invoke(util.clj:161) at metabase.sync.analyze$fn__52762$analyze_db_BANG___52767$fn__52768.invoke(analyze.clj:120) at metabase.sync.analyze$fn__52762$analyze_db_BANG___52767.invoke(analyze.clj:115) at metabase.api.database$fn__55211$fn__55213.invoke(database.clj:615) at clojure.core$binding_conveyor_fn$fn__5754.invoke(core.clj:2030) at clojure.lang.AFn.call(AFn.java:18) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) Caused by: com.simba.athena.support.exceptions.GeneralException: [Simba][AthenaJDBC](100071) An error has been thrown from the AWS Athena client. HIVE_PARTITION_SCHEMA_MISMATCH: There is a mismatch between the table and partition schemas. The types are incompatible and cannot be coerced. The column 'teamid' in table 'event_parquet_db.go_to_flock_paywall_clicked' is declared as type 'string', but partition 'dt=2020-03-09/partition_1=go.to%3Aflock%3something.json.2020-03-09-02' declared column 'teamid' as type 'double'. [Execution ID: 6c52fb9b-c929-4327-9bfd-ac6f5c4e37a2] ... 145 more

dacort commented 4 years ago

@rudhra13 If you have access to the Athena console and can look at your query history you should be able to see the queries that Metabase is executing and which ones fail.

Based on the stack trace above, the error message (HIVE_PARTITION_SCHEMA_MISMATCH) is with the Athena table itself. Even if you were running that query inside Athena directly, it would fail because the schemas are different on the partition than they are on the table itself. This may have worked previously if something changed with your data on S3 or the query hit a different set of data first...

dacort commented 4 years ago

@rudhra13 Digging deeper into your original error message, I'm not sure there's a lot that I can do here.

Looking at the stack trace, this is the last line from this driver: at metabase.driver.athena$get_tables.invokeStatic(athena.clj:242)

get_tables is a method that calls .getTables in the JDBC library that Metabase uses (c3p0). That then executes a series of calls in the Athena JDBC driver, one of which is getTablesMetadata. When that call attempts to load the metadata of a specific table, it's failing and throwing an exception.

Because that exception happens inside the generic get_tables call, I can't gracefully the exception because the entire call is failing. So once that call fails, I don't have metadata about any of the tables in the database.

I could potentially add some additional logging to help narrow down the database the issue is happening in, but that still wouldn't help resolve the issue in the driver since the entire get_tables call fails.

A few additional questions that might help you narrow down which table this is:

Based on the error message (Failed to invoke lambda function due to Unsupported Arrow Type [Timestamp(MILLISECOND, null)] in Lambda Data Source), it really seems like you have some other catalog or Athena Federation functionality enabled. This is based on how Athena Federation uses the Apache Arrow library to facilitate data transfer and Federation is the only thing I'm aware of in Athena that would be calling a lambda function. If you can find that other catalog and find which table that's related to, you might be able to remove or delete that table.

Here's an example AWS CLI command that lists my data catalogs:

aws athena list-data-catalogs --region us-east-1
{
    "DataCatalogsSummary": [
        {
            "CatalogName": "AwsDataCatalog",
            "Type": "GLUE"
        },
        {
            "CatalogName": "cwm",
            "Type": "LAMBDA"
        },
        {
            "CatalogName": "s3qlite",
            "Type": "LAMBDA"
        }
    ]
}
dacort commented 4 years ago

Based on https://github.com/awslabs/aws-athena-query-federation/issues/72 it seems like this is almost certainly an error related to Athena Federation.

Based on that issue, it looks like a fix has been pushed, but somebody on your side would need to upgrade the related lambda function. Looks like the fix was pushed sometime after April 12.

rudhra13 commented 4 years ago

This worked like a charm, Removed the Athena federated query catalog and everything got synced, Even I was not aware, it was there, Although it was there from quite some time and data was getting synced without any issues, don't know, how the issue starts to occur now.

Removing it fixed the issue. Thanks for the help.