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

Error running sync step #63

Closed octocat1000 closed 4 years ago

octocat1000 commented 4 years ago

Trying this for the first time and seems to fail at syncing. Clean install of Metabase v0.36.6

Also tried different log level settings for the DB but logging doesn't seem to change...

[6477ad8b-15ca-4eda-8113-5044c62ed21c] 2020-09-17T17:21:08-07:00 INFO metabase.sync.util STARTING: Sync metadata for athena Database 2 'Sandbox' [6477ad8b-15ca-4eda-8113-5044c62ed21c] 2020-09-17T17:21:08-07:00 INFO metabase.sync.util STARTING: step 'sync-timezone' for athena Database 2 'Sandbox' [6477ad8b-15ca-4eda-8113-5044c62ed21c] 2020-09-17T17:21:08-07:00 INFO metabase.sync.util FINISHED: step 'sync-timezone' for athena Database 2 'Sandbox' (854.2 µs) [6477ad8b-15ca-4eda-8113-5044c62ed21c] 2020-09-17T17:21:08-07:00 INFO metabase.sync.util STARTING: step 'sync-tables' for athena Database 2 'Sandbox' [6477ad8b-15ca-4eda-8113-5044c62ed21c] 2020-09-17T17:21:09-07:00 ERROR metabase.sync.util Error running sync step [6477ad8b-15ca-4eda-8113-5044c62ed21c] 2020-09-17T17:21:09-07:00 INFO metabase.sync.util FINISHED: Sync metadata for athena Database 2 'Sandbox' (1.0 s) [6477ad8b-15ca-4eda-8113-5044c62ed21c] 2020-09-17T17:21:09-07:00 INFO metabase.sync.util STARTING: Analyze data for athena Database 2 'Sandbox' [6477ad8b-15ca-4eda-8113-5044c62ed21c] 2020-09-17T17:21:09-07:00 INFO metabase.sync.util STARTING: step 'fingerprint-fields' for athena Database 2 'Sandbox' [6477ad8b-15ca-4eda-8113-5044c62ed21c] 2020-09-17T17:21:09-07:00 INFO metabase.sync.util FINISHED: step 'classify-fields' for athena Database 2 'Sandbox' (196.0 µs) [6477ad8b-15ca-4eda-8113-5044c62ed21c] 2020-09-17T17:21:09-07:00 INFO metabase.sync.util FINISHED: step 'fingerprint-fields' for athena Database 2 'Sandbox' (305.6 µs) [6477ad8b-15ca-4eda-8113-5044c62ed21c] 2020-09-17T17:21:09-07:00 INFO metabase.sync.util STARTING: step 'classify-fields' for athena Database 2 'Sandbox' [6477ad8b-15ca-4eda-8113-5044c62ed21c] 2020-09-17T17:21:09-07:00 INFO metabase.sync.util FINISHED: step 'classify-tables' for athena Database 2 'Sandbox' (272.5 µs) [6477ad8b-15ca-4eda-8113-5044c62ed21c] 2020-09-17T17:21:09-07:00 INFO metabase.sync.util STARTING: step 'classify-tables' for athena Database 2 'Sandbox' [6477ad8b-15ca-4eda-8113-5044c62ed21c] 2020-09-17T17:21:09-07:00 INFO metabase.sync.util FINISHED: Analyze data for athena Database 2 'Sandbox' (10.0 ms)

dacort commented 4 years ago

👋 Heyo, thanks for filing the issue! Can you make sure your IAM user has all the necessary permissions? There were a few extra ones noted in the release notes and #56

octocat1000 commented 4 years ago

My IAM user has s3:, Athena:, and glue:* as I was just trying this for the first time, I didn't want IAM to trip me up.

Is there anyway to increase the logging to see what is going on?

dacort commented 4 years ago

OK, that sounds fine then. :)

For increasing logging, depending on how you're running Metabase you can enable different log4j levels to enable trace logging for any metabase.sync calls.

If you're running with the jar: java -Dlog4j.configuration=https://log4j.us/templates/metabase?trace=metabase.sync -jar metabase.jar

If you're running with docker: docker run -e JAVA_OPTS=-Dlog4j.configuration=https://log4j.us/templates/metabase?trace=metabase.sync metabase/metabase

I'd also check your Athena query history to see if you've got any failing commands.

octocat1000 commented 4 years ago

Looks like the problem is twofold: 1.) I have a federated data source setup and, in order to use that, the IAM user needs permissions to invoke the lambda that the source uses. I added those permissions after seeing the error in CloudTrail.

2.) The data source is actually a Redshift database which is offline. After giving the use permissions, I now see a timeout in CloudTrail as below (redacted). I guess this will happen anytime that the target is unavailable...

{ "eventVersion": "1.05", "userIdentity": { "type": "IAMUser", "principalId": "xxx", "arn": "arn:aws:iam::123:user/xxx", "accountId": "123", "accessKeyId": "AAA", "userName": "xxx" }, "eventTime": "2020-09-18T20:58:14Z", "eventSource": "athena.amazonaws.com", "eventName": "ListDatabases", "awsRegion": "us-east-1", "sourceIPAddress": "72.220.234.219", "userAgent": "sbAthenaJDBCDriver/2.0, aws-sdk-java/1.11.793 Linux/4.19.76-linuxkit OpenJDK_64-Bit_Server_VM/11.0.8+10 java/11.0.8 clojure/1.10.1 vendor/AdoptOpenJDK", "errorCode": "MetadataException", "errorMessage": "Failed to invoke lambda function due to com.amazonaws.SdkClientException: Unable to execute HTTP request: Read timed out", "requestParameters": { "catalogName": "somefederated" }, "responseElements": null, "requestID": "15a90415-ca54-4109-91d0-b48b9292f3e1", "eventID": "81d46e61-daaf-437f-a1fc-f14f709ed961", "eventType": "AwsApiCall", "recipientAccountId": "123" }

dacort commented 4 years ago

Ah interesting, federation has come up a few times lately. Thanks for diving into this...were you able to get any detailed sync logs from Metabase? I'm wondering if ListDatabases throws an error or if it just kind of times out on the Metabase side.

Related to #55 but this appears to be a silent failure.

octocat1000 commented 4 years ago

Sorry, I didn't get any more detailed logs. Actually I "fixed" it by deleting the federated data source as this was in my sandbox account and it wasn't a source that we are actively using.

dacort commented 4 years ago

OK thanks @octocat1000 - I'll go ahead and close this for now. I opened a new issue to track better support for federated data sources as a feature request.