Severe Performance Degradation Mongo Connector

jeff.crooks · May 10, 2022, 7:40pm

Is this your first time deploying Airbyte?: No
OS Version / Instance: EC2
Memory / Disk: Enough of both
Deployment: Docker
Airbyte Version: 0.38.1
Source name/version: MongoDB latest
Destination name/version: Redshift latest
Step: Sync
Description: Before upgrading to 0.37.1 or 0.38.1 the hourly sync took less than 30 seconds for 50-150 records. This sync now takes 45 minutes per execution. Logs below

2022-05-10 11:09:37 e[32mINFOe[m i.a.w.w.WorkerRun(call):49 - Executing worker wrapper. Airbyte version: 0.37.1-alpha
2022-05-10 11:09:37 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/9932/0/logs.log
2022-05-10 11:09:37 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: 0.37.1-alpha
2022-05-10 11:09:37 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):104 - start sync worker. job id: 9932 attempt id: 0
2022-05-10 11:09:37 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):116 - configured sync modes: {parse.WorkoutWithoutTriggers=incremental - append, parse.OnboardingProgress=incremental - append}
2022-05-10 11:09:37 e[32mINFOe[m i.a.w.p.a.DefaultAirbyteDestination(start):69 - Running destination...
2022-05-10 11:09:37 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):82 - Checking if airbyte/destination-redshift:0.3.32 exists...
2022-05-10 11:09:37 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):82 - airbyte/destination-redshift:0.3.32 was found locally.
2022-05-10 11:09:37 e[32mINFOe[m i.a.w.p.DockerProcessFactory(create):108 - Creating docker job ID: 9932
2022-05-10 11:09:37 e[32mINFOe[m i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/9932/0 --log-driver none --name destination-redshift-write-9932-0-lpoml --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e WORKER_CONNECTOR_IMAGE=airbyte/destination-redshift:0.3.32 -e WORKER_JOB_ATTEMPT=0 -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e AIRBYTE_VERSION=0.37.1-alpha -e WORKER_JOB_ID=9932 airbyte/destination-redshift:0.3.32 write --config destination_config.json --catalog destination_catalog.json
2022-05-10 11:09:37 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):82 - Checking if airbyte/source-mongodb-v2:0.1.14 exists...
2022-05-10 11:09:37 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):82 - airbyte/source-mongodb-v2:0.1.14 was found locally.
2022-05-10 11:09:37 e[32mINFOe[m i.a.w.p.DockerProcessFactory(create):108 - Creating docker job ID: 9932
2022-05-10 11:09:37 e[32mINFOe[m i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/9932/0 --log-driver none --name source-mongodb-v2-read-9932-0-yuqzs --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e WORKER_CONNECTOR_IMAGE=airbyte/source-mongodb-v2:0.1.14 -e WORKER_JOB_ATTEMPT=0 -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e AIRBYTE_VERSION=0.37.1-alpha -e WORKER_JOB_ID=9932 airbyte/source-mongodb-v2:0.1.14 read --config source_config.json --catalog source_catalog.json --state input_state.json
2022-05-10 11:09:37 e[32mINFOe[m i.a.w.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$6):346 - Destination output thread started.
2022-05-10 11:09:37 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):158 - Waiting for source and destination threads to complete.
2022-05-10 11:09:37 e[32mINFOe[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):279 - Replication thread started.
2022-05-10 11:09:38 e[43mdestinatione[0m > SLF4J: Class path contains multiple SLF4J bindings.
2022-05-10 11:09:38 e[43mdestinatione[0m > SLF4J: Found binding in [jar:file:/airbyte/lib/log4j-slf4j-impl-2.17.1.jar!/org/slf4j/impl/StaticLoggerBinder.class]
2022-05-10 11:09:38 e[43mdestinatione[0m > SLF4J: Found binding in [jar:file:/airbyte/lib/slf4j-log4j12-1.7.25.jar!/org/slf4j/impl/StaticLoggerBinder.class]
2022-05-10 11:09:38 e[43mdestinatione[0m > SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
2022-05-10 11:09:39 e[43mdestinatione[0m > SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory]
2022-05-10 11:09:40 e[44msourcee[0m > 2022-05-10 11:09:40 e[32mINFOe[m i.a.i.s.m.MongoDbSource(main):64 - starting source: class io.airbyte.integrations.source.mongodb.MongoDbSource
2022-05-10 11:09:40 e[43mdestinatione[0m > 2022-05-10 11:09:40 e[32mINFOe[m i.a.i.d.r.RedshiftDestination(main):70 - starting destination: class io.airbyte.integrations.destination.redshift.RedshiftDestination
2022-05-10 11:09:40 e[44msourcee[0m > 2022-05-10 11:09:40 e[32mINFOe[m i.a.i.b.IntegrationCliParser(parseOptions):118 - integration args: {read=null, catalog=source_catalog.json, state=input_state.json, config=source_config.json}
2022-05-10 11:09:40 e[44msourcee[0m > 2022-05-10 11:09:40 e[32mINFOe[m i.a.i.b.IntegrationRunner(runInternal):121 - Running integration: io.airbyte.integrations.source.mongodb.MongoDbSource
2022-05-10 11:09:40 e[44msourcee[0m > 2022-05-10 11:09:40 e[32mINFOe[m i.a.i.b.IntegrationRunner(runInternal):122 - Command: READ
2022-05-10 11:09:40 e[44msourcee[0m > 2022-05-10 11:09:40 e[32mINFOe[m i.a.i.b.IntegrationRunner(runInternal):123 - Integration config: IntegrationConfig{command=READ, configPath='source_config.json', catalogPath='source_catalog.json', statePath='input_state.json'}
2022-05-10 11:09:41 e[44msourcee[0m > 2022-05-10 11:09:41 e[33mWARNe[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
2022-05-10 11:09:41 e[44msourcee[0m > 2022-05-10 11:09:41 e[33mWARNe[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
2022-05-10 11:09:41 e[44msourcee[0m > 2022-05-10 11:09:41 e[33mWARNe[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
2022-05-10 11:09:41 e[44msourcee[0m > 2022-05-10 11:09:41 e[32mINFOe[m i.a.i.s.r.CdcStateManager(<init>):26 - Initialized CDC state with: null
2022-05-10 11:09:41 e[44msourcee[0m > 2022-05-10 11:09:41 e[32mINFOe[m i.a.i.s.r.StateManager(createCursorInfoForStream):108 - Found matching cursor in state. Stream: AirbyteStreamNameNamespacePair{name='WorkoutWithoutTriggers', namespace='parse'}. Cursor Field: _updated_at Value: 2022-05-10T04:39:11.398Z
2022-05-10 11:09:41 e[44msourcee[0m > 2022-05-10 11:09:41 e[32mINFOe[m i.a.i.s.r.StateManager(createCursorInfoForStream):108 - Found matching cursor in state. Stream: AirbyteStreamNameNamespacePair{name='OnboardingProgress', namespace='parse'}. Cursor Field: _updated_at Value: 2022-05-10T10:48:35.155Z
2022-05-10 11:09:41 e[43mdestinatione[0m > 2022-05-10 11:09:41 e[32mINFOe[m i.a.i.b.IntegrationCliParser(parseOptions):118 - integration args: {catalog=destination_catalog.json, write=null, config=destination_config.json}
2022-05-10 11:09:41 e[43mdestinatione[0m > 2022-05-10 11:09:41 e[32mINFOe[m i.a.i.b.IntegrationRunner(runInternal):121 - Running integration: io.airbyte.integrations.destination.redshift.RedshiftDestination
2022-05-10 11:09:41 e[43mdestinatione[0m > 2022-05-10 11:09:41 e[32mINFOe[m i.a.i.b.IntegrationRunner(runInternal):122 - Command: WRITE
2022-05-10 11:09:41 e[43mdestinatione[0m > 2022-05-10 11:09:41 e[32mINFOe[m i.a.i.b.IntegrationRunner(runInternal):123 - Integration config: IntegrationConfig{command=WRITE, configPath='destination_config.json', catalogPath='destination_catalog.json', statePath='null'}
2022-05-10 11:09:41 e[44msourcee[0m > 2022-05-10 11:09:41 e[32mINFOe[m c.m.d.l.SLF4JLogger(info):71 - Cluster created with settings {hosts=[MYSERVER-shard-00-03-naqnz.mongodb.net:27017], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2022-05-10 11:09:41 e[44msourcee[0m > 2022-05-10 11:09:41 e[32mINFOe[m c.m.d.l.SLF4JLogger(info):71 - Cluster description not yet available. Waiting for 30000 ms before timing out
2022-05-10 11:09:41 e[43mdestinatione[0m > 2022-05-10 11:09:41 e[33mWARNe[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
2022-05-10 11:09:41 e[43mdestinatione[0m > 2022-05-10 11:09:41 e[33mWARNe[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
2022-05-10 11:09:41 e[43mdestinatione[0m > 2022-05-10 11:09:41 e[32mINFOe[m i.a.i.d.j.c.SwitchingDestination(getConsumer):65 - Using destination type: COPY_S3_WITH_SUPER_TMP_TYPE
2022-05-10 11:09:42 e[43mdestinatione[0m > 2022-05-10 11:09:42 e[32mINFOe[m i.a.i.d.s.S3DestinationConfig(createS3Client):165 - Creating S3 client...
2022-05-10 11:09:42 e[44msourcee[0m > 2022-05-10 11:09:42 e[32mINFOe[m c.m.d.l.SLF4JLogger(info):71 - Opened connection [connectionId{localValue:2, serverValue:444747}] to MYSERVER-shard-00-03-naqnz.mongodb.net:27017
2022-05-10 11:09:42 e[44msourcee[0m > 2022-05-10 11:09:42 e[32mINFOe[m c.m.d.l.SLF4JLogger(info):71 - Opened connection [connectionId{localValue:1, serverValue:444748}] to MYSERVER-shard-00-03-naqnz.mongodb.net:27017
2022-05-10 11:09:42 e[44msourcee[0m > 2022-05-10 11:09:42 e[32mINFOe[m c.m.d.l.SLF4JLogger(info):71 - Monitor thread successfully connected to server with description ServerDescription{address=MYSERVER-shard-00-03-naqnz.mongodb.net:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=13, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=387907879, setName='MYSERVER-shard-0', canonicalAddress=MYSERVER-shard-00-03-naqnz.mongodb.net:27017, hosts=[MYSERVER-shard-00-00-naqnz.mongodb.net:27017, MYSERVER-shard-00-01-naqnz.mongodb.net:27017, MYSERVER-shard-00-02-naqnz.mongodb.net:27017], passives=[MYSERVER-shard-00-03-naqnz.mongodb.net:27017], arbiters=[], primary='MYSERVER-shard-00-02-naqnz.mongodb.net:27017', tagSet=TagSet{[Tag{name='nodeType', value='ANALYTICS'}, Tag{name='provider', value='AWS'}, Tag{name='region', value='US_EAST_1'}]}, electionId=null, setVersion=8, topologyVersion=TopologyVersion{processId=626818dba4185f8ff0f1c673, counter=4}, lastWriteDate=Tue May 10 11:09:50 UTC 2022, lastUpdateTimeNanos=21595667948974110}
2022-05-10 11:09:42 e[44msourcee[0m > 2022-05-10 11:09:42 e[32mINFOe[m c.m.d.l.SLF4JLogger(info):71 - Opened connection [connectionId{localValue:3, serverValue:444749}] to MYSERVER-shard-00-03-naqnz.mongodb.net:27017
2022-05-10 11:09:43 e[43mdestinatione[0m > 2022-05-10 11:09:43 e[32mINFOe[m i.a.i.d.b.BufferedStreamConsumer(startTracked):116 - class io.airbyte.integrations.destination.buffered_stream_consumer.BufferedStreamConsumer started.
2022-05-10 11:56:26 e[44msourcee[0m > 2022-05-10 11:56:26 e[32mINFOe[m i.a.i.s.r.StateDecoratingIterator(computeNext):60 - State Report: stream name: AirbyteStreamNameNamespacePair{name='OnboardingProgress', namespace='parse'}, original cursor field: _updated_at, original cursor 2022-05-10T10:48:35.155Z, cursor field: _updated_at, new cursor: 2022-05-10T11:55:36.819Z
2022-05-10 11:56:26 e[44msourcee[0m > 2022-05-10 11:56:26 e[32mINFOe[m i.a.i.s.r.StateDecoratingIterator(computeNext):60 - State Report: stream name: AirbyteStreamNameNamespacePair{name='WorkoutWithoutTriggers', namespace='parse'}, original cursor field: _updated_at, original cursor 2022-05-10T04:39:11.398Z, cursor field: _updated_at, new cursor: 2022-05-10T04:39:11.398Z
2022-05-10 11:56:26 e[44msourcee[0m > 2022-05-10 11:56:26 e[32mINFOe[m i.a.i.s.r.AbstractDbSource(lambda$read$2):124 - Closing database connection pool.
2022-05-10 11:56:26 e[44msourcee[0m > 2022-05-10 11:56:26 e[32mINFOe[m i.a.i.s.r.AbstractDbSource(lambda$read$2):126 - Closed database connection pool.
2022-05-10 11:56:26 e[44msourcee[0m > 2022-05-10 11:56:26 e[32mINFOe[m i.a.i.b.IntegrationRunner(runInternal):169 - Completed integration: io.airbyte.integrations.source.mongodb.MongoDbSource
2022-05-10 11:56:26 e[44msourcee[0m > 2022-05-10 11:56:26 e[32mINFOe[m i.a.i.s.m.MongoDbSource(main):66 - completed source: class io.airbyte.integrations.source.mongodb.MongoDbSource
2022-05-10 11:56:26 e[32mINFOe[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):304 - Source has no more messages, closing connection.
2022-05-10 11:56:26 e[32mINFOe[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):312 - Total records read: 97 (29 KB)
2022-05-10 11:56:26 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):163 - One of source or destination thread complete. Waiting on the other.
2022-05-10 11:56:26 e[43mdestinatione[0m > 2022-05-10 11:56:26 e[32mINFOe[m i.a.i.b.FailureTrackingAirbyteMessageConsumer(close):65 - Airbyte message consumer: succeeded.
2022-05-10 11:56:26 e[43mdestinatione[0m > 2022-05-10 11:56:26 e[32mINFOe[m i.a.i.d.b.BufferedStreamConsumer(close):170 - executing on success close procedure.
2022-05-10 11:56:26 e[43mdestinatione[0m > 2022-05-10 11:56:26 e[32mINFOe[m i.a.i.d.r.InMemoryRecordBufferingStrategy(lambda$flushAll$1):84 - Flushing OnboardingProgress: 95 records (92 KB)
2022-05-10 11:56:26 e[43mdestinatione[0m > 2022-05-10 11:56:26 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(prepareStagingFile):96 - S3 upload part size: 10 MB
2022-05-10 11:56:26 e[43mdestinatione[0m > 2022-05-10 11:56:26 e[32mINFOe[m i.a.i.d.s.c.S3CsvWriter(<init>):58 - Full S3 path for stream 'OnboardingProgress': s3://MYBUCKET//suf_atlas_raw/OnboardingProgress/2022_05_10_1652180983131_847e5e01-8018-4b21-ac80-e242f79bb464.csv
2022-05-10 11:56:26 e[43mdestinatione[0m > 2022-05-10 11:56:26 e[32mINFOe[m i.a.i.d.s.u.StreamTransferManagerHelper(getDefault):55 - PartSize arg is set to 10 MB
2022-05-10 11:56:27 e[43mdestinatione[0m > 2022-05-10 11:56:27 e[32mINFOe[m a.m.s.StreamTransferManager(getMultiPartOutputStreams):329 - Initiated multipart upload to MYBUCKET//suf_atlas_raw/OnboardingProgress/2022_05_10_1652180983131_847e5e01-8018-4b21-ac80-e242f79bb464.csv with full ID fyzIKn9tYUKBZA5WcgUfDQ41fXeNqglrdcBOSIt.I1wF7rHXlc.r3IRBZLL91dQGLI_0tA3QEkxVmRNZrQYLePG2IEavGyqM.H_57GVjCRo1a459TvnXbywlaocnajYG
2022-05-10 11:56:27 e[43mdestinatione[0m > 2022-05-10 11:56:27 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createDestinationSchema):155 - Creating schema in destination if it doesn't exist: suf_atlas_raw
2022-05-10 11:56:27 e[43mdestinatione[0m > 2022-05-10 11:56:27 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createTemporaryTable):161 - Preparing tmp table in destination for stream: WorkoutWithoutTriggers, schema: suf_atlas_raw, tmp table name: _airbyte_tmp_jdx_workoutwithouttriggers.
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m i.a.i.d.r.RedshiftStreamCopier(copyStagingFileToTemporaryTable):86 - Starting copy to tmp table: _airbyte_tmp_jdx_workoutwithouttriggers in destination for stream: WorkoutWithoutTriggers, schema: suf_atlas_raw, .
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m i.a.i.d.r.RedshiftStreamCopier(copyStagingFileToTemporaryTable):90 - Copy to tmp table _airbyte_tmp_jdx_workoutwithouttriggers in destination for stream WorkoutWithoutTriggers complete.
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createDestinationTable):177 - Preparing table _airbyte_raw_workoutwithouttriggers in destination.
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createDestinationTable):179 - Table _airbyte_tmp_jdx_workoutwithouttriggers in destination prepared.
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(generateMergeStatement):186 - Preparing to merge tmp table _airbyte_tmp_jdx_workoutwithouttriggers to dest table: _airbyte_raw_workoutwithouttriggers, schema: suf_atlas_raw, in destination.
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m i.a.i.d.s.w.BaseS3Writer(close):113 - Uploading remaining data for stream 'OnboardingProgress'.
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m a.m.s.MultiPartOutputStream(close):158 - Called close() on [MultipartOutputStream for parts 1 - 10000]
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m a.m.s.MultiPartOutputStream(close):158 - Called close() on [MultipartOutputStream for parts 1 - 10000]
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[33mWARNe[m a.m.s.MultiPartOutputStream(close):160 - [MultipartOutputStream for parts 1 - 10000] is already closed
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m a.m.s.StreamTransferManager(complete):367 - [Manager uploading to MYBUCKET//suf_atlas_raw/OnboardingProgress/2022_05_10_1652180983131_847e5e01-8018-4b21-ac80-e242f79bb464.csv with id fyzIKn9tY...laocnajYG]: Uploading leftover stream [Part number 1 containing 0.04 MB]
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to MYBUCKET//suf_atlas_raw/OnboardingProgress/2022_05_10_1652180983131_847e5e01-8018-4b21-ac80-e242f79bb464.csv with id fyzIKn9tY...laocnajYG]: Finished uploading [Part number 1 containing 0.04 MB]
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m a.m.s.StreamTransferManager(complete):395 - [Manager uploading to MYBUCKET//suf_atlas_raw/OnboardingProgress/2022_05_10_1652180983131_847e5e01-8018-4b21-ac80-e242f79bb464.csv with id fyzIKn9tY...laocnajYG]: Completed
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m i.a.i.d.s.w.BaseS3Writer(close):115 - Upload completed for stream 'OnboardingProgress'.
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createDestinationSchema):155 - Creating schema in destination if it doesn't exist: suf_atlas_raw
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createTemporaryTable):161 - Preparing tmp table in destination for stream: OnboardingProgress, schema: suf_atlas_raw, tmp table name: _airbyte_tmp_wiv_onboardingprogress.
2022-05-10 11:56:28 e[43mdestinatione[0m > 2022-05-10 11:56:28 e[32mINFOe[m i.a.i.d.r.RedshiftStreamCopier(copyStagingFileToTemporaryTable):86 - Starting copy to tmp table: _airbyte_tmp_wiv_onboardingprogress in destination for stream: OnboardingProgress, schema: suf_atlas_raw, .
2022-05-10 11:56:29 e[43mdestinatione[0m > 2022-05-10 11:56:29 e[32mINFOe[m i.a.i.d.r.RedshiftStreamCopier(copyStagingFileToTemporaryTable):90 - Copy to tmp table _airbyte_tmp_wiv_onboardingprogress in destination for stream OnboardingProgress complete.
2022-05-10 11:56:29 e[43mdestinatione[0m > 2022-05-10 11:56:29 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createDestinationTable):177 - Preparing table _airbyte_raw_onboardingprogress in destination.
2022-05-10 11:56:29 e[43mdestinatione[0m > 2022-05-10 11:56:29 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createDestinationTable):179 - Table _airbyte_tmp_wiv_onboardingprogress in destination prepared.
2022-05-10 11:56:29 e[43mdestinatione[0m > 2022-05-10 11:56:29 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(generateMergeStatement):186 - Preparing to merge tmp table _airbyte_tmp_wiv_onboardingprogress to dest table: _airbyte_raw_onboardingprogress, schema: suf_atlas_raw, in destination.
2022-05-10 11:56:29 e[43mdestinatione[0m > 2022-05-10 11:56:29 e[32mINFOe[m i.a.i.d.r.RedshiftSqlOperations(onDestinationCloseOperations):110 - Executing operations for Redshift Destination DB engine...
2022-05-10 11:56:29 e[43mdestinatione[0m > 2022-05-10 11:56:29 e[32mINFOe[m i.a.i.d.r.RedshiftSqlOperations(discoverNotSuperTables):129 - Discovering NOT SUPER table types...
2022-05-10 11:56:29 e[43mdestinatione[0m > 2022-05-10 11:56:29 e[32mINFOe[m i.a.i.d.r.RedshiftSqlOperations(onDestinationCloseOperations):118 - Executing operations for Redshift Destination DB engine completed.
2022-05-10 11:56:30 e[43mdestinatione[0m > 2022-05-10 11:56:30 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(removeFileAndDropTmpTable):205 - Begin cleaning _airbyte_tmp_jdx_workoutwithouttriggers tmp table in destination.
2022-05-10 11:56:30 e[43mdestinatione[0m > 2022-05-10 11:56:30 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(removeFileAndDropTmpTable):207 - _airbyte_tmp_jdx_workoutwithouttriggers tmp table in destination cleaned.
2022-05-10 11:56:30 e[43mdestinatione[0m > 2022-05-10 11:56:30 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(removeFileAndDropTmpTable):201 - S3 staging file /suf_atlas_raw/OnboardingProgress/2022_05_10_1652180983131_847e5e01-8018-4b21-ac80-e242f79bb464.csv cleaned.
2022-05-10 11:56:30 e[43mdestinatione[0m > 2022-05-10 11:56:30 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(removeFileAndDropTmpTable):205 - Begin cleaning _airbyte_tmp_wiv_onboardingprogress tmp table in destination.
2022-05-10 11:56:30 e[43mdestinatione[0m > 2022-05-10 11:56:30 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(removeFileAndDropTmpTable):207 - _airbyte_tmp_wiv_onboardingprogress tmp table in destination cleaned.
2022-05-10 11:56:30 e[43mdestinatione[0m > 2022-05-10 11:56:30 e[32mINFOe[m i.a.i.d.r.RedshiftStreamCopier(removeFileAndDropTmpTable):106 - Begin cleaning s3 manifest file /737c93f6-3540-4f5b-8b77-1e774cdff2c3/suf_atlas_raw/c2c0b8ff-62e0-4dec-9b11-260e555c50a0.manifest.
2022-05-10 11:56:30 e[43mdestinatione[0m > 2022-05-10 11:56:30 e[32mINFOe[m i.a.i.d.r.RedshiftStreamCopier(removeFileAndDropTmpTable):110 - S3 manifest file /737c93f6-3540-4f5b-8b77-1e774cdff2c3/suf_atlas_raw/c2c0b8ff-62e0-4dec-9b11-260e555c50a0.manifest cleaned.
2022-05-10 11:56:30 e[32mINFOe[m i.a.w.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$6):356 - State in DefaultReplicationWorker from destination: io.airbyte.protocol.models.AirbyteMessage@24c35cfa[type=STATE,log=<null>,spec=<null>,connectionStatus=<null>,catalog=<null>,record=<null>,state=io.airbyte.protocol.models.AirbyteStateMessage@2a04a612[data={"cdc":false,"streams":[{"stream_name":"OnboardingProgress","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-10T11:55:36.819Z"},{"stream_name":"WorkoutWithoutTriggers","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-10T04:39:11.398Z"}]},additionalProperties={}],trace=<null>,additionalProperties={}]
2022-05-10 11:56:30 e[43mdestinatione[0m > 2022-05-10 11:56:30 e[32mINFOe[m i.a.i.b.IntegrationRunner(runInternal):169 - Completed integration: io.airbyte.integrations.destination.redshift.RedshiftDestination
2022-05-10 11:56:30 e[43mdestinatione[0m > 2022-05-10 11:56:30 e[32mINFOe[m i.a.i.d.r.RedshiftDestination(main):72 - completed destination: class io.airbyte.integrations.destination.redshift.RedshiftDestination
2022-05-10 11:56:30 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):165 - Source and destination threads complete.
2022-05-10 11:56:30 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):228 - sync summary: io.airbyte.config.ReplicationAttemptSummary@7a0be173[status=completed,recordsSynced=95,bytesSynced=30167,startTime=1652180977659,endTime=1652183790924,totalStats=io.airbyte.config.SyncStats@5ddbd872[recordsEmitted=95,bytesEmitted=30167,stateMessagesEmitted=2,recordsCommitted=95],streamStats=[io.airbyte.config.StreamSyncStats@629267a6[streamName=OnboardingProgress,stats=io.airbyte.config.SyncStats@56951e25[recordsEmitted=95,bytesEmitted=30167,stateMessagesEmitted=<null>,recordsCommitted=95]]]]
2022-05-10 11:56:30 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):248 - Source output at least one state message
2022-05-10 11:56:30 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):254 - State capture: Updated state to: Optional[io.airbyte.config.State@73306dfd[state={"cdc":false,"streams":[{"stream_name":"OnboardingProgress","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-10T11:55:36.819Z"},{"stream_name":"WorkoutWithoutTriggers","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-10T04:39:11.398Z"}]}]]
2022-05-10 11:56:30 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
2022-05-10 11:56:30 e[32mINFOe[m i.a.w.t.s.ReplicationActivityImpl(lambda$replicate$3):155 - sync summary: io.airbyte.config.StandardSyncOutput@57e7e790[standardSyncSummary=io.airbyte.config.StandardSyncSummary@12e57308[status=completed,recordsSynced=95,bytesSynced=30167,startTime=1652180977659,endTime=1652183790924,totalStats=io.airbyte.config.SyncStats@5ddbd872[recordsEmitted=95,bytesEmitted=30167,stateMessagesEmitted=2,recordsCommitted=95],streamStats=[io.airbyte.config.StreamSyncStats@629267a6[streamName=OnboardingProgress,stats=io.airbyte.config.SyncStats@56951e25[recordsEmitted=95,bytesEmitted=30167,stateMessagesEmitted=<null>,recordsCommitted=95]]]],normalizationSummary=<null>,state=io.airbyte.config.State@73306dfd[state={"cdc":false,"streams":[{"stream_name":"OnboardingProgress","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-10T11:55:36.819Z"},{"stream_name":"WorkoutWithoutTriggers","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-10T04:39:11.398Z"}]}],outputCatalog=io.airbyte.protocol.models.ConfiguredAirbyteCatalog@333c9538[streams=[io.airbyte.protocol.models.ConfiguredAirbyteStream@233d638d[stream=io.airbyte.protocol.models.AirbyteStream@4b0edb1d[name=OnboardingProgress,jsonSchema={"type":"object","properties":{"_id":{"type":"string"},"step":{"type":"string"},"input":{"type":"string"},"_p_user":{"type":"string"},"platform":{"type":"string"},"appVersion":{"type":"string"},"_created_at":{"type":"string"},"_updated_at":{"type":"string"},"calculation":{"type":"string"},"completedDate":{"type":"string"}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[],namespace=suf_atlas_raw,additionalProperties={}],syncMode=incremental,cursorField=[_updated_at],destinationSyncMode=append,primaryKey=[],additionalProperties={}], io.airbyte.protocol.models.ConfiguredAirbyteStream@72ca8c47[stream=io.airbyte.protocol.models.AirbyteStream@25884273[name=WorkoutWithoutTriggers,jsonSchema={"type":"object","properties":{"_id":{"type":"string"},"name":{"type":"string"},"tags":{"type":"array"},"brand":{"type":"string"},"level":{"type":"string"},"notes":{"type":"string"},"sport":{"type":"string"},"hidden":{"type":"boolean"},"isFree":{"type":"boolean"},"isTest":{"type":"boolean"},"bestFor":{"type":"string"},"details":{"type":"string"},"_p_style":{"type":"string"},"_p_video":{"type":"string"},"nameIcon":{"type":"string"},"rating1m":{"type":"number"},"rating5m":{"type":"number"},"rating5s":{"type":"number"},"videoUrl":{"type":"string"},"breakdown":{"type":"string"},"equipment":{"type":"array"},"rating20m":{"type":"number"},"sortOrder":{"type":"number"},"thumbnail":{"type":"string"},"_p_creator":{"type":"string"},"previewUrl":{"type":"string"},"stampImage":{"type":"string"},"_created_at":{"type":"string"},"_updated_at":{"type":"string"},"breakdownV2":{"type":"string"},"description":{"type":"string"},"downloadUrl":{"type":"string"},"imperatives":{"type":"string"},"_p_cleanVideo":{"type":"string"},"_p_instructor":{"type":"string"},"_p_systmVideo":{"type":"string"},"cloudfrontUrl":{"type":"string"},"nonAppWorkout":{"type":"boolean"},"previewImage1":{"type":"string"},"previewImage2":{"type":"string"},"previewImage3":{"type":"string"},"tagsFormatted":{"type":"string"},"generateSounds":{"type":"boolean"},"trainingPeaksId":{"type":"string"},"_p_featuredRace1":{"type":"string"},"_p_featuredRace2":{"type":"string"},"_p_featuredRace3":{"type":"string"},"_p_featuredRace4":{"type":"string"},"previewThumbnail":{"type":"string"},"shortDescription":{"type":"string"},"durationSecondsV3":{"type":"number"},"_p_promotedWorkout":{"type":"string"},"tss_aibyte_transform":{"type":"string"},"durationSeconds_aibyte_transform":{"type":"string"},"intensityFactor_aibyte_transform":{"type":"string"},"durationSecondsV2_aibyte_transform":{"type":"string"}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[],namespace=suf_atlas_raw,additionalProperties={}],syncMode=incremental,cursorField=[_updated_at],destinationSyncMode=append,primaryKey=[],additionalProperties={}]],additionalProperties={}],failures=[]]
2022-05-10 11:56:30 e[32mINFOe[m i.a.w.t.TemporalUtils(withBackgroundHeartbeat):236 - Stopping temporal heartbeating...
2022-05-10 11:56:30 e[32mINFOe[m i.a.c.p.ConfigRepository(updateConnectionState):774 - Updating connection 560373a7-2d53-4e06-b717-54b55c8452c9 state: io.airbyte.config.State@76849234[state={"cdc":false,"streams":[{"stream_name":"OnboardingProgress","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-10T11:55:36.819Z"},{"stream_name":"WorkoutWithoutTriggers","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-10T04:39:11.398Z"}]}]
2022-05-10 11:56:31 e[33mWARNe[m i.a.s.p.JobNotifier(notifyJob):116 - Failed to successfully notify success: io.airbyte.config.Notification@5eb36cc9[notificationType=slack,sendOnSuccess=false,sendOnFailure=true,slackConfiguration=io.airbyte.config.SlackNotificationConfiguration@43e6c043[webhook=MYWEBHOOK],customerioConfiguration=<null>,additionalProperties={}]

jeff.crooks · May 10, 2022, 7:44pm

Logs from when it worked correctly

2022-05-09 18:36:35 e[32mINFOe[m i.a.w.w.WorkerRun(call):49 - Executing worker wrapper. Airbyte version: 0.35.59-alpha
2022-05-09 18:36:35 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(get):105 - Docker volume job log path: /tmp/workspace/9906/0/logs.log
2022-05-09 18:36:35 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(get):110 - Executing worker wrapper. Airbyte version: 0.35.59-alpha
2022-05-09 18:36:35 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):104 - start sync worker. job id: 9906 attempt id: 0
2022-05-09 18:36:35 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):116 - configured sync modes: {parse.WorkoutWithoutTriggers=incremental - append, parse.OnboardingProgress=incremental - append}
2022-05-09 18:36:35 e[32mINFOe[m i.a.w.p.a.DefaultAirbyteDestination(start):69 - Running destination...
2022-05-09 18:36:35 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):82 - Checking if airbyte/destination-redshift:0.3.28 exists...
2022-05-09 18:36:35 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):82 - airbyte/destination-redshift:0.3.28 was found locally.
2022-05-09 18:36:35 e[32mINFOe[m i.a.w.p.DockerProcessFactory(create):106 - Creating docker job ID: 9906
2022-05-09 18:36:35 e[32mINFOe[m i.a.w.p.DockerProcessFactory(create):158 - Preparing command: docker run --rm --init -i -w /data/9906/0 --log-driver none --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e WORKER_CONNECTOR_IMAGE=airbyte/destination-redshift:0.3.28 -e WORKER_JOB_ATTEMPT=0 -e AIRBYTE_ROLE= -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_VERSION=0.35.59-alpha -e WORKER_JOB_ID=9906 airbyte/destination-redshift:0.3.28 write --config destination_config.json --catalog destination_catalog.json
2022-05-09 18:36:35 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):82 - Checking if airbyte/source-mongodb-v2:0.1.10 exists...
2022-05-09 18:36:35 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):82 - airbyte/source-mongodb-v2:0.1.10 was found locally.
2022-05-09 18:36:35 e[32mINFOe[m i.a.w.p.DockerProcessFactory(create):106 - Creating docker job ID: 9906
2022-05-09 18:36:35 e[32mINFOe[m i.a.w.p.DockerProcessFactory(create):158 - Preparing command: docker run --rm --init -i -w /data/9906/0 --log-driver none --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e WORKER_CONNECTOR_IMAGE=airbyte/source-mongodb-v2:0.1.10 -e WORKER_JOB_ATTEMPT=0 -e AIRBYTE_ROLE= -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_VERSION=0.35.59-alpha -e WORKER_JOB_ID=9906 airbyte/source-mongodb-v2:0.1.10 read --config source_config.json --catalog source_catalog.json --state input_state.json
2022-05-09 18:36:35 e[32mINFOe[m i.a.w.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$6):339 - Destination output thread started.
2022-05-09 18:36:35 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):158 - Waiting for source and destination threads to complete.
2022-05-09 18:36:35 e[32mINFOe[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):279 - Replication thread started.
2022-05-09 18:36:36 e[43mdestinatione[0m > SLF4J: Class path contains multiple SLF4J bindings.
2022-05-09 18:36:36 e[43mdestinatione[0m > SLF4J: Found binding in [jar:file:/airbyte/lib/log4j-slf4j-impl-2.17.1.jar!/org/slf4j/impl/StaticLoggerBinder.class]
2022-05-09 18:36:36 e[43mdestinatione[0m > SLF4J: Found binding in [jar:file:/airbyte/lib/slf4j-log4j12-1.7.25.jar!/org/slf4j/impl/StaticLoggerBinder.class]
2022-05-09 18:36:36 e[43mdestinatione[0m > SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
2022-05-09 18:36:36 e[43mdestinatione[0m > SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory]
2022-05-09 18:36:38 e[44msourcee[0m > 2022-05-09 18:36:38 e[32mINFOe[m i.a.i.s.m.MongoDbSource(main):64 - starting source: class io.airbyte.integrations.source.mongodb.MongoDbSource
2022-05-09 18:36:38 e[44msourcee[0m > 2022-05-09 18:36:38 e[32mINFOe[m i.a.i.b.IntegrationRunner(run):76 - Running integration: io.airbyte.integrations.source.mongodb.MongoDbSource
2022-05-09 18:36:38 e[44msourcee[0m > 2022-05-09 18:36:38 e[32mINFOe[m i.a.i.b.IntegrationCliParser(parseOptions):118 - integration args: {read=null, catalog=source_catalog.json, state=input_state.json, config=source_config.json}
2022-05-09 18:36:38 e[44msourcee[0m > 2022-05-09 18:36:38 e[32mINFOe[m i.a.i.b.IntegrationRunner(run):80 - Command: READ
2022-05-09 18:36:38 e[44msourcee[0m > 2022-05-09 18:36:38 e[32mINFOe[m i.a.i.b.IntegrationRunner(run):81 - Integration config: IntegrationConfig{command=READ, configPath='source_config.json', catalogPath='source_catalog.json', statePath='input_state.json'}
2022-05-09 18:36:38 e[43mdestinatione[0m > 2022-05-09 18:36:38 e[32mINFOe[m i.a.i.d.r.RedshiftDestination(main):77 - starting destination: class io.airbyte.integrations.destination.redshift.RedshiftDestination
2022-05-09 18:36:38 e[44msourcee[0m > 2022-05-09 18:36:38 e[33mWARNe[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
2022-05-09 18:36:38 e[44msourcee[0m > 2022-05-09 18:36:38 e[33mWARNe[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
2022-05-09 18:36:38 e[44msourcee[0m > 2022-05-09 18:36:38 e[33mWARNe[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
2022-05-09 18:36:38 e[43mdestinatione[0m > 2022-05-09 18:36:38 e[32mINFOe[m i.a.i.b.IntegrationCliParser(parseOptions):118 - integration args: {catalog=destination_catalog.json, write=null, config=destination_config.json}
2022-05-09 18:36:38 e[43mdestinatione[0m > 2022-05-09 18:36:38 e[32mINFOe[m i.a.i.b.IntegrationRunner(runInternal):121 - Running integration: io.airbyte.integrations.destination.redshift.RedshiftDestination
2022-05-09 18:36:38 e[43mdestinatione[0m > 2022-05-09 18:36:38 e[32mINFOe[m i.a.i.b.IntegrationRunner(runInternal):122 - Command: WRITE
2022-05-09 18:36:39 e[43mdestinatione[0m > 2022-05-09 18:36:38 e[32mINFOe[m i.a.i.b.IntegrationRunner(runInternal):123 - Integration config: IntegrationConfig{command=WRITE, configPath='destination_config.json', catalogPath='destination_catalog.json', statePath='null'}
2022-05-09 18:36:39 e[44msourcee[0m > 2022-05-09 18:36:39 e[32mINFOe[m i.a.i.s.r.CdcStateManager(<init>):26 - Initialized CDC state with: null
2022-05-09 18:36:39 e[44msourcee[0m > 2022-05-09 18:36:39 e[32mINFOe[m i.a.i.s.r.StateManager(createCursorInfoForStream):108 - Found matching cursor in state. Stream: AirbyteStreamNameNamespacePair{name='WorkoutWithoutTriggers', namespace='parse'}. Cursor Field: _updated_at Value: 2022-05-07T10:16:15.701Z
2022-05-09 18:36:39 e[44msourcee[0m > 2022-05-09 18:36:39 e[32mINFOe[m i.a.i.s.r.StateManager(createCursorInfoForStream):108 - Found matching cursor in state. Stream: AirbyteStreamNameNamespacePair{name='OnboardingProgress', namespace='parse'}. Cursor Field: _updated_at Value: 2022-05-09T17:36:53.041Z
2022-05-09 18:36:39 e[43mdestinatione[0m > 2022-05-09 18:36:39 e[33mWARNe[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
2022-05-09 18:36:39 e[43mdestinatione[0m > 2022-05-09 18:36:39 e[33mWARNe[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
2022-05-09 18:36:39 e[43mdestinatione[0m > 2022-05-09 18:36:39 e[32mINFOe[m i.a.i.d.j.c.SwitchingDestination(getConsumer):65 - Using destination type: COPY_S3
2022-05-09 18:36:39 e[44msourcee[0m > 2022-05-09 18:36:39 e[32mINFOe[m c.m.d.l.SLF4JLogger(info):71 - Cluster created with settings {hosts=[MYSERVER-shard-00-03-naqnz.mongodb.net:27017], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2022-05-09 18:36:39 e[44msourcee[0m > 2022-05-09 18:36:39 e[32mINFOe[m c.m.d.l.SLF4JLogger(info):71 - Cluster description not yet available. Waiting for 30000 ms before timing out
2022-05-09 18:36:39 e[43mdestinatione[0m > 2022-05-09 18:36:39 e[32mINFOe[m i.a.i.d.s.S3DestinationConfig(createS3Client):169 - Creating S3 client...
2022-05-09 18:36:40 e[44msourcee[0m > 2022-05-09 18:36:40 e[32mINFOe[m c.m.d.l.SLF4JLogger(info):71 - Opened connection [connectionId{localValue:2, serverValue:423946}] to MYSERVER-shard-00-03-naqnz.mongodb.net:27017
2022-05-09 18:36:40 e[44msourcee[0m > 2022-05-09 18:36:40 e[32mINFOe[m c.m.d.l.SLF4JLogger(info):71 - Opened connection [connectionId{localValue:1, serverValue:423945}] to MYSERVER-shard-00-03-naqnz.mongodb.net:27017
2022-05-09 18:36:40 e[44msourcee[0m > 2022-05-09 18:36:40 e[32mINFOe[m c.m.d.l.SLF4JLogger(info):71 - Monitor thread successfully connected to server with description ServerDescription{address=MYSERVER-shard-00-03-naqnz.mongodb.net:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=13, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=386251241, setName='MYSERVER-shard-0', canonicalAddress=MYSERVER-shard-00-03-naqnz.mongodb.net:27017, hosts=[MYSERVER-shard-00-00-naqnz.mongodb.net:27017, MYSERVER-shard-00-01-naqnz.mongodb.net:27017, MYSERVER-shard-00-02-naqnz.mongodb.net:27017], passives=[MYSERVER-shard-00-03-naqnz.mongodb.net:27017], arbiters=[], primary='MYSERVER-shard-00-02-naqnz.mongodb.net:27017', tagSet=TagSet{[Tag{name='nodeType', value='ANALYTICS'}, Tag{name='provider', value='AWS'}, Tag{name='region', value='US_EAST_1'}]}, electionId=null, setVersion=8, topologyVersion=TopologyVersion{processId=626818dba4185f8ff0f1c673, counter=4}, lastWriteDate=Mon May 09 18:36:47 UTC 2022, lastUpdateTimeNanos=21536085859074990}
2022-05-09 18:36:40 e[44msourcee[0m > 2022-05-09 18:36:40 e[32mINFOe[m c.m.d.l.SLF4JLogger(info):71 - Opened connection [connectionId{localValue:3, serverValue:423947}] to MYSERVER-shard-00-03-naqnz.mongodb.net:27017
2022-05-09 18:36:40 e[43mdestinatione[0m > 2022-05-09 18:36:40 e[32mINFOe[m i.a.i.d.b.BufferedStreamConsumer(startTracked):141 - class io.airbyte.integrations.destination.buffered_stream_consumer.BufferedStreamConsumer started.
2022-05-09 18:36:54 e[44msourcee[0m > 2022-05-09 18:36:54 e[32mINFOe[m i.a.i.s.r.StateDecoratingIterator(computeNext):60 - State Report: stream name: AirbyteStreamNameNamespacePair{name='OnboardingProgress', namespace='parse'}, original cursor field: _updated_at, original cursor 2022-05-09T17:36:53.041Z, cursor field: _updated_at, new cursor: 2022-05-09T18:34:20.663Z
2022-05-09 18:36:54 e[44msourcee[0m > 2022-05-09 18:36:54 e[32mINFOe[m i.a.i.s.r.StateDecoratingIterator(computeNext):60 - State Report: stream name: AirbyteStreamNameNamespacePair{name='WorkoutWithoutTriggers', namespace='parse'}, original cursor field: _updated_at, original cursor 2022-05-07T10:16:15.701Z, cursor field: _updated_at, new cursor: 2022-05-07T10:16:15.701Z
2022-05-09 18:36:54 e[44msourcee[0m > 2022-05-09 18:36:54 e[32mINFOe[m i.a.i.s.r.AbstractDbSource(lambda$read$2):123 - Closing database connection pool.
2022-05-09 18:36:54 e[44msourcee[0m > 2022-05-09 18:36:54 e[32mINFOe[m i.a.i.s.r.AbstractDbSource(lambda$read$2):125 - Closed database connection pool.
2022-05-09 18:36:54 e[44msourcee[0m > 2022-05-09 18:36:54 e[32mINFOe[m i.a.i.b.IntegrationRunner(run):133 - Completed integration: io.airbyte.integrations.source.mongodb.MongoDbSource
2022-05-09 18:36:54 e[44msourcee[0m > 2022-05-09 18:36:54 e[32mINFOe[m i.a.i.s.m.MongoDbSource(main):66 - completed source: class io.airbyte.integrations.source.mongodb.MongoDbSource
2022-05-09 18:36:54 e[32mINFOe[m i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):305 - Total records read: 136 (39 KB)
2022-05-09 18:36:54 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):163 - One of source or destination thread complete. Waiting on the other.
2022-05-09 18:36:54 e[43mdestinatione[0m > 2022-05-09 18:36:54 e[32mINFOe[m i.a.i.b.FailureTrackingAirbyteMessageConsumer(close):65 - Airbyte message consumer: succeeded.
2022-05-09 18:36:54 e[43mdestinatione[0m > 2022-05-09 18:36:54 e[32mINFOe[m i.a.i.d.b.BufferedStreamConsumer(close):217 - executing on success close procedure.
2022-05-09 18:36:54 e[43mdestinatione[0m > 2022-05-09 18:36:54 e[32mINFOe[m i.a.i.d.b.BufferedStreamConsumer(flushQueueToDestination):181 - Flushing buffer: 182180 bytes
2022-05-09 18:36:54 e[43mdestinatione[0m > 2022-05-09 18:36:54 e[32mINFOe[m i.a.i.d.b.BufferedStreamConsumer(lambda$flushQueueToDestination$1):185 - Flushing OnboardingProgress: 134 records
2022-05-09 18:36:54 e[43mdestinatione[0m > 2022-05-09 18:36:54 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(prepareStagingFile):95 - S3 upload part size: 10 MB
2022-05-09 18:36:54 e[43mdestinatione[0m > 2022-05-09 18:36:54 e[32mINFOe[m i.a.i.d.s.c.S3CsvWriter(<init>):58 - Full S3 path for stream 'OnboardingProgress': s3://MYBUCKET/suf_atlas_raw/OnboardingProgress/2022_05_09_1652121400855_f4be0c12-296a-4876-b48c-e453d60f9ef1.csv
2022-05-09 18:36:54 e[43mdestinatione[0m > 2022-05-09 18:36:54 e[32mINFOe[m i.a.i.d.s.u.S3StreamTransferManagerHelper(getDefault):55 - PartSize arg is set to 10 MB
2022-05-09 18:36:54 e[43mdestinatione[0m > 2022-05-09 18:36:54 e[32mINFOe[m a.m.s.StreamTransferManager(getMultiPartOutputStreams):329 - Initiated multipart upload to MYBUCKET/suf_atlas_raw/OnboardingProgress/2022_05_09_1652121400855_f4be0c12-296a-4876-b48c-e453d60f9ef1.csv with full ID aaEfD6M_X5Mtgu5QOWNRT.yMPpW4R6FXvoQjKiUyGH6pmmyLp9kjR1yZwTa8ZxmnavYSt8wP0gHRnn.LPDLkwH2xsr52hLQp93O15I205T0Hgz3nX9ZhV8pVY4yzDTy1
2022-05-09 18:36:54 e[43mdestinatione[0m > 2022-05-09 18:36:54 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createDestinationSchema):152 - Creating schema in destination if it doesn't exist: suf_atlas_raw
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createTemporaryTable):158 - Preparing tmp table in destination for stream: WorkoutWithoutTriggers, schema: suf_atlas_raw, tmp table name: _airbyte_tmp_ohi_workoutwithouttriggers.
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[32mINFOe[m i.a.i.d.r.RedshiftStreamCopier(copyStagingFileToTemporaryTable):85 - Starting copy to tmp table: _airbyte_tmp_ohi_workoutwithouttriggers in destination for stream: WorkoutWithoutTriggers, schema: suf_atlas_raw, .
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[32mINFOe[m i.a.i.d.r.RedshiftStreamCopier(copyStagingFileToTemporaryTable):89 - Copy to tmp table _airbyte_tmp_ohi_workoutwithouttriggers in destination for stream WorkoutWithoutTriggers complete.
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createDestinationTable):174 - Preparing table _airbyte_raw_workoutwithouttriggers in destination.
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createDestinationTable):176 - Table _airbyte_tmp_ohi_workoutwithouttriggers in destination prepared.
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(generateMergeStatement):183 - Preparing to merge tmp table _airbyte_tmp_ohi_workoutwithouttriggers to dest table: _airbyte_raw_workoutwithouttriggers, schema: suf_atlas_raw, in destination.
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[32mINFOe[m i.a.i.d.s.w.BaseS3Writer(close):113 - Uploading remaining data for stream 'OnboardingProgress'.
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[32mINFOe[m a.m.s.MultiPartOutputStream(close):158 - Called close() on [MultipartOutputStream for parts 1 - 10000]
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[32mINFOe[m a.m.s.MultiPartOutputStream(close):158 - Called close() on [MultipartOutputStream for parts 1 - 10000]
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[33mWARNe[m a.m.s.MultiPartOutputStream(close):160 - [MultipartOutputStream for parts 1 - 10000] is already closed
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[32mINFOe[m a.m.s.StreamTransferManager(complete):367 - [Manager uploading to MYBUCKET/suf_atlas_raw/OnboardingProgress/2022_05_09_1652121400855_f4be0c12-296a-4876-b48c-e453d60f9ef1.csv with id aaEfD6M_X...VY4yzDTy1]: Uploading leftover stream [Part number 1 containing 0.05 MB]
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[32mINFOe[m a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to MYBUCKET/suf_atlas_raw/OnboardingProgress/2022_05_09_1652121400855_f4be0c12-296a-4876-b48c-e453d60f9ef1.csv with id aaEfD6M_X...VY4yzDTy1]: Finished uploading [Part number 1 containing 0.05 MB]
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[32mINFOe[m a.m.s.StreamTransferManager(complete):395 - [Manager uploading to MYBUCKET/suf_atlas_raw/OnboardingProgress/2022_05_09_1652121400855_f4be0c12-296a-4876-b48c-e453d60f9ef1.csv with id aaEfD6M_X...VY4yzDTy1]: Completed
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[32mINFOe[m i.a.i.d.s.w.BaseS3Writer(close):115 - Upload completed for stream 'OnboardingProgress'.
2022-05-09 18:36:56 e[43mdestinatione[0m > 2022-05-09 18:36:56 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createDestinationSchema):152 - Creating schema in destination if it doesn't exist: suf_atlas_raw
2022-05-09 18:36:57 e[43mdestinatione[0m > 2022-05-09 18:36:57 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createTemporaryTable):158 - Preparing tmp table in destination for stream: OnboardingProgress, schema: suf_atlas_raw, tmp table name: _airbyte_tmp_zvw_onboardingprogress.
2022-05-09 18:36:57 e[43mdestinatione[0m > 2022-05-09 18:36:57 e[32mINFOe[m i.a.i.d.r.RedshiftStreamCopier(copyStagingFileToTemporaryTable):85 - Starting copy to tmp table: _airbyte_tmp_zvw_onboardingprogress in destination for stream: OnboardingProgress, schema: suf_atlas_raw, .
2022-05-09 18:36:58 e[43mdestinatione[0m > 2022-05-09 18:36:58 e[32mINFOe[m i.a.i.d.r.RedshiftStreamCopier(copyStagingFileToTemporaryTable):89 - Copy to tmp table _airbyte_tmp_zvw_onboardingprogress in destination for stream OnboardingProgress complete.
2022-05-09 18:36:58 e[43mdestinatione[0m > 2022-05-09 18:36:58 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createDestinationTable):174 - Preparing table _airbyte_raw_onboardingprogress in destination.
2022-05-09 18:36:58 e[43mdestinatione[0m > 2022-05-09 18:36:58 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(createDestinationTable):176 - Table _airbyte_tmp_zvw_onboardingprogress in destination prepared.
2022-05-09 18:36:58 e[43mdestinatione[0m > 2022-05-09 18:36:58 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(generateMergeStatement):183 - Preparing to merge tmp table _airbyte_tmp_zvw_onboardingprogress to dest table: _airbyte_raw_onboardingprogress, schema: suf_atlas_raw, in destination.
2022-05-09 18:36:58 e[43mdestinatione[0m > 2022-05-09 18:36:58 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(removeFileAndDropTmpTable):202 - Begin cleaning _airbyte_tmp_ohi_workoutwithouttriggers tmp table in destination.
2022-05-09 18:36:59 e[43mdestinatione[0m > 2022-05-09 18:36:59 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(removeFileAndDropTmpTable):204 - _airbyte_tmp_ohi_workoutwithouttriggers tmp table in destination cleaned.
2022-05-09 18:36:59 e[43mdestinatione[0m > 2022-05-09 18:36:59 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(removeFileAndDropTmpTable):198 - S3 staging file suf_atlas_raw/OnboardingProgress/2022_05_09_1652121400855_f4be0c12-296a-4876-b48c-e453d60f9ef1.csv cleaned.
2022-05-09 18:36:59 e[43mdestinatione[0m > 2022-05-09 18:36:59 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(removeFileAndDropTmpTable):202 - Begin cleaning _airbyte_tmp_zvw_onboardingprogress tmp table in destination.
2022-05-09 18:36:59 e[43mdestinatione[0m > 2022-05-09 18:36:59 e[32mINFOe[m i.a.i.d.j.c.s.S3StreamCopier(removeFileAndDropTmpTable):204 - _airbyte_tmp_zvw_onboardingprogress tmp table in destination cleaned.
2022-05-09 18:36:59 e[43mdestinatione[0m > 2022-05-09 18:36:59 e[32mINFOe[m i.a.i.d.r.RedshiftStreamCopier(removeFileAndDropTmpTable):105 - Begin cleaning s3 manifest file null/37b16dbd-ffc2-411e-bfff-e9ffd29f79cb/suf_atlas_raw/a6ca8c66-e7c2-45b2-9203-c2ee136ec3d5.manifest.
2022-05-09 18:36:59 e[43mdestinatione[0m > 2022-05-09 18:36:59 e[32mINFOe[m i.a.i.d.r.RedshiftStreamCopier(removeFileAndDropTmpTable):109 - S3 manifest file null/37b16dbd-ffc2-411e-bfff-e9ffd29f79cb/suf_atlas_raw/a6ca8c66-e7c2-45b2-9203-c2ee136ec3d5.manifest cleaned.
2022-05-09 18:36:59 e[32mINFOe[m i.a.w.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$6):349 - State in DefaultReplicationWorker from destination: io.airbyte.protocol.models.AirbyteMessage@d4d33a2[type=STATE,log=<null>,spec=<null>,connectionStatus=<null>,catalog=<null>,record=<null>,state=io.airbyte.protocol.models.AirbyteStateMessage@38acc7b[data={"cdc":false,"streams":[{"stream_name":"OnboardingProgress","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-09T18:34:20.663Z"},{"stream_name":"WorkoutWithoutTriggers","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-07T10:16:15.701Z"}]},additionalProperties={}],additionalProperties={}]
2022-05-09 18:36:59 e[43mdestinatione[0m > 2022-05-09 18:36:59 e[32mINFOe[m i.a.i.b.IntegrationRunner(runInternal):169 - Completed integration: io.airbyte.integrations.destination.redshift.RedshiftDestination
2022-05-09 18:36:59 e[43mdestinatione[0m > 2022-05-09 18:36:59 e[32mINFOe[m i.a.i.d.r.RedshiftDestination(main):79 - completed destination: class io.airbyte.integrations.destination.redshift.RedshiftDestination
2022-05-09 18:36:59 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):165 - Source and destination threads complete.
2022-05-09 18:36:59 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):228 - sync summary: io.airbyte.config.ReplicationAttemptSummary@355fdf8c[status=completed,recordsSynced=134,bytesSynced=40598,startTime=1652121395369,endTime=1652121419546,totalStats=io.airbyte.config.SyncStats@6f479795[recordsEmitted=134,bytesEmitted=40598,stateMessagesEmitted=2,recordsCommitted=134],streamStats=[io.airbyte.config.StreamSyncStats@67255908[streamName=OnboardingProgress,stats=io.airbyte.config.SyncStats@7a3c8dee[recordsEmitted=134,bytesEmitted=40598,stateMessagesEmitted=<null>,recordsCommitted=134]]]]
2022-05-09 18:36:59 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):248 - Source output at least one state message
2022-05-09 18:36:59 e[32mINFOe[m i.a.w.DefaultReplicationWorker(run):254 - State capture: Updated state to: Optional[io.airbyte.config.State@31d48e9a[state={"cdc":false,"streams":[{"stream_name":"OnboardingProgress","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-09T18:34:20.663Z"},{"stream_name":"WorkoutWithoutTriggers","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-07T10:16:15.701Z"}]}]]
2022-05-09 18:36:59 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(get):131 - Stopping cancellation check scheduling...
2022-05-09 18:36:59 e[32mINFOe[m i.a.w.t.s.ReplicationActivityImpl(lambda$replicate$1):147 - sync summary: io.airbyte.config.StandardSyncOutput@29a45c8e[standardSyncSummary=io.airbyte.config.StandardSyncSummary@538e80d7[status=completed,recordsSynced=134,bytesSynced=40598,startTime=1652121395369,endTime=1652121419546,totalStats=io.airbyte.config.SyncStats@6f479795[recordsEmitted=134,bytesEmitted=40598,stateMessagesEmitted=2,recordsCommitted=134],streamStats=[io.airbyte.config.StreamSyncStats@67255908[streamName=OnboardingProgress,stats=io.airbyte.config.SyncStats@7a3c8dee[recordsEmitted=134,bytesEmitted=40598,stateMessagesEmitted=<null>,recordsCommitted=134]]]],state=io.airbyte.config.State@31d48e9a[state={"cdc":false,"streams":[{"stream_name":"OnboardingProgress","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-09T18:34:20.663Z"},{"stream_name":"WorkoutWithoutTriggers","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-07T10:16:15.701Z"}]}],outputCatalog=io.airbyte.protocol.models.ConfiguredAirbyteCatalog@5166a1b8[streams=[io.airbyte.protocol.models.ConfiguredAirbyteStream@289dc10[stream=io.airbyte.protocol.models.AirbyteStream@9c2a0e3[name=OnboardingProgress,jsonSchema={"type":"object","properties":{"_id":{"type":"string"},"step":{"type":"string"},"input":{"type":"string"},"_p_user":{"type":"string"},"platform":{"type":"string"},"appVersion":{"type":"string"},"_created_at":{"type":"string"},"_updated_at":{"type":"string"},"calculation":{"type":"string"},"completedDate":{"type":"string"}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[],namespace=suf_atlas_raw,additionalProperties={}],syncMode=incremental,cursorField=[_updated_at],destinationSyncMode=append,primaryKey=[],additionalProperties={}], io.airbyte.protocol.models.ConfiguredAirbyteStream@2eed0134[stream=io.airbyte.protocol.models.AirbyteStream@4a620e30[name=WorkoutWithoutTriggers,jsonSchema={"type":"object","properties":{"_id":{"type":"string"},"name":{"type":"string"},"tags":{"type":"array"},"brand":{"type":"string"},"level":{"type":"string"},"notes":{"type":"string"},"sport":{"type":"string"},"hidden":{"type":"boolean"},"isFree":{"type":"boolean"},"isTest":{"type":"boolean"},"bestFor":{"type":"string"},"details":{"type":"string"},"_p_style":{"type":"string"},"_p_video":{"type":"string"},"nameIcon":{"type":"string"},"rating1m":{"type":"number"},"rating5m":{"type":"number"},"rating5s":{"type":"number"},"videoUrl":{"type":"string"},"breakdown":{"type":"string"},"equipment":{"type":"array"},"rating20m":{"type":"number"},"sortOrder":{"type":"number"},"thumbnail":{"type":"string"},"_p_creator":{"type":"string"},"previewUrl":{"type":"string"},"stampImage":{"type":"string"},"_created_at":{"type":"string"},"_updated_at":{"type":"string"},"breakdownV2":{"type":"string"},"description":{"type":"string"},"downloadUrl":{"type":"string"},"imperatives":{"type":"string"},"_p_cleanVideo":{"type":"string"},"_p_instructor":{"type":"string"},"_p_systmVideo":{"type":"string"},"cloudfrontUrl":{"type":"string"},"nonAppWorkout":{"type":"boolean"},"previewImage1":{"type":"string"},"previewImage2":{"type":"string"},"previewImage3":{"type":"string"},"tagsFormatted":{"type":"string"},"generateSounds":{"type":"boolean"},"trainingPeaksId":{"type":"string"},"_p_featuredRace1":{"type":"string"},"_p_featuredRace2":{"type":"string"},"_p_featuredRace3":{"type":"string"},"_p_featuredRace4":{"type":"string"},"previewThumbnail":{"type":"string"},"shortDescription":{"type":"string"},"durationSecondsV3":{"type":"number"},"_p_promotedWorkout":{"type":"string"},"tss_aibyte_transform":{"type":"string"},"durationSeconds_aibyte_transform":{"type":"string"},"intensityFactor_aibyte_transform":{"type":"string"},"durationSecondsV2_aibyte_transform":{"type":"string"}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[],namespace=suf_atlas_raw,additionalProperties={}],syncMode=incremental,cursorField=[_updated_at],destinationSyncMode=append,primaryKey=[],additionalProperties={}]],additionalProperties={}],failures=[]]
2022-05-09 18:36:59 e[32mINFOe[m i.a.w.t.TemporalUtils(withBackgroundHeartbeat):235 - Stopping temporal heartbeating...
2022-05-09 18:36:59 e[32mINFOe[m i.a.c.p.ConfigRepository(updateConnectionState):543 - Updating connection 560373a7-2d53-4e06-b717-54b55c8452c9 state: io.airbyte.config.State@5c3c0975[state={"cdc":false,"streams":[{"stream_name":"OnboardingProgress","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-09T18:34:20.663Z"},{"stream_name":"WorkoutWithoutTriggers","stream_namespace":"parse","cursor_field":["_updated_at"],"cursor":"2022-05-07T10:16:15.701Z"}]}]
2022-05-09 18:36:59 e[33mWARNe[m i.a.s.p.JobNotifier(notifyJob):104 - Failed to successfully notify success: io.airbyte.config.Notification@4f64b0a9[notificationType=slack,sendOnSuccess=false,sendOnFailure=true,slackConfiguration=io.airbyte.config.SlackNotificationConfiguration@16848131[webhook=myhook],additionalProperties={}]

jeff.crooks · May 10, 2022, 8:27pm

After around 30minutes, here’s the first log message

2022-05-10 20:20:32 WARN i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):298 - Record schema validation failed. Errors: json schema validation failed when comparing the data to the json schema

marcosmarxm · May 11, 2022, 2:13am

Jeff did you update the Mongodb connector version too?

jeff.crooks · May 11, 2022, 7:51pm

I didn’t. I upgraded Airbyte platform which auto updated all my connectors and broke nearly everything

marcosmarxm · May 12, 2022, 12:43am

I didn’t. I upgraded Airbyte platform which auto updated all my connectors and broke nearly everything

strange, upgrade Airbyte should update connector only in patch versions… but a few connectors had breaking changes even in patch update.

jeff.crooks · May 12, 2022, 12:57pm

Updating the connectors at all on platform upgrade shouldnt happen in my opinion, and has definitely changed from previous behavior

jeff.crooks · May 13, 2022, 2:21pm

Legacy Connector

v2 Connector

It’s the same server for both connectors, the v2 connector loaded the same incremental in less than a minute previous to upgrade.

marcosmarxm · May 18, 2022, 8:28pm

Jeff you had opened this issue https://github.com/airbytehq/airbyte/issues/6544 and said the issue was solved in version 0.1.9. Does it work for a while and now it’s not working anymore or never worked as you expected compared to older version?

jeff.crooks · May 24, 2022, 6:02pm

It worked fine until the latest upgrade

marcosmarxm · May 25, 2022, 12:06am

Tomorrow I’ll test using the numbers of posted in the issue with latest version of Airbyte.

jeff.crooks · June 1, 2022, 1:09pm

Any update on testing results?

marcosmarxm · June 2, 2022, 9:26pm

I tried to sync sample_trainingfrom sample Atlas data. Both connectors took a while until connect to the shard and after the sync for both runs normally.
Jeff are you using Redshift normalization? Maybe this is causing the lag? (not likely) because you said you’re syncing same collection with both connectors.

Do you have a sample dataset to test both connectors with full refresh?

With new connector

with legacy connector

jeff.crooks · June 3, 2022, 6:33pm

Both are using (the same) dbt transforms

marcosmarxm · June 5, 2022, 11:36pm

Jeff if you create a new instance and deploy only the connectors again to that new instance to test it, do you mind doing this test. Unfortunately I couldn’t be able to reproduce the performance degradation you said. Maybe you give more info about network details and the schema itself so we can recreate it.

jeff.crooks · June 6, 2022, 2:32pm

Attempting to setup a new source never completes schema discovery

marcosmarxm · June 7, 2022, 10:01pm

With both connectors?

jeff.crooks · June 8, 2022, 2:42pm

Legacy connector works, new one does not

marcosmarxm · June 13, 2022, 10:55pm

(schedule meeting with Jeff to get more context to reproduce issue)

jeff.crooks · July 6, 2022, 7:10pm

Here’s the error from server logs. I can no longer refresh schema using the old or new connectors


2022-07-06 18:34:56 e[1;31mERRORe[m i.a.s.e.UncaughtExceptionMapper(toResponse):22 - Uncaught exception
java.lang.NullPointerException: Cannot invoke "io.airbyte.api.model.generated.AirbyteCatalog.getStreams()" because "discovered" is null
	at io.airbyte.server.handlers.WebBackendConnectionsHandler.updateSchemaWithDiscovery(WebBackendConnectionsHandler.java:302) ~[io.airbyte-airbyte-server-0.39.34-alpha.jar:?]
	at io.airbyte.server.handlers.WebBackendConnectionsHandler.webBackendGetConnection(WebBackendConnectionsHandler.java:246) ~[io.airbyte-airbyte-server-0.39.34-alpha.jar:?]
	at io.airbyte.server.apis.ConfigurationApi.lambda$webBackendGetConnection$88(ConfigurationApi.java:812) ~[io.airbyte-airbyte-server-0.39.34-alpha.jar:?]
	at io.airbyte.server.apis.ConfigurationApi.execute(ConfigurationApi.java:868) ~[io.airbyte-airbyte-server-0.39.34-alpha.jar:?]
	at io.airbyte.server.apis.ConfigurationApi.webBackendGetConnection(ConfigurationApi.java:812) ~[io.airbyte-airbyte-server-0.39.34-alpha.jar:?]
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:52) ~[jersey-server-2.31.jar:?]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:124) ~[jersey-server-2.31.jar:?]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:167) ~[jersey-server-2.31.jar:?]
	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:219) ~[jersey-server-2.31.jar:?]
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:79) ~[jersey-server-2.31.jar:?]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:469) ~[jersey-server-2.31.jar:?]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:391) ~[jersey-server-2.31.jar:?]
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:80) ~[jersey-server-2.31.jar:?]
	at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:253) ~[jersey-server-2.31.jar:?]
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) ~[jersey-common-2.31.jar:?]
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) ~[jersey-common-2.31.jar:?]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:292) ~[jersey-common-2.31.jar:?]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:274) ~[jersey-common-2.31.jar:?]
	at org.glassfish.jersey.internal.Errors.process(Errors.java:244) ~[jersey-common-2.31.jar:?]
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265) ~[jersey-common-2.31.jar:?]
	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:232) ~[jersey-server-2.31.jar:?]
	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:680) ~[jersey-server-2.31.jar:?]
	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:394) ~[jersey-container-servlet-core-2.31.jar:?]
	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346) ~[jersey-container-servlet-core-2.31.jar:?]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:366) ~[jersey-container-servlet-core-2.31.jar:?]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:319) ~[jersey-container-servlet-core-2.31.jar:?]
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205) ~[jersey-container-servlet-core-2.31.jar:?]
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:763) ~[jetty-servlet-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:569) ~[jetty-servlet-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[jetty-server-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1377) ~[jetty-server-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[jetty-server-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:507) ~[jetty-servlet-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[jetty-server-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1292) ~[jetty-server-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[jetty-server-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[jetty-server-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.server.Server.handle(Server.java:501) ~[jetty-server-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383) ~[jetty-server-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:556) [jetty-server-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375) [jetty-server-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273) [jetty-server-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [jetty-io-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) [jetty-io-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) [jetty-io-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [jetty-util-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [jetty-util-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [jetty-util-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [jetty-util-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375) [jetty-util-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806) [jetty-util-9.4.31.v20200723.jar:9.4.31.v20200723]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938) [jetty-util-9.4.31.v20200723.jar:9.4.31.v20200723]
	at java.lang.Thread.run(Thread.java:833) [?:?]
2022-07-06 18:34:56 e[1;31mERRORe[m i.a.s.RequestLogger(filter):110 - REQ 172.22.0.4 POST 500 /api/v1/web_backend/connections/get - {"connectionId":"bf3aba72-2685-4990-929e-6b37b891211f","withRefreshedCatalog":true}

Topic		Replies	Views
Mongodb to s3 connection failing with same errors Connector Questions & Issues source-mongo-db , destination-s3 , data-loading , connectors	3	643	July 14, 2022
MySQL source connector: slow CDC replication Connector Questions & Issues source-mysql	6	544	September 23, 2022
MySql source connector - slow performance - full refresh Connector Questions & Issues source-mysql , destination-redshift , connectors , performance	0	491	June 27, 2023
Connectors Failing with Sync Failed Message Platform Questions platform , question , mongodb-source , postgres-source , connectors-failing	0	3	August 9, 2024
Sync worker failed Zendesk -> Redshift Connector Questions & Issues destination-redshift	6	423	July 14, 2022

Severe Performance Degradation Mongo Connector

Related topics