Source Postgres: fails with idle-transaction-timeout issue
- Lingua principale
- Python
- Stelle
- 22.1k
- Fork
- 5.3k
- Metriche di merge delle PR
- Metriche PR in attesa
Descrizione
### Connector Name
source-postgres
### Connector Version
2.0.34
### What step the error happened?
During the sync
### Revelant information
Postgres version 14
Airbyte version 0.50.1
We are trying to connect to a replica database in our postgresdb with ~3.15gb of data synced. However during the end of the sync while closing the connection, we run into an `idle-transaction-timeout` error. Using the JDBC url params to bump up the `idle_in_transaction_session_timeout ` doesn't work. Below are the relevant logs.
### Relevant log output
```shell
2023-06-26 18:25:47 [32mINFO[m i.a.w.g.ReplicationWorkerHelper(processMessageFromSource):226 - Records read: 35000 (3 GB)
2023-06-26 18:25:48 [32mINFO[m i.a.w.g.DefaultReplicationWorker(lambda$readFromSrcAndWriteToDstRunnable$5):299 - Source has no more messages, closing connection.
2023-06-26 18:25:48 [32mINFO[m i.a.w.p.KubePodProcess(close):784 - (pod: internal-analytics-test / dd-airbyte-read-73753-0-epftv) - Closed all resources for pod
2023-06-26 18:26:19 [32mINFO[m i.a.w.p.KubePodProcess(close):784 - (pod: internal-analytics-test / dd-airbyte-write-73753-0-basvm) - Closed all resources for pod
2023-06-26 18:26:19 [1;31mERROR[m i.a.w.g.DefaultReplicationWorker(replicate):215 - Sync worker failed.
io.airbyte.workers.internal.exception.SourceException: Source didn't exit properly - check the logs!
at io.airbyte.workers.general.DefaultReplicationWorker.lambda$readFromSrcAndWriteToDstRunnable$5(DefaultReplicationWorker.java:303) ~[io.airbyte-airbyte-commons-worker-0.50.1.jar:?]
at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
at java.lang.Thread.run(Thread.java:1589) ~[?:?]
Suppressed: io.airbyte.workers.exception.WorkerException: Source process exit with code 1. This warning is normal if the job was cancelled.
at io.airbyte.workers.internal.DefaultAirbyteSource.close(DefaultAirbyteSource.java:145) ~[io.airbyte-airbyte-commons-worker-0.50.1.jar:?]
at io.airbyte.workers.general.DefaultReplicationWorker.replicate(DefaultReplicationWorker.java:165) ~[io.airbyte-airbyte-commons-worker-0.50.1.jar:?]
at io.airbyte.workers.general.DefaultReplicationWorker.run(DefaultReplicationWorker.java:149) ~[io.airbyte-airbyte-commons-worker-0.50.1.jar:?]
at io.airbyte.workers.general.DefaultReplicationWorker.run(DefaultReplicationWorker.java:63) ~[io.airbyte-airbyte-commons-worker-0.50.1.jar:?]
at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$5(TemporalAttemptExecution.java:195) ~[io.airbyte-airbyte-workers-0.50.1.jar:?]
at java.lang.Thread.run(Thread.java:1589) ~[?:?]
Caused by: io.airbyte.workers.exception.WorkerException: Source process exit with code 1. This warning is normal if the job was cancelled.
at io.airbyte.workers.internal.DefaultAirbyteSource.close(DefaultAirbyteSource.java:145) ~[io.airbyte-airbyte-commons-worker-0.50.1.jar:?]
at io.airbyte.workers.general.DefaultReplicationWorker.lambda$readFromSrcAndWriteToDstRunnable$5(DefaultReplicationWorker.java:301) ~[io.airbyte-airbyte-commons-worker-0.50.1.jar:?]
... 4 more
2023-06-26 18:26:19 [32mINFO[m i.a.w.g.ReplicationWorkerHelper(getReplicationOutput):312 - sync summary: {
"status" : "failed",
"recordsSynced" : 39552,
"bytesSynced" : 3382101715,
"startTime" : 1687803625314,
"endTime" : 1687803979344,
"totalStats" : {
"bytesCommitted" : 0,
"bytesEmitted" : 3382101715,
"destinationStateMessagesEmitted" : 0,
"destinationWriteEndTime" : 1687803979243,
"destinationWriteStartTime" : 1687803625314,
"meanSecondsBeforeSourceStateMessageEmitted" : 0,
"maxSecondsBeforeSourceStateMessageEmitted" : 0,
"maxSecondsBetweenStateMessageEmittedandCommitted" : 0,
"meanSecondsBetweenStateMessageEmittedandCommitted" : 0,
"recordsEmitted" : 39552,
"recordsCommitted" : 0,
"replicationEndTime" : 0,
"replicationStartTime" : 1687803625314,
"sourceReadEndTime" : 0,
"sourceReadStartTime" : 1687803632636,
"sourceStateMessagesEmitted" : 0
},
"streamStats" : [ {
"streamName" : "audit_history",
"stats" : {
"bytesEmitted" : 3382101715,
"recordsEmitted" : 39552
}
}, {
"streamName" : "audit_history",
"streamNamespace" : "public",
"stats" : {
"bytesEmitted" : 0,
"recordsEmitted" : 0
}
} ]
}
2023-06-26 18:26:19 [32mINFO[m i.a.w.g.ReplicationWorkerHelper(getReplicationOutput):313 - failures: [ {
"failureOrigin" : "source",
"failureType" : "system_error",
"internalMessage" : "java.lang.RuntimeException: java.lang.RuntimeException: org.postgresql.util.PSQLException: FATAL: terminating connection due to idle-in-transaction timeout",
"externalMessage" : "Something went wrong in the connector. See the logs for more details.",
"metadata" : {
"attemptNumber" : 0,
"jobId" : 73753,
"from_trace_message" : true,
"connector_command" : "read"
},
"stacktrace" : "java.lang.RuntimeException: java.lang.RuntimeException: org.postgresql.util.PSQLException: FATAL: terminating connection due to idle-in-transaction timeout\n\tat io.airbyte.commons.util.CompositeIterator.computeNext(CompositeIterator.java:78)\n\tat com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)\n\tat com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)\n\tat io.airbyte.commons.util.DefaultAutoCloseableIterator.computeNext(DefaultAutoCloseableIterator.java:42)\n\tat com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)\n\tat com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)\n\tat io.airbyte.commons.util.DefaultAutoCloseableIterator.computeNext(DefaultAutoCloseableIterator.java:42)\n\tat com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)\n\tat com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)\n\tat java.base/java.util.Iterator.forEachRemaining(Iterator.java:132)\n\tat io.airbyte.integrations.base.IntegrationRunner.lambda$produceMessages$2(IntegrationRunner.java:200)\n\tat io.airbyte.integrations.base.IntegrationRunner.watchForOrphanThreads(IntegrationRunner.java:270)\n\tat io.airbyte.integrations.base.IntegrationRunner.produceMessages(IntegrationRunner.java:199)\n\tat io.airbyte.integrations.base.IntegrationRunner.runInternal(IntegrationRunner.java:140)\n\tat io.airbyte.integrations.base.IntegrationRunner.run(IntegrationRunner.java:99)\n\tat io.airbyte.integrations.source.postgres.PostgresSource.main(PostgresSource.java:538)\nCaused by: java.lang.RuntimeException: org.postgresql.util.PSQLException: FATAL: terminating connection due to idle-in-transaction timeout\n\tat io.airbyte.db.jdbc.StreamingJdbcDatabase.lambda$unsafeQuery$0(StreamingJdbcDatabase.java:78)\n\tat java.base/java.util.stream.AbstractPipeline.close(AbstractPipeline.java:323)\n\tat io.airbyte.commons.concurrency.VoidCallable.call(VoidCallable.java:15)\n\tat io.airbyte.commons.util.DefaultAutoCloseableIterator.close(DefaultAutoCloseableIterator.java:53)\n\tat io.airbyte.commons.util.LazyAutoCloseableIterator.close(LazyAutoCloseableIterator.java:56)\n\tat io.airbyte.commons.concurrency.VoidCallable.call(VoidCallable.java:15)\n\tat io.airbyte.commons.util.DefaultAutoCloseableIterator.close(DefaultAutoCloseableIterator.java:53)\n\tat io.airbyte.commons.concurrency.VoidCallable.call(VoidCallable.java:15)\n\tat io.airbyte.commons.util.DefaultAutoCloseableIterator.close(DefaultAutoCloseableIterator.java:53)\n\tat io.airbyte.commons.util.CompositeIterator.computeNext(CompositeIterator.java:74)\n\t... 15 more\nCaused by: org.postgresql.util.PSQLException: FATAL: terminating connection due to idle-in-transaction timeout\n\tat org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2676)\n\tat org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2366)\n\tat org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:356)\n\tat org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:316)\n\tat org.postgresql.jdbc.PgConnection.executeTransactionCommand(PgConnection.java:879)\n\tat org.postgresql.jdbc.PgConnection.commit(PgConnection.java:901)\n\tat org.postgresql.jdbc.PgConnection.setAutoCommit(PgConnection.java:843)\n\tat com.zaxxer.hikari.pool.ProxyConnection.setAutoCommit(ProxyConnection.java:401)\n\tat com.zaxxer.hikari.pool.HikariProxyConnection.setAutoCommit(HikariProxyConnection.java)\n\tat io.airbyte.db.jdbc.StreamingJdbcDatabase.lambda$unsafeQuery$0(StreamingJdbcDatabase.java:72)\n\t... 24 more\n",
"timestamp" : 1687803948318
}, {
"failureOrigin" : "source",
"internalMessage" : "Source didn't exit properly - check the logs!",
"externalMessage" : "Something went wrong within the source connector",
"metadata" : {
"attemptNumber" : 0,
"jobId" : 73753,
"connector_command" : "read"
},
"stacktrace" : "io.airbyte.workers.internal.exception.SourceException: Source didn't exit properly - check the logs!\n\tat io.airbyte.workers.general.DefaultReplicationWorker.lambda$readFromSrcAndWriteToDstRunnable$5(DefaultReplicationWorker.java:303)\n\tat java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)\n\tat java.base/java.lang.Thread.run(Thread.java:1589)\nCaused by: io.airbyte.workers.exception.WorkerException: Source process exit with code 1. This warning is normal if the job was cancelled.\n\tat io.airbyte.workers.internal.DefaultAirbyteSource.close(DefaultAirbyteSource.java:145)\n\tat io.airbyte.workers.general.DefaultReplicationWorker.lambda$readFromSrcAndWriteToDstRunnable$5(DefaultReplicationWorker.java:301)\n\t... 4 more\n",
"timestamp" : 1687803948804
} ]
2023-06-26 18:26:19 [32mINFO[m i.a.c.i.LineGobbler(voidCall):149 -
2023-06-26 18:26:19 [32mINFO[m i.a.w.t.TemporalAttemptExecution(get):163 - Stopping cancellation check scheduling...
2023-06-26 18:26:19 [32mINFO[m i.a.c.i.LineGobbler(voidCall):149 - ----- END REPLICATION -----
2023-06-26 18:26
```
### Contribute
- [ ] Yes, I want to contribute
Guida per i contributori
Apri la guida per i contributori
Valutazione
Questa issue non è ancora stata valutata.