2022-06-30 08:42:13 INFO i.a.v.j.JsonSchemaValidator(test):71 - JSON schema validation failed. errors: $.compression_codec: is missing but it is required, $.format_type: does not have a value in the enumeration [Avro] 2022-06-30 08:42:13 INFO i.a.v.j.JsonSchemaValidator(test):71 - JSON schema validation failed. errors: $.flattening: is missing but it is required, $.format_type: does not have a value in the enumeration [CSV] 2022-06-30 08:42:13 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/33/0/logs.log 2022-06-30 08:42:13 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: 0.39.28-alpha 2022-06-30 08:42:13 INFO i.a.c.i.LineGobbler(voidCall):82 - Checking if 229217603461.dkr.ecr.eu-west-1.amazonaws.com/airbyte_connectors:crossref-metadata-api-v1.2 exists... 2022-06-30 08:42:13 INFO i.a.c.i.LineGobbler(voidCall):82 - 229217603461.dkr.ecr.eu-west-1.amazonaws.com/airbyte_connectors:crossref-metadata-api-v1.2 was found locally. 2022-06-30 08:42:13 INFO i.a.w.p.DockerProcessFactory(create):108 - Creating docker job ID: 33 2022-06-30 08:42:13 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/33/0 --log-driver none --name airbyte_connectors-check-33-0-utfec --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e AIRBYTE_ROLE= -e WORKER_ENVIRONMENT=DOCKER -e WORKER_CONNECTOR_IMAGE=229217603461.dkr.ecr.eu-west-1.amazonaws.com/airbyte_connectors:crossref-metadata-api-v1.2 -e WORKER_JOB_ATTEMPT=0 -e AIRBYTE_VERSION=0.39.28-alpha -e WORKER_JOB_ID=33 229217603461.dkr.ecr.eu-west-1.amazonaws.com/airbyte_connectors:crossref-metadata-api-v1.2 check --config source_config.json 2022-06-30 08:42:15 INFO i.a.w.i.DefaultAirbyteStreamFactory(internalLog):97 - Check succeeded 2022-06-30 08:42:15 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling... 2022-06-30 08:42:15 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/33/0/logs.log 2022-06-30 08:42:15 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: 0.39.28-alpha 2022-06-30 08:42:15 INFO i.a.c.i.LineGobbler(voidCall):82 - Checking if airbyte/destination-s3:0.2.12 exists... 2022-06-30 08:42:15 INFO i.a.c.i.LineGobbler(voidCall):82 - airbyte/destination-s3:0.2.12 was found locally. 2022-06-30 08:42:15 INFO i.a.w.p.DockerProcessFactory(create):108 - Creating docker job ID: 33 2022-06-30 08:42:15 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/33/0 --log-driver none --name destination-s3-check-33-0-eankl --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e AIRBYTE_ROLE= -e WORKER_ENVIRONMENT=DOCKER -e WORKER_CONNECTOR_IMAGE=airbyte/destination-s3:0.2.12 -e WORKER_JOB_ATTEMPT=0 -e AIRBYTE_VERSION=0.39.28-alpha -e WORKER_JOB_ID=33 airbyte/destination-s3:0.2.12 check --config source_config.json 2022-06-30 08:42:16 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: Class path contains multiple SLF4J bindings. 2022-06-30 08:42:16 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: Found binding in [jar:file:/airbyte/lib/log4j-slf4j-impl-2.17.1.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2022-06-30 08:42:16 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: Found binding in [jar:file:/airbyte/lib/slf4j-log4j12-1.7.25.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2022-06-30 08:42:16 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. 2022-06-30 08:42:16 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory] 2022-06-30 08:42:17 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:17 INFO i.a.i.b.IntegrationCliParser(parseOptions):118 - integration args: {check=null, config=source_config.json} 2022-06-30 08:42:17 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:17 INFO i.a.i.b.IntegrationRunner(runInternal):121 - Running integration: io.airbyte.integrations.destination.s3.S3Destination 2022-06-30 08:42:17 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:17 INFO i.a.i.b.IntegrationRunner(runInternal):122 - Command: CHECK 2022-06-30 08:42:17 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:17 INFO i.a.i.b.IntegrationRunner(runInternal):123 - Integration config: IntegrationConfig{command=CHECK, configPath='source_config.json', catalogPath='null', statePath='null'} 2022-06-30 08:42:17 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:17 WARN 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-06-30 08:42:17 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:17 WARN 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-06-30 08:42:17 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:17 WARN 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-06-30 08:42:17 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:17 INFO i.a.i.d.s.S3FormatConfigs(getS3FormatConfig):22 - S3 format config: {"format_type":"JSONL","part_size_mb":5} 2022-06-30 08:42:17 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:17 INFO i.a.i.d.s.S3DestinationConfig(createS3Client):169 - Creating S3 client... 2022-06-30 08:42:18 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:18 INFO i.a.i.d.s.S3StorageOperations(createBucketObjectIfNotExists):74 - Storage Object koldev-crossref/koldev-crossref does not exist in bucket; creating... 2022-06-30 08:42:18 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:18 INFO i.a.i.d.s.S3StorageOperations(createBucketObjectIfNotExists):76 - Storage Object koldev-crossref/koldev-crossref has been created in bucket. 2022-06-30 08:42:18 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:18 INFO i.a.i.d.s.S3Destination(testIAMUserHasListObjectPermission):154 - Started testing if IAM user can call listObjects on the destination bucket 2022-06-30 08:42:18 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:18 INFO i.a.i.d.s.S3Destination(testIAMUserHasListObjectPermission):157 - Finished checking for listObjects permission 2022-06-30 08:42:18 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:18 INFO i.a.i.d.s.S3Destination(testSingleUpload):81 - Started testing if all required credentials assigned to user for single file uploading 2022-06-30 08:42:18 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:18 INFO i.a.i.d.s.S3Destination(testSingleUpload):88 - Finished checking for normal upload mode 2022-06-30 08:42:18 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:18 INFO i.a.i.d.s.S3Destination(testMultipartUpload):92 - Started testing if all required credentials assigned to user for multipart upload 2022-06-30 08:42:18 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:18 INFO i.a.i.d.s.u.StreamTransferManagerHelper(getDefault):55 - PartSize arg is set to 5 MB 2022-06-30 08:42:18 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:18 INFO a.m.s.StreamTransferManager(getMultiPartOutputStreams):329 - Initiated multipart upload to koldev-crossref/test_1656578538717 with full ID ERDh7bcextixoFHxVPtRNDWaAd4mqjaWK8QBG.wSiU5ycoq3EqhBZ0atWsS4oPZi_QZH6DmjPMzh9W5QTN0o2tm4q7wehrGiP40xukZuxTGhY3wAQz4MwDytNJqRv7AWTTgJk_qbv9jh4CZFgmn8SQ-- 2022-06-30 08:42:18 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:18 INFO a.m.s.MultiPartOutputStream(close):158 - Called close() on [MultipartOutputStream for parts 1 - 10000] 2022-06-30 08:42:18 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:18 INFO a.m.s.MultiPartOutputStream(close):158 - Called close() on [MultipartOutputStream for parts 1 - 10000] 2022-06-30 08:42:18 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:18 WARN a.m.s.MultiPartOutputStream(close):160 - [MultipartOutputStream for parts 1 - 10000] is already closed 2022-06-30 08:42:18 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:18 INFO a.m.s.StreamTransferManager(complete):367 - [Manager uploading to koldev-crossref/test_1656578538717 with id ERDh7bcex...Fgmn8SQ--]: Uploading leftover stream [Part number 1 containing 3.34 MB] 2022-06-30 08:42:19 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:19 INFO a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to koldev-crossref/test_1656578538717 with id ERDh7bcex...Fgmn8SQ--]: Finished uploading [Part number 1 containing 3.34 MB] 2022-06-30 08:42:19 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:19 INFO a.m.s.StreamTransferManager(complete):395 - [Manager uploading to koldev-crossref/test_1656578538717 with id ERDh7bcex...Fgmn8SQ--]: Completed 2022-06-30 08:42:19 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-30 08:42:19 INFO i.a.i.d.s.S3Destination(testMultipartUpload):118 - Finished verification for multipart upload mode 2022-06-30 08:42:19 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling... 2022-06-30 08:42:19 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/33/0/logs.log 2022-06-30 08:42:19 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: 0.39.28-alpha 2022-06-30 08:42:19 INFO i.a.w.g.DefaultReplicationWorker(run):115 - start sync worker. job id: 33 attempt id: 0 2022-06-30 08:42:19 INFO i.a.w.g.DefaultReplicationWorker(run):127 - configured sync modes: {null.works=full_refresh - append} 2022-06-30 08:42:19 INFO i.a.w.i.DefaultAirbyteDestination(start):69 - Running destination... 2022-06-30 08:42:19 INFO i.a.c.i.LineGobbler(voidCall):82 - Checking if airbyte/destination-s3:0.2.12 exists... 2022-06-30 08:42:19 INFO i.a.c.i.LineGobbler(voidCall):82 - airbyte/destination-s3:0.2.12 was found locally. 2022-06-30 08:42:19 INFO i.a.w.p.DockerProcessFactory(create):108 - Creating docker job ID: 33 2022-06-30 08:42:19 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/33/0 --log-driver none --name destination-s3-write-33-0-lviel --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e AIRBYTE_ROLE= -e WORKER_ENVIRONMENT=DOCKER -e WORKER_CONNECTOR_IMAGE=airbyte/destination-s3:0.2.12 -e WORKER_JOB_ATTEMPT=0 -e AIRBYTE_VERSION=0.39.28-alpha -e WORKER_JOB_ID=33 airbyte/destination-s3:0.2.12 write --config destination_config.json --catalog destination_catalog.json 2022-06-30 08:42:19 INFO i.a.c.i.LineGobbler(voidCall):82 - Checking if 229217603461.dkr.ecr.eu-west-1.amazonaws.com/airbyte_connectors:crossref-metadata-api-v1.2 exists... 2022-06-30 08:42:19 INFO i.a.c.i.LineGobbler(voidCall):82 - 229217603461.dkr.ecr.eu-west-1.amazonaws.com/airbyte_connectors:crossref-metadata-api-v1.2 was found locally. 2022-06-30 08:42:19 INFO i.a.w.p.DockerProcessFactory(create):108 - Creating docker job ID: 33 2022-06-30 08:42:19 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/33/0 --log-driver none --name airbyte_connectors-read-33-0-xqrjz --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e AIRBYTE_ROLE= -e WORKER_ENVIRONMENT=DOCKER -e WORKER_CONNECTOR_IMAGE=229217603461.dkr.ecr.eu-west-1.amazonaws.com/airbyte_connectors:crossref-metadata-api-v1.2 -e WORKER_JOB_ATTEMPT=0 -e AIRBYTE_VERSION=0.39.28-alpha -e WORKER_JOB_ID=33 229217603461.dkr.ecr.eu-west-1.amazonaws.com/airbyte_connectors:crossref-metadata-api-v1.2 read --config source_config.json --catalog source_catalog.json 2022-06-30 08:42:19 INFO i.a.w.g.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$7):405 - Destination output thread started. 2022-06-30 08:42:19 INFO i.a.w.g.DefaultReplicationWorker(run):169 - Waiting for source and destination threads to complete. 2022-06-30 08:42:19 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):298 - Replication thread started. 2022-06-30 08:42:20 destination > SLF4J: Class path contains multiple SLF4J bindings. 2022-06-30 08:42:20 destination > SLF4J: Found binding in [jar:file:/airbyte/lib/log4j-slf4j-impl-2.17.1.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2022-06-30 08:42:20 destination > SLF4J: Found binding in [jar:file:/airbyte/lib/slf4j-log4j12-1.7.25.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2022-06-30 08:42:20 destination > SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. 2022-06-30 08:42:20 destination > SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory] 2022-06-30 08:42:21 source > Starting syncing SourceCrossrefMetadataApi 2022-06-30 08:42:22 source > Syncing stream: works 2022-06-30 08:42:22 destination > 2022-06-30 08:42:22 INFO i.a.i.b.IntegrationCliParser(parseOptions):118 - integration args: {catalog=destination_catalog.json, write=null, config=destination_config.json} 2022-06-30 08:42:22 destination > 2022-06-30 08:42:22 INFO i.a.i.b.IntegrationRunner(runInternal):121 - Running integration: io.airbyte.integrations.destination.s3.S3Destination 2022-06-30 08:42:22 destination > 2022-06-30 08:42:22 INFO i.a.i.b.IntegrationRunner(runInternal):122 - Command: WRITE 2022-06-30 08:42:22 destination > 2022-06-30 08:42:22 INFO i.a.i.b.IntegrationRunner(runInternal):123 - Integration config: IntegrationConfig{command=WRITE, configPath='destination_config.json', catalogPath='destination_catalog.json', statePath='null'} 2022-06-30 08:42:22 destination > 2022-06-30 08:42:22 WARN 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-06-30 08:42:22 destination > 2022-06-30 08:42:22 WARN 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-06-30 08:42:22 destination > 2022-06-30 08:42:22 WARN 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-06-30 08:42:22 destination > 2022-06-30 08:42:22 INFO i.a.i.d.s.S3FormatConfigs(getS3FormatConfig):22 - S3 format config: {"format_type":"JSONL","part_size_mb":5} 2022-06-30 08:42:22 destination > 2022-06-30 08:42:22 INFO i.a.i.d.s.S3DestinationConfig(createS3Client):169 - Creating S3 client... 2022-06-30 08:42:23 destination > 2022-06-30 08:42:23 INFO i.a.i.d.s.SerializedBufferFactory(getCreateFunction):50 - S3 format config: {"format_type":"JSONL","part_size_mb":5} 2022-06-30 08:42:23 destination > 2022-06-30 08:42:23 INFO i.a.i.d.s.S3ConsumerFactory(lambda$toWriteConfig$0):90 - Write config: WriteConfig{streamName=works, namespace=null, outputNamespace=publications_downloaded, outputBucketPath=publications_downloaded/works/, syncMode=append} 2022-06-30 08:42:23 destination > 2022-06-30 08:42:23 INFO i.a.i.d.b.BufferedStreamConsumer(startTracked):116 - class io.airbyte.integrations.destination.buffered_stream_consumer.BufferedStreamConsumer started. 2022-06-30 08:42:23 destination > 2022-06-30 08:42:23 INFO i.a.i.d.s.S3ConsumerFactory(lambda$onStartFunction$2):105 - Preparing bucket in destination started for 1 streams 2022-06-30 08:42:23 destination > 2022-06-30 08:42:23 INFO i.a.i.d.s.S3ConsumerFactory(lambda$onStartFunction$2):119 - Preparing storage area in destination completed. 2022-06-30 08:42:35 destination > 2022-06-30 08:42:35 INFO i.a.i.d.r.SerializedBufferingStrategy(lambda$addRecord$0):55 - Starting a new buffer for stream works (current state: 0 bytes in 0 buffers)