We’re performing syncs with Snowflake through airbyte, but they fail around the 6 hour mark with a 403 FORBIDDEN error. We believe this is due to an expired snowflake token since our data sets are fairly large and can sync for many hours at a time. Is there a way to configure token refreshes within Airbyte currently?
We’ve found an old issue report that details the same issue that we’re experiencing here, but it doesn’t look like it’s gone anywhere recently.
opened 11:57AM - 16 Mar 22 UTC
type/bug
community
needs-triage
team/use
autoteam
<!--
Welcome to Airbyte!
We're really appreciate your report and know that th… is will help us build an
amazing tool. If you want to contribute yourself, you can find a good place
to start by searching for the good-first-issues label or maybe... by trying
to solve this one? (we can help debug this with you!)
Right now we are in alpha, so we're releasing versions a lot more frequently than
normal. You can help us get to the root of the problem faster by filling out the
questionnaire below!
It's really important having all information and context.
You can remove the examples bellow and fill out with your information.
-->
## Environment
- **Airbyte version**: example is 0.35.55-alpha
- **OS Version / Instance**:Kubernetes AWS EKS
- **Source Connector and version**: Snowflake 0.1.10
- **Destination Connector and version**: Postgres 0.3.15
- **Severity**: High
- **Step where error happened**: Sync job
## Current Behavior
After 6 hours syncing data from snowflake to postgres i got `403 Request has expired` errors
## Expected Behavior
Finish the sync job without issues, the driver must refresh the S3 access token.
## Logs
```
2022-03-16 01:31:18 [32mINFO[m i.a.w.w.WorkerRun(call):49 - Executing worker wrapper. Airbyte version: 0.35.55-alpha
2022-03-16 01:31:19 [32mINFO[m i.a.w.t.TemporalAttemptExecution(get):107 - Cloud storage job log path: /workspace/1821/0/logs.log
2022-03-16 01:31:19 [32mINFO[m i.a.w.t.TemporalAttemptExecution(get):110 - Executing worker wrapper. Airbyte version: 0.35.55-alpha
2022-03-16 01:31:23 [43mdestination[0m > SLF4J: Class path contains multiple SLF4J bindings.
2022-03-16 01:31:19 [32mINFO[m i.a.w.DefaultReplicationWorker(run):103 - start sync worker. job id: 1821 attempt id: 0
2022-03-16 01:31:19 [32mINFO[m i.a.w.DefaultReplicationWorker(run):115 - configured sync modes: {LOANS.LENDERS_TRANSACTIONS=full_refresh - overwrite}
2022-03-16 01:31:19 [32mINFO[m i.a.w.p.a.DefaultAirbyteDestination(start):69 - Running destination...
2022-03-16 01:31:19 [32mINFO[m i.a.w.p.KubeProcessFactory(create):111 - Attempting to start pod = destination-postgres-sync-1821-0-astgz
.....
.....
.....
2022-03-16 07:39:36 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44143000
2022-03-16 07:39:37 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44144000
2022-03-16 07:39:37 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44145000
2022-03-16 07:39:37 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44146000
2022-03-16 07:39:37 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44147000
2022-03-16 07:39:37 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44148000
2022-03-16 07:39:37 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44149000
2022-03-16 07:39:37 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44150000
2022-03-16 07:39:38 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44151000
2022-03-16 07:39:38 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44152000
2022-03-16 07:39:38 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44153000
2022-03-16 07:40:17 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44154000
2022-03-16 07:40:17 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44155000
2022-03-16 07:40:17 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44156000
2022-03-16 07:40:18 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44157000
2022-03-16 07:40:18 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44158000
2022-03-16 07:40:18 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44159000
2022-03-16 07:40:18 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44160000
2022-03-16 07:40:18 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44161000
2022-03-16 07:40:18 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44162000
2022-03-16 07:40:18 [32mINFO[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):300 - Records read: 44163000
2022-03-16 07:39:36 [44msource[0m > 2022-03-16 07:39:36 [32mINFO[m i.a.i.s.r.AbstractDbSource(lambda$createReadIterator$7):250 - Reading stream LENDERS_TRANSACTIONS. Records read: 44140000
2022-03-16 07:39:37 [43mdestination[0m > 2022-03-16 07:39:37 [32mINFO[m i.a.i.d.b.BufferedStreamConsumer(flushQueueToDestination):181 - Flushing buffer: 26213505 bytes
2022-03-16 07:39:37 [43mdestination[0m > 2022-03-16 07:39:37 [32mINFO[m i.a.i.d.b.BufferedStreamConsumer(lambda$flushQueueToDestination$1):185 - Flushing LENDERS_TRANSACTIONS: 16595 records
2022-03-16 07:39:37 [44msource[0m > 2022-03-16 07:39:37 [32mINFO[m i.a.i.s.r.AbstractDbSource(lambda$createReadIterator$7):250 - Reading stream LENDERS_TRANSACTIONS. Records read: 44150000
2022-03-16 07:40:18 [44msource[0m > 2022-03-16 07:40:18 [32mINFO[m i.a.i.s.r.AbstractDbSource(lambda$createReadIterator$7):250 - Reading stream LENDERS_TRANSACTIONS. Records read: 44160000
2022-03-16 07:40:19 [43mdestination[0m > 2022-03-16 07:40:19 [32mINFO[m i.a.i.d.b.BufferedStreamConsumer(flushQueueToDestination):181 - Flushing buffer: 26213159 bytes
2022-03-16 07:40:19 [43mdestination[0m > 2022-03-16 07:40:19 [32mINFO[m i.a.i.d.b.BufferedStreamConsumer(lambda$flushQueueToDestination$1):185 - Flushing LENDERS_TRANSACTIONS: 16614 records
2022-03-16 07:40:20 [44msource[0m > Mar 16, 2022 7:40:20 AM net.snowflake.client.jdbc.RestRequest execute
2022-03-16 07:40:20 [44msource[0m > SEVERE: Error response: HTTP Response code: 403, request: GET https://zzzz-zzzz-zzzzzz-customer-stage.s3.us-west-2.amazonaws.com/xxxxxxx-xxx-xxx/results/0xxxxxxx-xxx-xxx-xxxxx-xxxxx_0/main/data_0_2_64?x-amz-server-side-encryption-customer-algorithm=AES256&response-content-encoding=gzip&AWSAccessKeyId=****&Expires=1647415892&Signature=**** HTTP/1.1
2022-03-16 07:40:20 [44msource[0m > Mar 16, 2022 7:40:20 AM net.snowflake.client.jdbc.DefaultResultStreamProvider getInputStream
2022-03-16 07:40:20 [44msource[0m > SEVERE: Error fetching chunk from: https://zzzz-zzzz-zzzzzz-customer-stage.s3.us-west-2.amazonaws.com/yyy-yyyy-yyyy/results/0xxxxxxx-xxx-xxx-xxxxx-xxxxx_0/main/data_0_2_64?x-amz-server-side-encryption-customer-algorithm=AES256&response-content-encoding=gzip&AWSAccessKeyId=****&Expires=1647415892&Signature=****
2022-03-16 07:40:20 [44msource[0m > Mar 16, 2022 7:40:20 AM net.snowflake.client.jdbc.SnowflakeUtil logResponseDetails
2022-03-16 07:40:20 [44msource[0m > SEVERE: Response status line reason: Forbidden
2022-03-16 07:40:20 [44msource[0m > Mar 16, 2022 7:40:20 AM net.snowflake.client.jdbc.SnowflakeUtil logResponseDetails
2022-03-16 07:40:20 [44msource[0m > SEVERE: Response content: <?xml version="1.0" encoding="UTF-8"?>
2022-03-16 07:40:20 [44msource[0m > <Error><Code>AccessDenied</Code><Message>Request has expired</Message><Expires>2022-03-16T07:31:32Z</Expires><ServerTime>2022-03-16T07:40:21Z</ServerTime><RequestId>117ZD9YBDB4Z2ETR</RequestId><HostId>DSdkMbKiFFYbe5qIJa0wjSYH6rLQqMuodDuz2Oxa0tcXt02Ky+rgCEp8mqS/ukFNjL8mkyxTrMk=</HostId></Error>
try reached for the download of #chunk211 (Total chunks: 591) retry=10, error=net.snowflake.client.jdbc.SnowflakeSQLException: JDBC driver encountered communication error. Message: Error encountered when downloading a result chunk: HTTP status=403.
2022-03-16 07:40:24 [44msource[0m > at net.snowflake.client.jdbc.DefaultResultStreamProvider.getInputStream(DefaultResultStreamProvider.java:65)
2022-03-16 07:40:24 [44msource[0m > at net.snowflake.client.jdbc.SnowflakeChunkDownloader$2.call(SnowflakeChunkDownloader.java:896)
2022-03-16 07:40:24 [44msource[0m > at net.snowflake.client.jdbc.SnowflakeChunkDownloader$2.call(SnowflakeChunkDownloader.java:810)
2022-03-16 07:40:24 [44msource[0m > at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
2022-03-16 07:40:24 [44msource[0m > at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
2022-03-16 07:40:24 [44msource[0m > at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
2022-03-16 07:40:24 [44msource[0m > at java.base/java.lang.Thread.run(Thread.java:833)
2022-03-16 07:40:24 [44msource[0m >
2022-03-16 07:40:24 [44msource[0m > Mar 16, 2022 7:40:24 AM net.snowflake.client.jdbc.RestRequest execute
2022-03-16 07:40:24 [44msource[0m > SEVERE: Error response: HTTP Response code: 403, request: GET https://zzzz-zzzz-zzzzzz-customer-stage.s3.us-west-2.amazonaws.com/yyy-yyyy-yyyy/results/0xxxxxxx-xxx-xxx-xxxxx-xxxxx_0/main/data_0_2_63?x-amz-server-side-encryption-customer-algorithm=AES256&response-content-encoding=gzip&AWSAccessKeyId=****&Expires=1647415892&Signature=**** HTTP/1.1
2022-03-16 07:40:24 [44msource[0m > Mar 16, 2022 7:40:24 AM net.snowflake.client.jdbc.DefaultResultStreamProvider getInputStream
2022-03-16 07:40:24 [44msource[0m > SEVERE: Error fetching chunk from: https://zzzz-zzzz-zzzzzz-customer-stage.s3.us-west-2.amazonaws.com/yyy-yyyy-yyyy/results/0xxxxxxx-xxx-xxx-xxxxx-xxxxx_0/main/data_0_2_63?x-amz-server-side-encryption-customer-algorithm=AES256&response-content-encoding=gzip&AWSAccessKeyId=****&Expires=1647415892&Signature=****
2022-03-16 07:40:24 [44msource[0m > Mar 16, 2022 7:40:24 AM net.snowflake.client.jdbc.SnowflakeUtil logResponseDetails
2022-03-16 07:40:24 [44msource[0m > SEVERE: Response status line reason: Forbidden
2022-03-16 07:40:24 [44msource[0m > Mar 16, 2022 7:40:24 AM net.snowflake.client.jdbc.SnowflakeUtil logResponseDetails
2022-03-16 07:40:24 [44msource[0m > SEVERE: Response content: <?xml version="1.0" encoding="UTF-8"?>
2022-03-16 07:40:24 [44msource[0m > <Error><Code>AccessDenied</Code><Message>Request has expired</Message><Expires>2022-03-16T07:31:32Z</Expires><ServerTime>2022-03-16T07:40:25Z</ServerTime><RequestId>57V6SEXKENAP5TMS</RequestId><HostId>OnRMpjKmFc8Uk6uoLL1BqOha9Nq9sUxZgSOAAy8dtK+s13jduCSxkOE2W+aJNbu3Z+gw0C/6Fz4=</HostId></Error>
```
## Are you willing to submit a PR?
Yes
Hey @OM1Tykam ,
Thanks for the post and welcome to the community. On a first glance, I’m wondering if this merged pr solves your issue: https://github.com/airbytehq/airbyte/pull/9567 .
Let me know!
Sounds promising!
I’ll update if there’s still an issue.