Salesforce and Mongo sources failing to sync to destination

  • Is this your first time deploying Airbyte?: Yes
  • OS Version / Instance: MacOS
  • Memory / Disk: 8GB
  • Deployment: Docker (desktop).
  • Airbyte Version: 0.36.1-alpha
  • Source name/version: Mongo 0.1.13, Salesforce 1.0.3
  • Destination name/version: Snowflake 0.4.24
  • Step: This issue is happening during the sync.

Description
I am testing Airbyte for two data sources I have, Mongo and Salesforce, that need to end up in Snowflake. I have successfully synced from Mongo to Snowflake just a week or so ago, and now this sync is failing. I also added Salesforce as a source, and I am seeing the same error for that connection as well. I have normalization enabled for both connections.

The error I am seeing for both syncs is:

2022-04-20 19:23:20 INFO i.a.w.DefaultNormalizationWorker(run):71 - Normalization executed in 9 minutes 33 seconds.
2022-04-20 19:23:20 INFO i.a.w.DefaultNormalizationWorker(run):77 - Normalization summary: io.airbyte.config.NormalizationSummary@12fffda[startTime=1650482027172,endTime=1650482600780]
2022-04-20 19:23:20 INFO i.a.w.t.TemporalAttemptExecution(get):131 - Stopping cancellation check scheduling...
2022-04-20 19:23:20 INFO i.a.w.t.TemporalUtils(withBackgroundHeartbeat):235 - Stopping temporal heartbeating...
2022-04-20 19:23:21 INFO i.a.v.j.JsonSchemaValidator(test):56 - JSON schema validation failed. 
errors: $.access_token: is missing but it is required, $.refresh_token: is missing but it is required
2022-04-20 19:23:21 INFO i.a.v.j.JsonSchemaValidator(test):56 - JSON schema validation failed. 
errors: $.method: does not have a value in the enumeration [Standard]

You will notice that it says normalization is completed, yet in my Snowflake destination, the tables are empty. I will attach the full log for the Salesforce connection here.

Thank you!

logs-7.txt (993.5 KB)

Hello @ray,
Do you receive data on your raw tables? If the normalization succeeds be you don’t have data in the table it created it’s probably because you have no data in the raw table. I read in the log that recordsCommitted=0 or recordsCommitted=<null> which mean that you’re likely to not have data in the raw table.

The root cause of this problem might be related to another error I found in the log:

2022-04-20 19:12:46 e[44msourcee[0m > Caught retryable error '' after 5 tries. Waiting 80 seconds then retrying...
2022-04-20 19:12:46 e[44msourcee[0m > Giving up _send(...) after 6 tries (airbyte_cdk.sources.streams.http.exceptions.DefaultBackoffException)

It looks like your report for the ForecastingItem__hd stream can’t be generated in an appropriate amount of time (160 seconds). Could you please try to generate a report yourself with Salesforce API for this stream? If it succeeds do you mind sharing how much time it took to generate it? Feel free to reach your Salesforce support if you need help on this side!

@alafanechere

Ah, thank you so much for identifying the root cause of the Salesforce issue. That is not an object I can query in Salesforce - so it makes sense that Airbyte would break on it.

I was able to remove that from the list of objects to sync, and the sync started working.


In regards to the Mongo issue, it seems like it would be a different root cause. I’ll attach the logs here, can you tell what’s breaking? This is the error message:

2022-04-21 17:38:42 e[1;31mERRORe[m i.a.w.DefaultReplicationWorker(run):169 - Sync worker failed.
java.util.concurrent.ExecutionException: io.airbyte.workers.DefaultReplicationWorker$SourceException: Source process exited with non-zero exit code 1
	at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[?:?]
	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073) ~[?:?]
	at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:162) ~[io.airbyte-airbyte-workers-0.36.1-alpha.jar:?]
	at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:57) ~[io.airbyte-airbyte-workers-0.36.1-alpha.jar:?]
	at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:155) ~[io.airbyte-airbyte-workers-0.36.1-alpha.jar:?]
	at java.lang.Thread.run(Thread.java:833) [?:?]
	Suppressed: io.airbyte.workers.WorkerException: Source process exit with code 1. 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.36.1-alpha.jar:?]
		at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:126) ~[io.airbyte-airbyte-workers-0.36.1-alpha.jar:?]
		at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:57) ~[io.airbyte-airbyte-workers-0.36.1-alpha.jar:?]
		at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:155) ~[io.airbyte-airbyte-workers-0.36.1-alpha.jar:?]
		at java.lang.Thread.run(Thread.java:833) [?:?]
Caused by: io.airbyte.workers.DefaultReplicationWorker$SourceException: Source process exited with non-zero exit code 1
	at io.airbyte.workers.DefaultReplicationWorker.lambda$getReplicationRunnable$5(DefaultReplicationWorker.java:312) ~[io.airbyte-airbyte-workers-0.36.1-alpha.jar:?]
	at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
	... 1 more
2022-04-21 17:38:42 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):228 - sync summary: io.airbyte.config.ReplicationAttemptSummary@5b49f4ce[status=failed,recordsSynced=0,bytesSynced=0,startTime=1650562678562,endTime=1650562722776,totalStats=io.airbyte.config.SyncStats@49a11bfe[recordsEmitted=0,bytesEmitted=0,stateMessagesEmitted=0,recordsCommitted=0],streamStats=[]]
2022-04-21 17:38:42 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):250 - Source did not output any state messages
2022-04-21 17:38:42 e[33mWARNe[m i.a.w.DefaultReplicationWorker(run):258 - State capture: No new state, falling back on input state: io.airbyte.config.State@5329fd58[state={}]
2022-04-21 17:38:42 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(get):131 - Stopping cancellation check scheduling...

Logs:
logs-11 (1).txt (59.8 KB)

Best,

Ray

Ah, thank you so much for identifying the root cause of the Salesforce issue. That is not an object I can query in Salesforce - so it makes sense that Airbyte would break on it.
I was able to remove that from the list of objects to sync, and the sync started working.

Great !

In regards to the Mongo issue, it seems like it would be a different root cause. I’ll attach the logs here, can you tell what’s breaking?

I think the connector can’t connect to your Mongo DB:

2022-04-21 17:42:40 e[44msourcee[0m > 2022-04-21 17:42:40 e[32mINFOe[m c.m.d.l.SLF4JLogger(info):76 - Exception in monitor thread while connecting to server alpha-db-mongo-ro.wonscore.io:27093
2022-04-21 17:42:40 e[44msourcee[0m > com.mongodb.MongoSocketOpenException: Exception opening socket
2022-04-21 17:42:40 e[44msourcee[0m > 	at com.mongodb.internal.connection.SocketStream.open(SocketStream.java:70) ~[mongodb-driver-core-4.4.0.jar:?]
2022-04-21 17:42:40 e[44msourcee[0m > 	at com.mongodb.internal.connection.InternalStreamConnection.open(InternalStreamConnection.java:180) ~[mongodb-driver-core-4.4.0.jar:?]
2022-04-21 17:42:40 e[44msourcee[0m > 	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.lookupServerDescription(DefaultServerMonitor.java:188) [mongodb-driver-core-4.4.0.jar:?]
2022-04-21 17:42:40 e[44msourcee[0m > 	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:152) [mongodb-driver-core-4.4.0.jar:?]
2022-04-21 17:42:40 e[44msourcee[0m > 	at java.lang.Thread.run(Thread.java:833) [?:?]
2022-04-21 17:42:40 e[44msourcee[0m > Caused by: java.net.SocketTimeoutException: Connect timed out
2022-04-21 17:42:40 e[44msourcee[0m > 	at sun.nio.ch.NioSocketImpl.timedFinishConnect(NioSocketImpl.java:546) ~[?:?]
2022-04-21 17:42:40 e[44msourcee[0m > 	at sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:597) ~[?:?]
2022-04-21 17:42:40 e[44msourcee[0m > 	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327) ~[?:?]
2022-04-21 17:42:40 e[44msourcee[0m > 	at java.net.Socket.connect(Socket.java:633) ~[?:?]
2022-04-21 17:42:40 e[44msourcee[0m > 	at com.mongodb.internal.connection.SocketStreamHelper.initialize(SocketStreamHelper.java:107) ~[mongodb-driver-core-4.4.0.jar:?]
2022-04-21 17:42:40 e[44msourcee[0m > 	at com.mongodb.internal.connection.SocketStream.initializeSocket(SocketStream.java:79) ~[mongodb-driver-core-4.4.0.jar:?]
2022-04-21 17:42:40 e[44msourcee[0m > 	at com.mongodb.internal.connection.SocketStream.open(SocketStream.java:65) ~[mongodb-driver-core-4.4.0.jar:?]
2022-04-21 17:42:40 e[44msourcee[0m > 	... 4 more

Can you check if the Mongo database is reachable from the network in which your Airbyte instance is running? Could you also please check if SSL is enabled or not on the source database and update your configuration settings accordingly (TLS connection)?