Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

LinkedIn Ads Source hangs after preparing tmp Tables #7206

Closed
tinomerl opened this issue Oct 20, 2021 · 8 comments · Fixed by #8382
Closed

LinkedIn Ads Source hangs after preparing tmp Tables #7206

tinomerl opened this issue Oct 20, 2021 · 8 comments · Fixed by #8382
Assignees
@annalvova05
Labels
area/connectors Connector related issues community connectors/source/linkedin-ads connectors/sources-api type/bug Something isn't working

Comments

@tinomerl
Copy link
Contributor

tinomerl commented Oct 20, 2021 •
edited
Loading

Enviroment

  • Airbyte version: 0.30.20-alpha
  • OS Version / Instance: Ubuntu 20.04
  • Deployment: Docker
  • Source Connector and version: LinkedIn Ads 0.1.4
  • Destination Connector and version: Postgres 0.3.11
  • Severity: High
  • Step where error happened: Sync job

Current Behavior

When replicating data from LinkedIn Ads to Postgres the tmp tables will be prepared but afterwards nothing happens. The Sync Job hangs and won't call any data. After some time a retryable Error is caught.

Expected Behavior

Data from LinkedIn should be replicated.

I tested different sources to exclude it's because of the deployment. I also tested with LinkedIn as a source and other destinations. No change in behaviour. Also tested in two different environments.

Logs

LinkedIn Ads to Postgres 
2021-10-20 07:28:39 INFO () WorkerRun(call):47 - Executing worker wrapper. Airbyte version: 0.30.20-alpha
2021-10-20 07:28:41 INFO () TemporalAttemptExecution(get):94 - Executing worker wrapper. Airbyte version: 0.30.20-alpha
2021-10-20 07:28:41 WARN () Databases(createPostgresDatabaseWithRetry):38 - Waiting for database to become available...
2021-10-20 07:28:41 INFO () JobsDatabaseInstance(lambda$static$2):25 - Testing if jobs database is ready...
2021-10-20 07:28:41 INFO () Databases(createPostgresDatabaseWithRetry):55 - Database available!
2021-10-20 07:28:41 INFO () DefaultReplicationWorker(run):82 - start sync worker. job id: 35 attempt id: 1
2021-10-20 07:28:41 INFO () DefaultReplicationWorker(run):91 - configured sync modes: {null.ad_creative_analytics=full_refresh - append, null.ad_campaign_analytics=full_refresh - append}
2021-10-20 07:28:41 INFO () DefaultAirbyteDestination(start):58 - Running destination...
2021-10-20 07:28:42 INFO () LineGobbler(voidCall):65 - Checking if airbyte/destination-postgres:0.3.11 exists...
2021-10-20 07:28:42 INFO () LineGobbler(voidCall):65 - airbyte/destination-postgres:0.3.11 was found locally.
2021-10-20 07:28:42 INFO () DockerProcessFactory(create):127 - Preparing command: docker run --rm --init -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/35/1 --network host --log-driver none airbyte/destination-postgres:0.3.11 write --config destination_config.json --catalog destination_catalog.json
2021-10-20 07:28:42 INFO () LineGobbler(voidCall):65 - Checking if airbyte/source-linkedin-ads:0.1.1 exists...
2021-10-20 07:28:42 INFO () LineGobbler(voidCall):65 - airbyte/source-linkedin-ads:0.1.1 was found locally.
2021-10-20 07:28:42 INFO () DockerProcessFactory(create):127 - Preparing command: docker run --rm --init -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/35/1 --network host --log-driver none airbyte/source-linkedin-ads:0.1.1 read --config source_config.json --catalog source_catalog.json
2021-10-20 07:28:42 INFO () DefaultReplicationWorker(lambda$getDestinationOutputRunnable$3):226 - Destination output thread started.
2021-10-20 07:28:42 INFO () DefaultReplicationWorker(run):119 - Waiting for source thread to join.
2021-10-20 07:28:42 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):190 - Replication thread started.
2021-10-20 07:29:11 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:11 �[32mINFO�[m i.a.i.d.p.PostgresDestination(main):85 - {} - starting destination: class io.airbyte.integrations.destination.postgres.PostgresDestination
2021-10-20 07:29:12 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:12 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):96 - {} - Running integration: io.airbyte.integrations.base.ssh.SshWrappedDestination
2021-10-20 07:29:13 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:12 �[32mINFO�[m i.a.i.b.IntegrationCliParser(parseOptions):135 - {} - integration args: {catalog=destination_catalog.json, write=null, config=destination_config.json}
2021-10-20 07:29:13 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:12 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):100 - {} - Command: WRITE
2021-10-20 07:29:13 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:13 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):101 - {} - Integration config: IntegrationConfig{command=WRITE, configPath='destination_config.json', catalogPath='destination_catalog.json', statePath='null'}
2021-10-20 07:29:13 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:13 �[33mWARN�[m c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword order - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-20 07:29:13 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:13 �[33mWARN�[m c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword examples - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-20 07:29:13 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:13 �[33mWARN�[m c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword airbyte_secret - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-20 07:29:13 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:13 �[33mWARN�[m c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword multiline - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-20 07:29:15 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:15 �[32mINFO�[m i.a.i.b.s.SshTunnel(getInstance):190 - {} - Starting connection with method: NO_TUNNEL
2021-10-20 07:29:15 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:15 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$toWriteConfig$0):116 - {} - Write config: WriteConfig{streamName=item_de-linkedin-ad_campaign_analytics, namespace=null, outputSchemaName=staging, tmpTableName=_airbyte_tmp_ojl_item_de_linkedin_ad_campaign_analytics, outputTableName=_airbyte_raw_item_de_linkedin_ad_campaign_analytics, syncMode=append}
2021-10-20 07:29:15 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:15 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$toWriteConfig$0):116 - {} - Write config: WriteConfig{streamName=item_de-linkedin-ad_creative_analytics, namespace=null, outputSchemaName=staging, tmpTableName=_airbyte_tmp_rcg_item_de_linkedin_ad_creative_analytics, outputTableName=_airbyte_raw_item_de_linkedin_ad_creative_analytics, syncMode=append}
2021-10-20 07:29:16 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:16 �[32mINFO�[m i.a.i.d.b.BufferedStreamConsumer(startTracked):143 - {} - class io.airbyte.integrations.destination.buffered_stream_consumer.BufferedStreamConsumer started.
2021-10-20 07:29:16 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:16 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):139 - {} - Preparing tmp tables in destination started for 2 streams
2021-10-20 07:29:16 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:16 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):143 - {} - Preparing tmp table in destination started for stream item_de-linkedin-ad_campaign_analytics. schema: staging, tmp table name: _airbyte_tmp_ojl_item_de_linkedin_ad_campaign_analytics
2021-10-20 07:29:17 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:17 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):143 - {} - Preparing tmp table in destination started for stream item_de-linkedin-ad_creative_analytics. schema: staging, tmp table name: _airbyte_tmp_rcg_item_de_linkedin_ad_creative_analytics
2021-10-20 07:29:17 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:17 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):149 - {} - Preparing tables in destination completed.
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Starting syncing SourceLinkedinAds
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Syncing stream: ad_campaign_analytics 
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:45 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
LinkedIn 0.1.4 to Postgres 
2021-12-02 14:56:48 INFO () WorkerRun(call):47 - Executing worker wrapper. Airbyte version: 0.30.20-alpha
2021-12-02 14:56:49 INFO () TemporalAttemptExecution(get):94 - Executing worker wrapper. Airbyte version: 0.30.20-alpha
2021-12-02 14:56:49 WARN () Databases(createPostgresDatabaseWithRetry):38 - Waiting for database to become available...
2021-12-02 14:56:49 INFO () JobsDatabaseInstance(lambda$static$2):25 - Testing if jobs database is ready...
2021-12-02 14:56:49 INFO () Databases(createPostgresDatabaseWithRetry):55 - Database available!
2021-12-02 14:56:49 INFO () DefaultReplicationWorker(run):82 - start sync worker. job id: 55 attempt id: 0
2021-12-02 14:56:49 INFO () DefaultReplicationWorker(run):91 - configured sync modes: {null.ad_creative_analytics=full_refresh - append, null.ad_campaign_analytics=full_refresh - append}
2021-12-02 14:56:49 INFO () DefaultAirbyteDestination(start):58 - Running destination...
2021-12-02 14:56:49 INFO () LineGobbler(voidCall):65 - Checking if airbyte/destination-postgres:0.3.12 exists...
2021-12-02 14:56:49 INFO () LineGobbler(voidCall):65 - airbyte/destination-postgres:0.3.12 was found locally.
2021-12-02 14:56:49 INFO () DockerProcessFactory(create):127 - Preparing command: docker run --rm --init -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/55/0 --network host --log-driver none airbyte/destination-postgres:0.3.12 write --config destination_config.json --catalog destination_catalog.json
2021-12-02 14:56:49 INFO () LineGobbler(voidCall):65 - Checking if airbyte/source-linkedin-ads:0.1.4 exists...
2021-12-02 14:56:49 INFO () LineGobbler(voidCall):65 - airbyte/source-linkedin-ads:0.1.4 was found locally.
2021-12-02 14:56:49 INFO () DockerProcessFactory(create):127 - Preparing command: docker run --rm --init -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/55/0 --network host --log-driver none airbyte/source-linkedin-ads:0.1.4 read --config source_config.json --catalog source_catalog.json --state input_state.json
2021-12-02 14:56:49 INFO () DefaultReplicationWorker(run):119 - Waiting for source thread to join.
2021-12-02 14:56:49 INFO () DefaultReplicationWorker(lambda$getDestinationOutputRunnable$3):226 - Destination output thread started.
2021-12-02 14:56:49 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):190 - Replication thread started.
2021-12-02 14:57:12 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Starting syncing SourceLinkedinAds
2021-12-02 14:57:12 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Syncing stream: ad_campaign_analytics 
2021-12-02 14:57:16 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:16 �[32mINFO�[m i.a.i.d.p.PostgresDestination(main):69 - {} - starting destination: class io.airbyte.integrations.destination.postgres.PostgresDestination
2021-12-02 14:57:17 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:17 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):76 - {} - Running integration: io.airbyte.integrations.base.ssh.SshWrappedDestination
2021-12-02 14:57:17 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:17 �[32mINFO�[m i.a.i.b.IntegrationCliParser(parseOptions):118 - {} - integration args: {catalog=destination_catalog.json, write=null, config=destination_config.json}
2021-12-02 14:57:17 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:17 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):80 - {} - Command: WRITE
2021-12-02 14:57:17 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:17 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):81 - {} - Integration config: IntegrationConfig{command=WRITE, configPath='destination_config.json', catalogPath='destination_catalog.json', statePath='null'}
2021-12-02 14:57:18 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:18 �[33mWARN�[m c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword order - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-12-02 14:57:18 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:18 �[33mWARN�[m c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword examples - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-12-02 14:57:18 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:18 �[33mWARN�[m c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword airbyte_secret - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-12-02 14:57:18 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:18 �[33mWARN�[m c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword multiline - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-12-02 14:57:19 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:19 �[32mINFO�[m i.a.i.b.s.SshTunnel(getInstance):170 - {} - Starting connection with method: NO_TUNNEL
2021-12-02 14:57:20 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:20 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$toWriteConfig$0):96 - {} - Write config: WriteConfig{streamName=item_de-linkedin-ad_campaign_analytics, namespace=null, outputSchemaName=staging, tmpTableName=_airbyte_tmp_qip_item_de_linkedin_ad_campaign_analytics, outputTableName=_airbyte_raw_item_de_linkedin_ad_campaign_analytics, syncMode=append}
2021-12-02 14:57:20 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:20 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$toWriteConfig$0):96 - {} - Write config: WriteConfig{streamName=item_de-linkedin-ad_creative_analytics, namespace=null, outputSchemaName=staging, tmpTableName=_airbyte_tmp_fhi_item_de_linkedin_ad_creative_analytics, outputTableName=_airbyte_raw_item_de_linkedin_ad_creative_analytics, syncMode=append}
2021-12-02 14:57:20 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:20 �[32mINFO�[m i.a.i.d.b.BufferedStreamConsumer(startTracked):124 - {} - class io.airbyte.integrations.destination.buffered_stream_consumer.BufferedStreamConsumer started.
2021-12-02 14:57:20 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:20 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):121 - {} - Preparing tmp tables in destination started for 2 streams
2021-12-02 14:57:20 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:20 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):125 - {} - Preparing tmp table in destination started for stream item_de-linkedin-ad_campaign_analytics. schema: staging, tmp table name: _airbyte_tmp_qip_item_de_linkedin_ad_campaign_analytics
2021-12-02 14:57:21 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:21 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):125 - {} - Preparing tmp table in destination started for stream item_de-linkedin-ad_creative_analytics. schema: staging, tmp table name: _airbyte_tmp_fhi_item_de_linkedin_ad_creative_analytics
2021-12-02 14:57:21 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 14:57:21 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):131 - {} - Preparing tables in destination completed.
2021-12-02 15:28:01 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):203 - Records read: 1000
2021-12-02 15:30:19 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Read 1180 records from ad_campaign_analytics stream
2021-12-02 15:30:19 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Syncing stream: ad_creative_analytics 
2021-12-02 16:30:32 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):203 - Records read: 2000
2021-12-02 16:49:55 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):203 - Records read: 3000
2021-12-02 17:00:07 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Read 2604 records from ad_creative_analytics stream
2021-12-02 17:00:07 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Finished syncing SourceLinkedinAds
2021-12-02 17:00:20 INFO () DefaultReplicationWorker(run):121 - Source thread complete.
2021-12-02 17:00:20 INFO () DefaultReplicationWorker(run):122 - Waiting for destination thread to join.
2021-12-02 17:00:20 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 17:00:20 �[32mINFO�[m i.a.i.b.FailureTrackingAirbyteMessageConsumer(close):60 - {} - Airbyte message consumer: succeeded.
2021-12-02 17:00:20 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 17:00:20 �[32mINFO�[m i.a.i.d.b.BufferedStreamConsumer(close):199 - {} - executing on success close procedure.
2021-12-02 17:00:29 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 17:00:29 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):160 - {} - Finalizing tables in destination started for 2 streams
2021-12-02 17:00:29 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 17:00:29 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):165 - {} - Finalizing stream item_de-linkedin-ad_campaign_analytics. schema staging, tmp table _airbyte_tmp_qip_item_de_linkedin_ad_campaign_analytics, final table _airbyte_raw_item_de_linkedin_ad_campaign_analytics
2021-12-02 17:00:29 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 17:00:29 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):165 - {} - Finalizing stream item_de-linkedin-ad_creative_analytics. schema staging, tmp table _airbyte_tmp_fhi_item_de_linkedin_ad_creative_analytics, final table _airbyte_raw_item_de_linkedin_ad_creative_analytics
2021-12-02 17:00:29 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 17:00:29 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):178 - {} - Executing finalization of tables.
2021-12-02 17:00:29 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 17:00:29 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):180 - {} - Finalizing tables in destination completed.
2021-12-02 17:00:29 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 17:00:29 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):183 - {} - Cleaning tmp tables in destination started for 2 streams
2021-12-02 17:00:29 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 17:00:29 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):187 - {} - Cleaning tmp table in destination started for stream item_de-linkedin-ad_campaign_analytics. schema staging, tmp table name: _airbyte_tmp_qip_item_de_linkedin_ad_campaign_analytics
2021-12-02 17:00:29 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 17:00:29 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):187 - {} - Cleaning tmp table in destination started for stream item_de-linkedin-ad_creative_analytics. schema staging, tmp table name: _airbyte_tmp_fhi_item_de_linkedin_ad_creative_analytics
2021-12-02 17:00:31 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 17:00:31 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):192 - {} - Cleaning tmp tables in destination completed.
2021-12-02 17:00:31 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 17:00:31 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):133 - {} - Completed integration: io.airbyte.integrations.base.ssh.SshWrappedDestination
2021-12-02 17:00:31 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-12-02 17:00:31 �[32mINFO�[m i.a.i.d.p.PostgresDestination(main):71 - {} - completed destination: class io.airbyte.integrations.destination.postgres.PostgresDestination
2021-12-02 17:00:39 INFO () DefaultReplicationWorker(run):124 - Destination thread complete.
2021-12-02 17:00:39 INFO () DefaultReplicationWorker(run):152 - sync summary: io.airbyte.config.ReplicationAttemptSummary@50574948[status=completed,recordsSynced=3784,bytesSynced=4484567,startTime=1638457009506,endTime=1638464439586]
2021-12-02 17:00:39 INFO () DefaultReplicationWorker(run):161 - Source did not output any state messages
2021-12-02 17:00:39 WARN () DefaultReplicationWorker(run):169 - State capture: No new state, falling back on input state: io.airbyte.config.State@3a4f212[state={}]
2021-12-02 17:00:39 INFO () TemporalAttemptExecution(get):115 - Stopping cancellation check scheduling...
2021-12-02 17:00:39 INFO () SyncWorkflow$ReplicationActivityImpl(replicate):178 - sync summary: io.airbyte.config.StandardSyncOutput@6e12de2b[standardSyncSummary=io.airbyte.config.StandardSyncSummary@691aa87b[status=completed,recordsSynced=3784,bytesSynced=4484567,startTime=1638457009506,endTime=1638464439586],state=io.airbyte.config.State@3a4f212[state={}],outputCatalog=io.airbyte.protocol.models.ConfiguredAirbyteCatalog@635dae37[streams=[io.airbyte.protocol.models.ConfiguredAirbyteStream@1b254a70[stream=io.airbyte.protocol.models.AirbyteStream@633e3cb9[name=item_de-linkedin-ad_campaign_analytics,jsonSchema={"type":["null","object"],"properties":{"likes":{"type":["null","number"]},"opens":{"type":["null","number"]},"pivot":{"type":["null","string"]},"sends":{"type":["null","number"]},"clicks":{"type":["null","number"]},"shares":{"type":["null","number"]},"follows":{"type":["null","number"]},"comments":{"type":["null","number"]},"end_date":{"type":["null","string"],"format":"date"},"costInUsd":{"type":["null","string"]},"reactions":{"type":["null","number"]},"pivotValue":{"type":["null","string"]},"start_date":{"type":["null","string"],"format":"date"},"videoViews":{"type":["null","number"]},"viralLikes":{"type":["null","number"]},"impressions":{"type":["null","number"]},"pivotValues":{"type":["null","array"],"items":{"type":["null","string"]}},"videoStarts":{"type":["null","number"]},"viralClicks":{"type":["null","number"]},"viralShares":{"type":["null","number"]},"actionClicks":{"type":["null","number"]},"adUnitClicks":{"type":["null","number"]},"viralFollows":{"type":["null","number"]},"oneClickLeads":{"type":["null","number"]},"textUrlClicks":{"type":["null","number"]},"viralComments":{"type":["null","number"]},"viralReactions":{"type":["null","number"]},"fullScreenPlays":{"type":["null","number"]},"viralVideoViews":{"type":["null","number"]},"otherEngagements":{"type":["null","number"]},"totalEngagements":{"type":["null","number"]},"videoCompletions":{"type":["null","number"]},"viralImpressions":{"type":["null","number"]},"viralVideoStarts":{"type":["null","number"]},"companyPageClicks":{"type":["null","number"]},"landingPageClicks":{"type":["null","number"]},"viralCommentLikes":{"type":["null","number"]},"viralOneClickLeads":{"type":["null","number"]},"costInLocalCurrency":{"type":["null","string"]},"viralFullScreenPlays":{"type":["null","number"]},"oneClickLeadFormOpens":{"type":["null","number"]},"viralOtherEngagements":{"type":["null","number"]},"viralTotalEngagements":{"type":["null","number"]},"viralVideoCompletions":{"type":["null","number"]},"viralCompanyPageClicks":{"type":["null","number"]},"viralLandingPageClicks":{"type":["null","number"]},"videoMidpointCompletions":{"type":["null","number"]},"externalWebsiteConversions":{"type":["null","number"]},"viralOneClickLeadFormOpens":{"type":["null","number"]},"videoFirstQuartileCompletions":{"type":["null","number"]},"videoThirdQuartileCompletions":{"type":["null","number"]},"viralVideoMidpointCompletions":{"type":["null","number"]},"conversionValueInLocalCurrency":{"type":["null","string"]},"viralExternalWebsiteConversions":{"type":["null","number"]},"externalWebsitePostViewConversions":{"type":["null","number"]},"leadGenerationMailInterestedClicks":{"type":["null","number"]},"viralVideoFirstQuartileCompletions":{"type":["null","number"]},"viralVideoThirdQuartileCompletions":{"type":["null","number"]},"externalWebsitePostClickConversions":{"type":["null","number"]},"leadGenerationMailContactInfoShares":{"type":["null","number"]},"viralExternalWebsitePostViewConversions":{"type":["null","number"]},"viralExternalWebsitePostClickConversions":{"type":["null","number"]}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=true,defaultCursorField=[end_date],sourceDefinedPrimaryKey=[[pivotValue], [end_date]],namespace=<null>,additionalProperties={}],syncMode=full_refresh,cursorField=[end_date],destinationSyncMode=append,primaryKey=[[pivotValue], [end_date]],additionalProperties={}], io.airbyte.protocol.models.ConfiguredAirbyteStream@5fdb19d5[stream=io.airbyte.protocol.models.AirbyteStream@5179380f[name=item_de-linkedin-ad_creative_analytics,jsonSchema={"type":["null","object"],"properties":{"likes":{"type":["null","number"]},"opens":{"type":["null","number"]},"pivot":{"type":["null","string"]},"sends":{"type":["null","number"]},"clicks":{"type":["null","number"]},"shares":{"type":["null","number"]},"follows":{"type":["null","number"]},"comments":{"type":["null","number"]},"end_date":{"type":["null","string"],"format":"date"},"costInUsd":{"type":["null","string"]},"reactions":{"type":["null","number"]},"pivotValue":{"type":["null","string"]},"start_date":{"type":["null","string"],"format":"date"},"videoViews":{"type":["null","number"]},"viralLikes":{"type":["null","number"]},"impressions":{"type":["null","number"]},"pivotValues":{"type":["null","array"],"items":{"type":["null","string"]}},"videoStarts":{"type":["null","number"]},"viralClicks":{"type":["null","number"]},"viralShares":{"type":["null","number"]},"actionClicks":{"type":["null","number"]},"adUnitClicks":{"type":["null","number"]},"viralFollows":{"type":["null","number"]},"oneClickLeads":{"type":["null","number"]},"textUrlClicks":{"type":["null","number"]},"viralComments":{"type":["null","number"]},"viralReactions":{"type":["null","number"]},"fullScreenPlays":{"type":["null","number"]},"viralVideoViews":{"type":["null","number"]},"otherEngagements":{"type":["null","number"]},"totalEngagements":{"type":["null","number"]},"videoCompletions":{"type":["null","number"]},"viralImpressions":{"type":["null","number"]},"viralVideoStarts":{"type":["null","number"]},"companyPageClicks":{"type":["null","number"]},"landingPageClicks":{"type":["null","number"]},"viralCommentLikes":{"type":["null","number"]},"viralOneClickLeads":{"type":["null","number"]},"costInLocalCurrency":{"type":["null","string"]},"viralFullScreenPlays":{"type":["null","number"]},"oneClickLeadFormOpens":{"type":["null","number"]},"viralOtherEngagements":{"type":["null","number"]},"viralTotalEngagements":{"type":["null","number"]},"viralVideoCompletions":{"type":["null","number"]},"viralCompanyPageClicks":{"type":["null","number"]},"viralLandingPageClicks":{"type":["null","number"]},"videoMidpointCompletions":{"type":["null","number"]},"externalWebsiteConversions":{"type":["null","number"]},"viralOneClickLeadFormOpens":{"type":["null","number"]},"videoFirstQuartileCompletions":{"type":["null","number"]},"videoThirdQuartileCompletions":{"type":["null","number"]},"viralVideoMidpointCompletions":{"type":["null","number"]},"conversionValueInLocalCurrency":{"type":["null","string"]},"viralExternalWebsiteConversions":{"type":["null","number"]},"externalWebsitePostViewConversions":{"type":["null","number"]},"leadGenerationMailInterestedClicks":{"type":["null","number"]},"viralVideoFirstQuartileCompletions":{"type":["null","number"]},"viralVideoThirdQuartileCompletions":{"type":["null","number"]},"externalWebsitePostClickConversions":{"type":["null","number"]},"leadGenerationMailContactInfoShares":{"type":["null","number"]},"viralExternalWebsitePostViewConversions":{"type":["null","number"]},"viralExternalWebsitePostClickConversions":{"type":["null","number"]}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=true,defaultCursorField=[end_date],sourceDefinedPrimaryKey=[[pivotValue], [end_date]],namespace=<null>,additionalProperties={}],syncMode=full_refresh,cursorField=[end_date],destinationSyncMode=append,primaryKey=[[pivotValue], [end_date]],additionalProperties={}]],additionalProperties={}]]
2021-12-02 17:00:41 INFO () TemporalAttemptExecution(get):94 - Executing worker wrapper. Airbyte version: 0.30.20-alpha
2021-12-02 17:00:41 WARN () Databases(createPostgresDatabaseWithRetry):38 - Waiting for database to become available...
2021-12-02 17:00:41 INFO () JobsDatabaseInstance(lambda$static$2):25 - Testing if jobs database is ready...
2021-12-02 17:00:41 INFO () Databases(createPostgresDatabaseWithRetry):55 - Database available!
2021-12-02 17:00:42 INFO () DefaultNormalizationWorker(run):46 - Running normalization.
2021-12-02 17:00:42 INFO () DefaultNormalizationRunner(runProcess):107 - Running with normalization version: airbyte/normalization:0.1.52
2021-12-02 17:00:44 INFO () LineGobbler(voidCall):65 - Checking if airbyte/normalization:0.1.52 exists...
2021-12-02 17:00:44 INFO () LineGobbler(voidCall):65 - airbyte/normalization:0.1.52 was found locally.
2021-12-02 17:00:44 INFO () DockerProcessFactory(create):127 - Preparing command: docker run --rm --init -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/55/0/normalize --network host --log-driver none airbyte/normalization:0.1.52 run --integration-type postgres --config destination_config.json --catalog destination_catalog.json
2021-12-02 17:00:53 INFO () LineGobbler(voidCall):65 - Running: transform-config --config destination_config.json --integration-type postgres --out /data/55/0/normalize
2021-12-02 17:01:02 INFO () LineGobbler(voidCall):65 - Namespace(config='destination_config.json', integration_type=<DestinationType.postgres: 'postgres'>, out='/data/55/0/normalize')
2021-12-02 17:01:02 INFO () LineGobbler(voidCall):65 - transform_postgres
2021-12-02 17:01:02 INFO () LineGobbler(voidCall):65 - Running: transform-catalog --integration-type postgres --profile-config-dir /data/55/0/normalize --catalog destination_catalog.json --out /data/55/0/normalize/models/generated/ --json-column _airbyte_data
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 - Processing destination_catalog.json...
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 - Truncating item_de_linkedin_ad_campaign_analytics_pivotValues (#50) to item_de_linkedin_ad__analytics_pivotValues (#43)
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 - Truncating item_de_linkedin_ad_creative_analytics_pivotValues (#50) to item_de_linkedin_ad__analytics_pivotValues (#43)
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 - WARN: Resolving conflict: staging.item_de_linkedin_ad___analytics_pivotvalues from 'item_de-linkedin-ad_campaign_analytics.pivotValues' into item_de_linkedin_ad_campaig_f30_pivotvalues
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 - WARN: Resolving conflict: staging.item_de_linkedin_ad___analytics_pivotvalues from 'item_de-linkedin-ad_creative_analytics.pivotValues' into item_de_linkedin_ad_creativ_4c3_pivotvalues
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 -   Generating airbyte_ctes/staging/item_de_linkedin_ad_campaign_analytics_ab1.sql from item_de-linkedin-ad_campaign_analytics
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 -   Generating airbyte_ctes/staging/item_de_linkedin_ad_campaign_analytics_ab2.sql from item_de-linkedin-ad_campaign_analytics
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 - Truncating _airbyte_item_de_linkedin_ad_campaign_analytics_hashid (#54) to _airbyte_item_de_lin_aign_analytics_hashid (#43)
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 -   Generating airbyte_ctes/staging/item_de_linkedin_ad_campaign_analytics_ab3.sql from item_de-linkedin-ad_campaign_analytics
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 - Truncating _airbyte_item_de_linkedin_ad_campaign_analytics_hashid (#54) to _airbyte_item_de_lin_aign_analytics_hashid (#43)
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 -   Generating airbyte_tables/staging/item_de_linkedin_ad_campaign_analytics.sql from item_de-linkedin-ad_campaign_analytics
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 -   Generating airbyte_ctes/staging/item_de_linkedin_ad_creative_analytics_ab1.sql from item_de-linkedin-ad_creative_analytics
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 -   Generating airbyte_ctes/staging/item_de_linkedin_ad_creative_analytics_ab2.sql from item_de-linkedin-ad_creative_analytics
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 - Truncating _airbyte_item_de_linkedin_ad_creative_analytics_hashid (#54) to _airbyte_item_de_lin_tive_analytics_hashid (#43)
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 -   Generating airbyte_ctes/staging/item_de_linkedin_ad_creative_analytics_ab3.sql from item_de-linkedin-ad_creative_analytics
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 - Truncating _airbyte_item_de_linkedin_ad_creative_analytics_hashid (#54) to _airbyte_item_de_lin_tive_analytics_hashid (#43)
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 -   Generating airbyte_tables/staging/item_de_linkedin_ad_creative_analytics.sql from item_de-linkedin-ad_creative_analytics
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 -   Ignoring stream 'pivotValues' from item_de-linkedin-ad_campaign_analytics/pivotValues because properties list is empty
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 -   Ignoring stream 'pivotValues' from item_de-linkedin-ad_creative_analytics/pivotValues because properties list is empty
2021-12-02 17:01:03 INFO () LineGobbler(voidCall):65 - detected no config file for ssh, assuming ssh is off.
2021-12-02 17:01:19 INFO () LineGobbler(voidCall):65 - Running with dbt=0.19.0
2021-12-02 17:01:28 INFO () LineGobbler(voidCall):65 - [�[33mWARNING�[0m]: Configuration paths exist in your dbt_project.yml file which do not apply to any resources.
2021-12-02 17:01:28 INFO () LineGobbler(voidCall):65 - There are 1 unused configuration paths:
2021-12-02 17:01:28 INFO () LineGobbler(voidCall):65 - - models.airbyte_utils.generated.airbyte_views
2021-12-02 17:01:28 INFO () LineGobbler(voidCall):65 - 
2021-12-02 17:01:28 INFO () LineGobbler(voidCall):65 - Found 8 models, 0 tests, 0 snapshots, 0 analyses, 422 macros, 0 operations, 0 seed files, 2 sources, 0 exposures
2021-12-02 17:01:28 INFO () LineGobbler(voidCall):65 - 
2021-12-02 17:01:29 INFO () LineGobbler(voidCall):65 - 17:01:29 | Concurrency: 32 threads (target='prod')
2021-12-02 17:01:29 INFO () LineGobbler(voidCall):65 - 17:01:29 | 
2021-12-02 17:01:31 INFO () LineGobbler(voidCall):65 - 17:01:31 | 1 of 2 START table model staging.item_de_linkedin_ad_campaign_analytics...................................... [RUN]
2021-12-02 17:01:31 INFO () LineGobbler(voidCall):65 - 17:01:31 | 2 of 2 START table model staging.item_de_linkedin_ad_creative_analytics...................................... [RUN]
2021-12-02 17:01:33 INFO () LineGobbler(voidCall):65 - 17:01:33 | 2 of 2 OK created table model staging.item_de_linkedin_ad_creative_analytics................................. [�[32mSELECT 2604�[0m in 1.88s]
2021-12-02 17:01:33 INFO () LineGobbler(voidCall):65 - 17:01:33 | 1 of 2 OK created table model staging.item_de_linkedin_ad_campaign_analytics................................. [�[32mSELECT 1180�[0m in 1.94s]
2021-12-02 17:01:33 INFO () LineGobbler(voidCall):65 - 17:01:33 | 
2021-12-02 17:01:33 INFO () LineGobbler(voidCall):65 - 17:01:33 | Finished running 2 table models in 4.52s.
2021-12-02 17:01:33 INFO () LineGobbler(voidCall):65 - 
2021-12-02 17:01:33 INFO () LineGobbler(voidCall):65 - �[32mCompleted successfully�[0m
2021-12-02 17:01:33 INFO () LineGobbler(voidCall):65 - 
2021-12-02 17:01:33 INFO () LineGobbler(voidCall):65 - Done. PASS=2 WARN=0 ERROR=0 SKIP=0 TOTAL=2
2021-12-02 17:01:47 INFO () DefaultNormalizationWorker(run):69 - Normalization executed in 1 minute 4 seconds.
2021-12-02 17:01:47 INFO () TemporalAttemptExecution(get):115 - Stopping cancellation check scheduling...

Steps to Reproduce

  1. Setup LinkedIn Ads Source
  2. Setup Postgres Destination
  3. Try to replicate data.

Acceptance Criteria

  1. Find root cause and publish a fix
  2. Fix the log message Caught retryable error '' which doesn't tell us what the actual error was

Are you willing to submit a PR?

Yes
@tinomerl tinomerl added the type/bug Something isn't working label Oct 20, 2021
@tinomerl
Copy link
Contributor Author

tinomerl commented Oct 21, 2021 •
edited
Loading

i tested the source and the docker image for it locally. the issue doesn't seem to be in the source connector.

for the testing i created a config.json with the credentials and tested the docker container as explained here under Run the source using docker. so i get data passed back from the source when running only the main.py with read but also from the docker source container running with read.

Edit:
I'm currently out of ideas and don't know where to look further. Could anyone help me out? This is a dealbreaker for using the source.

@sherifnada sherifnada added the area/connectors Connector related issues label Nov 15, 2021
@sherifnada
Copy link
Contributor

@tinomerl apologies for the late response here! will look into this and understand the root cause soon. Are you open to sharing the full job logs with us by downloading it from the UI?

@tinomerl
Copy link
Contributor Author

@sherifnada thanks for the reply! i added some logs specific for this source and destination in the issue when i opened it under LinkedIn Ads to Postgres. do you need more than that? if so i can export the whole scheduler log or are the server logs better?

@sherifnada
Copy link
Contributor

@tinomerl would you be able to share the full logs? specifically i'm unable to tell how this job terminated -- was it cancelled manually or failed on its own?

@tinomerl
Copy link
Contributor Author

@sherifnada i cancelled the job manually after the message Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...

Before that it ran for almost 20 Minutes without syncing any data. i attached the whole log. Is this sufficient?

Full Logs 
2021-10-20 07:28:39 INFO () WorkerRun(call):47 - Executing worker wrapper. Airbyte version: 0.30.20-alpha
2021-10-20 07:28:41 INFO () TemporalAttemptExecution(get):94 - Executing worker wrapper. Airbyte version: 0.30.20-alpha
2021-10-20 07:28:41 WARN () Databases(createPostgresDatabaseWithRetry):38 - Waiting for database to become available...
2021-10-20 07:28:41 INFO () JobsDatabaseInstance(lambda$static$2):25 - Testing if jobs database is ready...
2021-10-20 07:28:41 INFO () Databases(createPostgresDatabaseWithRetry):55 - Database available!
2021-10-20 07:28:41 INFO () DefaultReplicationWorker(run):82 - start sync worker. job id: 35 attempt id: 1
2021-10-20 07:28:41 INFO () DefaultReplicationWorker(run):91 - configured sync modes: {null.ad_creative_analytics=full_refresh - append, null.ad_campaign_analytics=full_refresh - append}
2021-10-20 07:28:41 INFO () DefaultAirbyteDestination(start):58 - Running destination...
2021-10-20 07:28:42 INFO () LineGobbler(voidCall):65 - Checking if airbyte/destination-postgres:0.3.11 exists...
2021-10-20 07:28:42 INFO () LineGobbler(voidCall):65 - airbyte/destination-postgres:0.3.11 was found locally.
2021-10-20 07:28:42 INFO () DockerProcessFactory(create):127 - Preparing command: docker run --rm --init -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/35/1 --network host --log-driver none airbyte/destination-postgres:0.3.11 write --config destination_config.json --catalog destination_catalog.json
2021-10-20 07:28:42 INFO () LineGobbler(voidCall):65 - Checking if airbyte/source-linkedin-ads:0.1.1 exists...
2021-10-20 07:28:42 INFO () LineGobbler(voidCall):65 - airbyte/source-linkedin-ads:0.1.1 was found locally.
2021-10-20 07:28:42 INFO () DockerProcessFactory(create):127 - Preparing command: docker run --rm --init -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/35/1 --network host --log-driver none airbyte/source-linkedin-ads:0.1.1 read --config source_config.json --catalog source_catalog.json
2021-10-20 07:28:42 INFO () DefaultReplicationWorker(lambda$getDestinationOutputRunnable$3):226 - Destination output thread started.
2021-10-20 07:28:42 INFO () DefaultReplicationWorker(run):119 - Waiting for source thread to join.
2021-10-20 07:28:42 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):190 - Replication thread started.
2021-10-20 07:29:11 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:11 �[32mINFO�[m i.a.i.d.p.PostgresDestination(main):85 - {} - starting destination: class io.airbyte.integrations.destination.postgres.PostgresDestination
2021-10-20 07:29:12 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:12 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):96 - {} - Running integration: io.airbyte.integrations.base.ssh.SshWrappedDestination
2021-10-20 07:29:13 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:12 �[32mINFO�[m i.a.i.b.IntegrationCliParser(parseOptions):135 - {} - integration args: {catalog=destination_catalog.json, write=null, config=destination_config.json}
2021-10-20 07:29:13 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:12 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):100 - {} - Command: WRITE
2021-10-20 07:29:13 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:13 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):101 - {} - Integration config: IntegrationConfig{command=WRITE, configPath='destination_config.json', catalogPath='destination_catalog.json', statePath='null'}
2021-10-20 07:29:13 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:13 �[33mWARN�[m c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword order - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-20 07:29:13 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:13 �[33mWARN�[m c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword examples - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-20 07:29:13 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:13 �[33mWARN�[m c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword airbyte_secret - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-20 07:29:13 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:13 �[33mWARN�[m c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword multiline - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-20 07:29:15 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:15 �[32mINFO�[m i.a.i.b.s.SshTunnel(getInstance):190 - {} - Starting connection with method: NO_TUNNEL
2021-10-20 07:29:15 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:15 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$toWriteConfig$0):116 - {} - Write config: WriteConfig{streamName=item_de-linkedin-ad_campaign_analytics, namespace=null, outputSchemaName=staging, tmpTableName=_airbyte_tmp_ojl_item_de_linkedin_ad_campaign_analytics, outputTableName=_airbyte_raw_item_de_linkedin_ad_campaign_analytics, syncMode=append}
2021-10-20 07:29:15 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:15 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$toWriteConfig$0):116 - {} - Write config: WriteConfig{streamName=item_de-linkedin-ad_creative_analytics, namespace=null, outputSchemaName=staging, tmpTableName=_airbyte_tmp_rcg_item_de_linkedin_ad_creative_analytics, outputTableName=_airbyte_raw_item_de_linkedin_ad_creative_analytics, syncMode=append}
2021-10-20 07:29:16 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:16 �[32mINFO�[m i.a.i.d.b.BufferedStreamConsumer(startTracked):143 - {} - class io.airbyte.integrations.destination.buffered_stream_consumer.BufferedStreamConsumer started.
2021-10-20 07:29:16 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:16 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):139 - {} - Preparing tmp tables in destination started for 2 streams
2021-10-20 07:29:16 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:16 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):143 - {} - Preparing tmp table in destination started for stream item_de-linkedin-ad_campaign_analytics. schema: staging, tmp table name: _airbyte_tmp_ojl_item_de_linkedin_ad_campaign_analytics
2021-10-20 07:29:17 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:17 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):143 - {} - Preparing tmp table in destination started for stream item_de-linkedin-ad_creative_analytics. schema: staging, tmp table name: _airbyte_tmp_rcg_item_de_linkedin_ad_creative_analytics
2021-10-20 07:29:17 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-20 07:29:17 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):149 - {} - Preparing tables in destination completed.
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Starting syncing SourceLinkedinAds
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Syncing stream: ad_campaign_analytics 
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:00 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:41:45 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:42:40 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:43:45 INFO () DefaultAirbyteStreamFactory(internalLog):90 - Caught retryable error '' after 1 tries. Waiting 5 seconds then retrying...
2021-10-20 07:47:21 INFO () TemporalAttemptExecution(lambda$getCancellationChecker$2):179 - Running sync worker cancellation...
2021-10-20 07:47:21 INFO () DefaultReplicationWorker(cancel):250 - Cancelling replication worker...
2021-10-20 07:47:31 INFO () DefaultReplicationWorker(cancel):258 - Cancelling destination...
2021-10-20 07:47:31 INFO () DefaultAirbyteDestination(cancel):114 - Attempting to cancel destination process...
2021-10-20 07:47:31 INFO () DefaultAirbyteDestination(cancel):119 - Destination process exists, cancelling...
2021-10-20 07:47:40 INFO () DefaultAirbyteDestination(cancel):121 - Cancelled destination process!
2021-10-20 07:47:40 INFO () DefaultReplicationWorker(cancel):265 - Cancelling source...
2021-10-20 07:47:40 INFO () DefaultAirbyteSource(cancel):121 - Attempting to cancel source process...
2021-10-20 07:47:40 INFO () DefaultAirbyteSource(cancel):126 - Source process exists, cancelling...
2021-10-20 07:47:48 INFO () DefaultReplicationWorker(run):121 - Source thread complete.
2021-10-20 07:47:48 INFO () DefaultReplicationWorker(run):122 - Waiting for destination thread to join.
2021-10-20 07:47:48 INFO () DefaultReplicationWorker(run):124 - Destination thread complete.
2021-10-20 07:47:49 INFO () DefaultAirbyteSource(cancel):128 - Cancelled source process!
2021-10-20 07:47:49 INFO () TemporalAttemptExecution(lambda$getCancellationChecker$2):183 - Interrupting worker thread...
2021-10-20 07:47:49 INFO () TemporalAttemptExecution(lambda$getCancellationChecker$2):186 - Cancelling completable future...
2021-10-20 07:47:49 WARN () CancellationHandler$TemporalCancellationHandler(checkAndHandleCancellation):51 - Job either timeout-ed or was cancelled.
2021-10-20 07:47:49 INFO () TemporalAttemptExecution(get):115 - Stopping cancellation check scheduling...
2021-10-20 07:47:49 WARN () POJOActivityTaskHandler$POJOActivityImplementation(execute):243 - Activity failure. ActivityId=277b1525-ae1e-398d-8e78-e84a45b0a916, activityType=Replicate, attempt=1
java.util.concurrent.CancellationException: null
	at java.util.concurrent.CompletableFuture.cancel(CompletableFuture.java:2468) ~[?:?]
	at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getCancellationChecker$2(TemporalAttemptExecution.java:189) ~[io.airbyte-airbyte-workers-0.30.20-alpha.jar:?]
	at io.airbyte.workers.temporal.CancellationHandler$TemporalCancellationHandler.checkAndHandleCancellation(CancellationHandler.java:50) ~[io.airbyte-airbyte-workers-0.30.20-alpha.jar:?]
	at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getCancellationChecker$3(TemporalAttemptExecution.java:192) ~[io.airbyte-airbyte-workers-0.30.20-alpha.jar:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) [?:?]
	at java.lang.Thread.run(Thread.java:832) [?:?]
2021-10-20 07:47:49 ERROR () DefaultReplicationWorker(run):128 - 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:115) ~[io.airbyte-airbyte-workers-0.30.20-alpha.jar:?]
	at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:126) ~[io.airbyte-airbyte-workers-0.30.20-alpha.jar:?]
	at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:32) ~[io.airbyte-airbyte-workers-0.30.20-alpha.jar:?]
	at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$1(TemporalAttemptExecution.java:145) ~[io.airbyte-airbyte-workers-0.30.20-alpha.jar:?]
	at java.lang.Thread.run(Thread.java:832) [?:?]
	Suppressed: java.io.IOException: Stream closed
		at java.lang.ProcessBuilder$NullOutputStream.write(ProcessBuilder.java:442) ~[?:?]
		at java.io.OutputStream.write(OutputStream.java:162) ~[?:?]
		at java.io.BufferedOutputStream.write(BufferedOutputStream.java:123) ~[?:?]
		at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:242) ~[?:?]
		at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:321) ~[?:?]
		at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:325) ~[?:?]
		at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:159) ~[?:?]
		at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:251) ~[?:?]
		at java.io.BufferedWriter.flush(BufferedWriter.java:257) ~[?:?]
		at io.airbyte.workers.protocols.airbyte.DefaultAirbyteDestination.notifyEndOfStream(DefaultAirbyteDestination.java:87) ~[io.airbyte-airbyte-workers-0.30.20-alpha.jar:?]
		at io.airbyte.workers.protocols.airbyte.DefaultAirbyteDestination.close(DefaultAirbyteDestination.java:100) ~[io.airbyte-airbyte-workers-0.30.20-alpha.jar:?]
		at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:101) ~[io.airbyte-airbyte-workers-0.30.20-alpha.jar:?]
		at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:32) ~[io.airbyte-airbyte-workers-0.30.20-alpha.jar:?]
		at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$1(TemporalAttemptExecution.java:145) ~[io.airbyte-airbyte-workers-0.30.20-alpha.jar:?]
		at java.lang.Thread.run(Thread.java:832) [?:?]
2021-10-20 07:47:49 INFO () DefaultReplicationWorker(run):152 - sync summary: io.airbyte.config.ReplicationAttemptSummary@1904db9e[status=cancelled,recordsSynced=340,bytesSynced=428636,startTime=1634714921908,endTime=1634716069189]
2021-10-20 07:47:49 INFO () DefaultReplicationWorker(run):161 - Source did not output any state messages
2021-10-20 07:47:49 WARN () DefaultReplicationWorker(run):172 - State capture: No state retained.
2021-10-20 07:47:50 WARN () CancellationHandler$TemporalCancellationHandler(checkAndHandleCancellation):51 - Job either timeout-ed or was cancelled.

@sherifnada
Copy link
Contributor

thanks, this is helpful!

@annalvova05 annalvova05 self-assigned this Nov 24, 2021
@annalvova05 annalvova05 linked a pull request Dec 1, 2021 that will close this issue
🐛 Source LinkedIn Ads: hands 429 response status code #8382
Merged
16 tasks
@annalvova05
Copy link
Contributor

@tinomerl @sherifnada this error was caused due to rate limits. Each account has quota limits for requests. Rate limits specify the maximum number of API calls that can be made in a 24 hour period. These limits reset at midnight UTC every day. You can find more information here. Also quotas and usage are here.

Also, just published a new connector version with a more informative log message, when sync is stopped.

@tinomerl
Copy link
Contributor Author

tinomerl commented Dec 6, 2021

Hey @annalvova05 thanks for your comment. But the issue seems to be a different one. I upgraded to your connector version last week and tested it. It took about 2 Hours to replicate the data to postgres. This is the only source connector we have problems with. I also checked our quotas after you mentioned it. We don't run into any restrictions here either.

@sherifnada i attached the logs to the original comment and updated the connector version. Could the issue please be reopened?

@sherifnada sherifnada moved this to Done in GL Roadmap Jan 12, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@annalvova05 annalvova05

Labels
area/connectors Connector related issues community connectors/source/linkedin-ads connectors/sources-api type/bug Something isn't working
Projects
No open projects
GL Roadmap
Archived in project
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

🐛 Source LinkedIn Ads: hands 429 response status code airbytehq/airbyte
5 participants
@sherifnada @tinomerl @annalvova05 @igrankova @octavia-squidington-iii