Normalize Failed When Connect with Salesforce

  • Is this your first time deploying Airbyte?: Yes
  • Deployment: Kubernetes
  • Airbyte Version: * 0.35.62-alpha
  • Source name/version: Salesforce (1.0.10)
  • Destination name/version: Redshift 0.3.44, happens in Postgresql 0.3.20 too
  • Step: The issue is happening during normalization
  • Description: Airbyte failds at normalize step, error log is below
2022-07-09 16:11:40 e[1;31mERRORe[m i.a.w.WorkerUtils(gentleClose):40 - Exception while while waiting for process to finish
java.lang.InterruptedException: sleep interrupted
	at java.lang.Thread.sleep(Native Method) ~[?:?]
	at java.lang.Process.waitFor(Process.java:468) ~[?:?]
	at io.airbyte.workers.process.KubePodProcess.waitFor(KubePodProcess.java:612) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
	at io.airbyte.workers.WorkerUtils.gentleClose(WorkerUtils.java:37) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
	at io.airbyte.workers.protocols.airbyte.DefaultAirbyteSource.close(DefaultAirbyteSource.java:128) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
	at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:167) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
	at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:57) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
	at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:155) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
	at java.lang.Thread.run(Thread.java:833) [?:?]
2022-07-09 16:11:40 e[32mINFOe[m i.a.w.p.KubePodProcess(destroy):623 - (pod: airbyte-prd / source-salesforce-sync-1685-1-kycsj) - Destroying Kube process.
2022-07-09 16:11:51 e[1;31mERRORe[m i.a.w.DefaultReplicationWorker(run):169 - Sync worker failed.
io.airbyte.workers.WorkerException: Source process exit with code 143. This warning is normal if the job was cancelled.
	at io.airbyte.workers.protocols.airbyte.DefaultAirbyteSource.close(DefaultAirbyteSource.java:136) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
	at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:167) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
	at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:57) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
	at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:155) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
	at java.lang.Thread.run(Thread.java:833) [?:?]
	Suppressed: java.net.SocketException: Socket closed
		at sun.nio.ch.NioSocketImpl.ensureOpenAndConnected(NioSocketImpl.java:165) ~[?:?]
		at sun.nio.ch.NioSocketImpl.beginWrite(NioSocketImpl.java:366) ~[?:?]
		at sun.nio.ch.NioSocketImpl.implWrite(NioSocketImpl.java:411) ~[?:?]
		at sun.nio.ch.NioSocketImpl.write(NioSocketImpl.java:440) ~[?:?]
		at sun.nio.ch.NioSocketImpl$2.write(NioSocketImpl.java:826) ~[?:?]
		at java.net.Socket$SocketOutputStream.write(Socket.java:1035) ~[?:?]
		at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:234) ~[?:?]
		at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:313) ~[?:?]
		at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:318) ~[?:?]
		at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:160) ~[?:?]
		at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:248) ~[?:?]
		at java.io.BufferedWriter.flush(BufferedWriter.java:257) ~[?:?]
		at io.airbyte.workers.protocols.airbyte.DefaultAirbyteDestination.notifyEndOfStream(DefaultAirbyteDestination.java:98) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
		at io.airbyte.workers.protocols.airbyte.DefaultAirbyteDestination.close(DefaultAirbyteDestination.java:111) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
		at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:126) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
		at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:57) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
		at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:155) ~[io.airbyte-airbyte-workers-0.35.62-alpha.jar:?]
		at java.lang.Thread.run(Thread.java:833) [?:?]

Hey @dongchirua,
Could you please upgrade your Airbyte version to the latest one? The normalization code is versioned with Airbyte and it received several improvements since 0.35.62.
Could you also share your full sync logs? I can’t find enough details in the sample you shared.

Hi @alafanechere , thank you for your comment.

I bring this issue to my local machine with Docker with version 0.39.35, Salesforce 1.0.11, Postgres 0.3.20. Here is a log and the same problem happens

logs-1.txt (4.3 MB)

Thank you for the full logs.
The error indeed happens on DBT normalization. It appears that there were a connection drop on your Postgres destination:

 2022-07-13 14:46:59 e[42mnormalizatione[0m > 14:46:13.463510 [error] [MainThread]: e[33mDatabase Error in model contact_stg (models/generated/airbyte_incremental/public/contact_stg.sql)e[0m2022-07-13 14:46:59 e[42mnormalizatione[0m > 14:46:13.472276 [error] [MainThread]: server closed the connection unexpectedly2022-07-13 14:46:59 e[42mnormalizatione[0m > 14:46:13.475089 [error] [MainThread]: This probably means the server terminated abnormally2022-07-13 14:46:59 e[42mnormalizatione[0m > 14:46:13.492811 [error] [MainThread]: before or while processing the request.2022-07-13 14:46:59 e[42mnormalizatione[0m > 14:46:13.499240 [error] [MainThread]: compiled SQL at ../build/run/airbyte_utils/models/generated/airbyte_incremental/public/contact_stg.sql2022-07-13 14:46:59 e[42mnormalizatione[0m > 14:46:13.517025 [info] [MainThread]: 2022-07-13 14:46:59 e[42mnormalizatione[0m > 14:46:13.520039 [error] [MainThread]: e[33mDatabase Error in model trhc__job__c_stg (models/generated/airbyte_incremental/public/trhc__job__c_stg.sql)e[0m2022-07-13 14:46:59 e[42mnormalizatione[0m > 14:46:13.523762 [error] [MainThread]: server closed the connection unexpectedly2022-07-13 14:46:59 e[42mnormalizatione[0m > 14:46:13.524877 [error] [MainThread]: This probably means the server terminated abnormally2022-07-13 14:46:59 e[42mnormalizatione[0m > 14:46:13.526218 [error] [MainThread]: before or while processing the request.

Could you monitor the connections and resources on your destination postgres instance to check if it is not lacking of resources or if the connection is closed for a specific reason?