2022-09-07 05:11:03 INFO i.a.w.w.WorkerRun(call):49 - Executing worker wrapper. Airbyte version: 0.36.4-alpha
2022-09-07 05:11:03 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/32509/0/logs.log
2022-09-07 05:11:03 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: 0.36.4-alpha
2022-09-07 05:11:03 DEBUG i.a.c.h.LogClientSingleton(setJobMdc):133 - Setting docker job mdc
2022-09-07 05:11:03 INFO i.a.w.DefaultReplicationWorker(run):104 - start sync worker. job id: 32509 attempt id: 0
2022-09-07 05:11:03 INFO i.a.w.DefaultReplicationWorker(run):116 - configured sync modes: {admin_devclubniagadb.invoice=full_refresh - overwrite}
2022-09-07 05:11:03 INFO i.a.w.p.a.DefaultAirbyteDestination(start):69 - Running destination...
2022-09-07 05:11:03 INFO i.a.c.i.LineGobbler(voidCall):82 - Checking if airbyte/destination-bigquery:1.1.11 exists...
2022-09-07 05:11:03 INFO i.a.c.i.LineGobbler(voidCall):82 - airbyte/destination-bigquery:1.1.11 was found locally.
2022-09-07 05:11:03 INFO i.a.w.p.DockerProcessFactory(create):106 - Creating docker job ID: 32509
2022-09-07 05:11:03 INFO i.a.w.p.DockerProcessFactory(create):158 - Preparing command: docker run --rm --init -i -w /data/32509/0 --log-driver none --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e WORKER_CONNECTOR_IMAGE=airbyte/destination-bigquery:1.1.11 -e WORKER_JOB_ATTEMPT=0 -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e AIRBYTE_VERSION=0.36.4-alpha -e WORKER_JOB_ID=32509 airbyte/destination-bigquery:1.1.11 write --config destination_config.json --catalog destination_catalog.json
2022-09-07 05:11:03 INFO i.a.c.i.LineGobbler(voidCall):82 - Checking if airbyte/source-mysql:0.6.9 exists...
2022-09-07 05:11:03 INFO i.a.c.i.LineGobbler(voidCall):82 - airbyte/source-mysql:0.6.9 was found locally.
2022-09-07 05:11:03 INFO i.a.w.p.DockerProcessFactory(create):106 - Creating docker job ID: 32509
2022-09-07 05:11:03 INFO i.a.w.p.DockerProcessFactory(create):158 - Preparing command: docker run --rm --init -i -w /data/32509/0 --log-driver none --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e WORKER_CONNECTOR_IMAGE=airbyte/source-mysql:0.6.9 -e WORKER_JOB_ATTEMPT=0 -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e AIRBYTE_VERSION=0.36.4-alpha -e WORKER_JOB_ID=32509 airbyte/source-mysql:0.6.9 read --config source_config.json --catalog source_catalog.json --state input_state.json
2022-09-07 05:11:03 INFO i.a.w.DefaultReplicationWorker(run):158 - Waiting for source and destination threads to complete.
2022-09-07 05:11:03 INFO i.a.w.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$6):339 - Destination output thread started.
2022-09-07 05:11:03 INFO i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):279 - Replication thread started.
2022-09-07 05:11:04 destination > SLF4J: Class path contains multiple SLF4J bindings.
2022-09-07 05:11:04 destination > SLF4J: Found binding in [jar:file:/airbyte/lib/log4j-slf4j-impl-2.17.1.jar!/org/slf4j/impl/StaticLoggerBinder.class]
2022-09-07 05:11:04 destination > SLF4J: Found binding in [jar:file:/airbyte/lib/slf4j-log4j12-1.7.25.jar!/org/slf4j/impl/StaticLoggerBinder.class]
2022-09-07 05:11:04 destination > SLF4J: Found binding in [jar:file:/airbyte/lib/logback-classic-1.2.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
2022-09-07 05:11:04 destination > SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
2022-09-07 05:11:04 destination > SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory]
2022-09-07 05:11:05 source > 2022-09-07 05:11:05 INFO i.a.i.s.m.MySqlSource(main):242 - starting source: class io.airbyte.integrations.source.mysql.MySqlSource
2022-09-07 05:11:05 destination > 2022-09-07 05:11:05 INFO i.a.i.b.IntegrationCliParser(parseOptions):118 - integration args: {catalog=destination_catalog.json, write=null, config=destination_config.json}
2022-09-07 05:11:05 destination > 2022-09-07 05:11:05 INFO i.a.i.b.IntegrationRunner(runInternal):123 - Running integration: io.airbyte.integrations.destination.bigquery.BigQueryDestination
2022-09-07 05:11:05 destination > 2022-09-07 05:11:05 INFO i.a.i.b.IntegrationRunner(runInternal):124 - Command: WRITE
2022-09-07 05:11:05 destination > 2022-09-07 05:11:05 INFO i.a.i.b.IntegrationRunner(runInternal):125 - Integration config: IntegrationConfig{command=WRITE, configPath='destination_config.json', catalogPath='destination_catalog.json', statePath='null'}
2022-09-07 05:11:05 source > 2022-09-07 05:11:05 INFO i.a.i.b.IntegrationCliParser(parseOptions):118 - integration args: {read=null, catalog=source_catalog.json, state=input_state.json, config=source_config.json}
2022-09-07 05:11:05 source > 2022-09-07 05:11:05 INFO i.a.i.b.IntegrationRunner(runInternal):104 - Running integration: io.airbyte.integrations.base.ssh.SshWrappedSource
2022-09-07 05:11:05 source > 2022-09-07 05:11:05 INFO i.a.i.b.IntegrationRunner(runInternal):105 - Command: READ
2022-09-07 05:11:05 source > 2022-09-07 05:11:05 INFO i.a.i.b.IntegrationRunner(runInternal):106 - Integration config: IntegrationConfig{command=READ, configPath='source_config.json', catalogPath='source_catalog.json', statePath='input_state.json'}
2022-09-07 05:11:05 destination > 2022-09-07 05:11:05 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-09-07 05:11:05 destination > 2022-09-07 05:11:05 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-09-07 05:11:05 destination > 2022-09-07 05:11:05 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-09-07 05:11:05 destination > 2022-09-07 05:11:05 INFO i.a.i.d.b.BigQueryUtils(getLoadingMethod):304 - Selected loading method is set to: STANDARD
2022-09-07 05:11:05 destination > 2022-09-07 05:11:05 WARN i.a.i.d.b.BigQueryDestination(getConsumer):197 - The "standard" upload mode is not performant, and is not recommended for production. Please use the GCS upload mode if you are syncing a large amount of data.
2022-09-07 05:11:05 source > 2022-09-07 05:11:05 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-09-07 05:11:05 source > 2022-09-07 05:11:05 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-09-07 05:11:05 source > 2022-09-07 05:11:05 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-09-07 05:11:05 source > 2022-09-07 05:11:05 WARN 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
2022-09-07 05:11:05 source > 2022-09-07 05:11:05 ERROR i.a.i.b.AirbyteExceptionHandler(uncaughtException):26 - Something went wrong in the connector. See the logs for more details.
2022-09-07 05:11:05 source > java.lang.Exception: Verification error(s) occurred for READ. Errors: [$.replication_method: should be valid to one and only one of the schemas , $.replication_method: string found, object expected] 
2022-09-07 05:11:05 source > 	at io.airbyte.integrations.base.IntegrationRunner.validateConfig(IntegrationRunner.java:277) ~[io.airbyte.airbyte-integrations.bases-base-java-0.40.4.jar:?]
2022-09-07 05:11:05 source > 	at io.airbyte.integrations.base.IntegrationRunner.runInternal(IntegrationRunner.java:133) ~[io.airbyte.airbyte-integrations.bases-base-java-0.40.4.jar:?]
2022-09-07 05:11:05 source > 	at io.airbyte.integrations.base.IntegrationRunner.run(IntegrationRunner.java:97) ~[io.airbyte.airbyte-integrations.bases-base-java-0.40.4.jar:?]
2022-09-07 05:11:05 source > 	at io.airbyte.integrations.source.mysql.MySqlSource.main(MySqlSource.java:243) ~[io.airbyte.airbyte-integrations.connectors-source-mysql-0.40.4.jar:?]
2022-09-07 05:11:05 INFO i.a.v.j.JsonSchemaValidator(test):56 - JSON schema validation failed. 
errors: $.type: does not have a value in the enumeration [RECORD, STATE, LOG, SPEC, CONNECTION_STATUS, CATALOG]
2022-09-07 05:11:05 ERROR i.a.w.p.a.DefaultAirbyteStreamFactory(lambda$create$1):70 - Validation failed: {"type":"TRACE","trace":{"type":"ERROR","emitted_at":1.662527465733E12,"error":{"message":"Something went wrong in the connector. See the logs for more details.","internal_message":"java.lang.Exception: Verification error(s) occurred for READ. Errors: [$.replication_method: should be valid to one and only one of the schemas , $.replication_method: string found, object expected] ","stack_trace":"java.lang.Exception: Verification error(s) occurred for READ. Errors: [$.replication_method: should be valid to one and only one of the schemas , $.replication_method: string found, object expected] \n\tat io.airbyte.integrations.base.IntegrationRunner.validateConfig(IntegrationRunner.java:277)\n\tat io.airbyte.integrations.base.IntegrationRunner.runInternal(IntegrationRunner.java:133)\n\tat io.airbyte.integrations.base.IntegrationRunner.run(IntegrationRunner.java:97)\n\tat io.airbyte.integrations.source.mysql.MySqlSource.main(MySqlSource.java:243)\n","failure_type":"system_error"}}}
2022-09-07 05:11:05 destination > 2022-09-07 05:11:05 INFO i.a.i.d.b.BigQueryUtils(getLoadingMethod):304 - Selected loading method is set to: STANDARD
2022-09-07 05:11:05 INFO i.a.w.DefaultReplicationWorker(lambda$getReplicationRunnable$5):305 - Total records read: 0 (0 bytes)
2022-09-07 05:11:05 DEBUG i.a.w.p.a.DefaultAirbyteSource(close):127 - Closing source process
2022-09-07 05:11:05 DEBUG i.a.w.p.a.DefaultAirbyteDestination(close):114 - Closing destination process
2022-09-07 05:11:07 destination > 2022-09-07 05:11:07 INFO i.a.i.d.b.BigQueryUtils(createPartitionedTable):131 - Partitioned table created successfully: GenericData{classInfo=[datasetId, projectId, tableId], {datasetId=niaga, tableId=_airbyte_tmp_mdw_invoice}}
2022-09-07 05:11:08 destination > 2022-09-07 05:11:08 INFO i.a.i.b.FailureTrackingAirbyteMessageConsumer(close):65 - Airbyte message consumer: succeeded.
2022-09-07 05:11:08 destination > 2022-09-07 05:11:08 INFO i.a.i.d.b.BigQueryRecordConsumer(close):58 - Started closing all connections
2022-09-07 05:11:08 destination > 2022-09-07 05:11:08 INFO i.a.i.d.b.u.AbstractBigQueryUploader(close):78 - Closing connector: AbstractBigQueryUploader{table=_airbyte_raw_invoice, tmpTable=_airbyte_tmp_mdw_invoice, syncMode=WRITE_TRUNCATE, writer=class io.airbyte.integrations.destination.bigquery.writer.BigQueryTableWriter, recordFormatter=class io.airbyte.integrations.destination.bigquery.formatter.DefaultBigQueryRecordFormatter}
2022-09-07 05:11:08 destination > 2022-09-07 05:11:08 INFO i.a.i.d.b.u.AbstractBigQueryUploader(uploadData):95 - Uploading data from the tmp table _airbyte_tmp_mdw_invoice to the source table _airbyte_raw_invoice.
2022-09-07 05:11:08 destination > 2022-09-07 05:11:08 INFO i.a.i.d.b.u.AbstractBigQueryUploader(uploadDataToTableFromTmpTable):120 - Replication finished with no explicit errors. Copying data from tmp tables to permanent
2022-09-07 05:11:09 destination > 2022-09-07 05:11:09 INFO i.a.i.d.b.u.AbstractBigQueryUploader(copyTable):185 - successfully copied table: GenericData{classInfo=[datasetId, projectId, tableId], {datasetId=niaga, tableId=_airbyte_tmp_mdw_invoice}} to table: GenericData{classInfo=[datasetId, projectId, tableId], {datasetId=niaga, tableId=_airbyte_raw_invoice}}
2022-09-07 05:11:09 destination > 2022-09-07 05:11:09 INFO i.a.i.d.b.u.AbstractBigQueryUploader(uploadData):97 - Data is successfully loaded to the source table _airbyte_raw_invoice!
2022-09-07 05:11:09 INFO i.a.v.j.JsonSchemaValidator(test):56 - JSON schema validation failed. 
errors: $: null found, object expected
2022-09-07 05:11:09 ERROR i.a.w.p.a.DefaultAirbyteStreamFactory(lambda$create$1):70 - Validation failed: null
2022-09-07 05:11:09 destination > 2022-09-07 05:11:09 INFO i.a.i.d.b.u.AbstractBigQueryUploader(uploadData):99 - Final state message is accepted.
2022-09-07 05:11:09 destination > 2022-09-07 05:11:09 INFO i.a.i.d.b.u.AbstractBigQueryUploader(dropTmpTable):111 - Removing tmp tables...
2022-09-07 05:11:09 destination > 2022-09-07 05:11:09 INFO i.a.i.d.b.u.AbstractBigQueryUploader(dropTmpTable):113 - Finishing destination process...completed
2022-09-07 05:11:09 destination > 2022-09-07 05:11:09 INFO i.a.i.d.b.u.AbstractBigQueryUploader(close):85 - Closed connector: AbstractBigQueryUploader{table=_airbyte_raw_invoice, tmpTable=_airbyte_tmp_mdw_invoice, syncMode=WRITE_TRUNCATE, writer=class io.airbyte.integrations.destination.bigquery.writer.BigQueryTableWriter, recordFormatter=class io.airbyte.integrations.destination.bigquery.formatter.DefaultBigQueryRecordFormatter}
2022-09-07 05:11:09 destination > 2022-09-07 05:11:09 INFO i.a.i.b.IntegrationRunner(runInternal):171 - Completed integration: io.airbyte.integrations.destination.bigquery.BigQueryDestination
2022-09-07 05:11:10 ERROR i.a.w.DefaultReplicationWorker(run):169 - Sync worker failed.
java.util.concurrent.ExecutionException: io.airbyte.workers.DefaultReplicationWorker$SourceException: Source process exited with non-zero exit code 1
	at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[?:?]
	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073) ~[?:?]
	at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:162) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:57) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at java.lang.Thread.run(Thread.java:833) [?:?]
	Suppressed: io.airbyte.workers.WorkerException: Source process exit with code 1. This warning is normal if the job was cancelled.
		at io.airbyte.workers.protocols.airbyte.DefaultAirbyteSource.close(DefaultAirbyteSource.java:136) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
		at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:126) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
		at io.airbyte.workers.DefaultReplicationWorker.run(DefaultReplicationWorker.java:57) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
		at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
		at java.lang.Thread.run(Thread.java:833) [?:?]
Caused by: io.airbyte.workers.DefaultReplicationWorker$SourceException: Source process exited with non-zero exit code 1
	at io.airbyte.workers.DefaultReplicationWorker.lambda$getReplicationRunnable$5(DefaultReplicationWorker.java:312) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
	... 1 more
2022-09-07 05:11:10 INFO i.a.w.DefaultReplicationWorker(run):228 - sync summary: io.airbyte.config.ReplicationAttemptSummary@5fe71bc8[status=failed,recordsSynced=0,bytesSynced=0,startTime=1662527463609,endTime=1662527470059,totalStats=io.airbyte.config.SyncStats@26a9e828[recordsEmitted=0,bytesEmitted=0,stateMessagesEmitted=0,recordsCommitted=0],streamStats=[]]
2022-09-07 05:11:10 INFO i.a.w.DefaultReplicationWorker(run):250 - Source did not output any state messages
2022-09-07 05:11:10 WARN i.a.w.DefaultReplicationWorker(run):258 - State capture: No new state, falling back on input state: io.airbyte.config.State@1d16de76[state={}]
2022-09-07 05:11:10 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
2022-09-07 05:11:10 INFO i.a.w.t.s.ReplicationActivityImpl(lambda$replicate$3):155 - sync summary: io.airbyte.config.StandardSyncOutput@44186897[standardSyncSummary=io.airbyte.config.StandardSyncSummary@11aee70[status=failed,recordsSynced=0,bytesSynced=0,startTime=1662527463609,endTime=1662527470059,totalStats=io.airbyte.config.SyncStats@26a9e828[recordsEmitted=0,bytesEmitted=0,stateMessagesEmitted=0,recordsCommitted=0],streamStats=[]],normalizationSummary=<null>,state=io.airbyte.config.State@1d16de76[state={}],outputCatalog=io.airbyte.protocol.models.ConfiguredAirbyteCatalog@4f2b2a8f[streams=[io.airbyte.protocol.models.ConfiguredAirbyteStream@30518a9d[stream=io.airbyte.protocol.models.AirbyteStream@378a10d0[name=invoice,jsonSchema={"type":"object","properties":{"id":{"type":"number"},"nr":{"type":"string"},"hash":{"type":"string"},"notes":{"type":"string"},"serie":{"type":"string"},"credit":{"type":"number"},"due_at":{"type":"string"},"refund":{"type":"number"},"status":{"type":"string"},"hash_nh":{"type":"string"},"paid_at":{"type":"string"},"taxname":{"type":"string"},"taxrate":{"type":"string"},"approved":{"type":"number"},"buyer_zip":{"type":"string"},"client_id":{"type":"number"},"buyer_city":{"type":"string"},"created_at":{"type":"string"},"nh_taxname":{"type":"string"},"nh_taxrate":{"type":"string"},"updated_at":{"type":"string"},"base_income":{"type":"number"},"base_refund":{"type":"number"},"buyer_email":{"type":"string"},"buyer_phone":{"type":"string"},"reminded_at":{"type":"string"},"uniqcode_nh":{"type":"number"},"buyer_address":{"type":"string"},"buyer_company":{"type":"string"},"buyer_country":{"type":"string"},"invoice_id_nh":{"type":"number"},"seller_company":{"type":"string"},"buyer_last_name":{"type":"string"},"buyer_first_name":{"type":"string"},"buyer_company_number":{"type":"string"},"seller_company_email":{"type":"string"},"seller_company_phone":{"type":"string"},"seller_company_number":{"type":"string"},"seller_company_address":{"type":"string"}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[[id]],namespace=<null>,additionalProperties={}],syncMode=full_refresh,cursorField=[updated_at],destinationSyncMode=overwrite,primaryKey=[[id]],additionalProperties={}]],additionalProperties={}],failures=[io.airbyte.config.FailureReason@6135113f[failureOrigin=source,failureType=<null>,internalMessage=io.airbyte.workers.DefaultReplicationWorker$SourceException: Source process exited with non-zero exit code 1,externalMessage=Something went wrong within the source connector,metadata=io.airbyte.config.Metadata@77dc20c4[additionalProperties={attemptNumber=0, jobId=32509}],stacktrace=java.util.concurrent.CompletionException: io.airbyte.workers.DefaultReplicationWorker$SourceException: Source process exited with non-zero exit code 1
	at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:315)
	at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:320)
	at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1807)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: io.airbyte.workers.DefaultReplicationWorker$SourceException: Source process exited with non-zero exit code 1
	at io.airbyte.workers.DefaultReplicationWorker.lambda$getReplicationRunnable$5(DefaultReplicationWorker.java:312)
	at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804)
	... 3 more
,retryable=<null>,timestamp=1662527465914]]]
2022-09-07 05:11:10 INFO i.a.w.t.TemporalUtils(withBackgroundHeartbeat):236 - Stopping temporal heartbeating...
2022-09-07 05:11:10 INFO i.a.c.p.ConfigRepository(updateConnectionState):774 - Updating connection 376ad4ff-b4f3-44e6-8075-bc4159f0f99d state: io.airbyte.config.State@73375ad0[state={}]
2022-09-07 05:11:10 DEBUG i.a.c.h.LogClientSingleton(setJobMdc):133 - Setting docker job mdc
2022-09-07 05:11:10 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/32509/0/logs.log
2022-09-07 05:11:10 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: 0.36.4-alpha
2022-09-07 05:11:10 DEBUG i.a.c.h.LogClientSingleton(setJobMdc):133 - Setting docker job mdc
2022-09-07 05:11:10 INFO i.a.w.DefaultNormalizationWorker(run):47 - Running normalization.
2022-09-07 05:11:10 INFO i.a.w.n.DefaultNormalizationRunner(runProcess):122 - Running with normalization version: airbyte/normalization:0.1.77
2022-09-07 05:11:10 INFO i.a.c.i.LineGobbler(voidCall):82 - Checking if airbyte/normalization:0.1.77 exists...
2022-09-07 05:11:10 INFO i.a.c.i.LineGobbler(voidCall):82 - airbyte/normalization:0.1.77 was found locally.
2022-09-07 05:11:10 INFO i.a.w.p.DockerProcessFactory(create):106 - Creating docker job ID: 32509
2022-09-07 05:11:10 INFO i.a.w.p.DockerProcessFactory(create):158 - Preparing command: docker run --rm --init -i -w /data/32509/0/normalize --log-driver none --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e AIRBYTE_VERSION=0.36.4-alpha airbyte/normalization:0.1.77 run --integration-type bigquery --config destination_config.json --catalog destination_catalog.json
2022-09-07 05:11:10 normalization > Running: transform-config --config destination_config.json --integration-type bigquery --out /data/32509/0/normalize
2022-09-07 05:11:10 normalization > Namespace(config='destination_config.json', integration_type=<DestinationType.BIGQUERY: 'bigquery'>, out='/data/32509/0/normalize')
2022-09-07 05:11:10 normalization > transform_bigquery
2022-09-07 05:11:10 normalization > Running: transform-catalog --integration-type bigquery --profile-config-dir /data/32509/0/normalize --catalog destination_catalog.json --out /data/32509/0/normalize/models/generated/ --json-column _airbyte_data
2022-09-07 05:11:10 normalization > Processing destination_catalog.json...
2022-09-07 05:11:10 normalization >   Generating airbyte_ctes/niaga/invoice_ab1.sql from invoice
2022-09-07 05:11:10 normalization >   Generating airbyte_ctes/niaga/invoice_ab2.sql from invoice
2022-09-07 05:11:10 normalization >   Generating airbyte_ctes/niaga/invoice_ab3.sql from invoice
2022-09-07 05:11:10 normalization >   Generating airbyte_tables/niaga/invoice.sql from invoice
2022-09-07 05:11:10 normalization > detected no config file for ssh, assuming ssh is off.
2022-09-07 05:11:13 normalization >            [--event-buffer-size EVENT_BUFFER_SIZE]
2022-09-07 05:11:13 normalization >   --event-buffer-size EVENT_BUFFER_SIZE
2022-09-07 05:11:13 normalization > 
2022-09-07 05:11:13 normalization > DBT >=1.0.0 detected; using 10K event buffer size
2022-09-07 05:11:13 normalization > 
2022-09-07 05:11:16 normalization > 05:11:16  Running with dbt=1.0.0
2022-09-07 05:11:16 normalization > 05:11:16  Partial parse save file not found. Starting full parse.
2022-09-07 05:11:18 normalization > 05:11:18  [WARNING]: Configuration paths exist in your dbt_project.yml file which do not apply to any resources.
2022-09-07 05:11:18 normalization > There are 2 unused configuration paths:
2022-09-07 05:11:18 normalization > - models.airbyte_utils.generated.airbyte_incremental
2022-09-07 05:11:18 normalization > - models.airbyte_utils.generated.airbyte_views
2022-09-07 05:11:18 normalization > 
2022-09-07 05:11:18 normalization > 05:11:18  Found 4 models, 0 tests, 0 snapshots, 0 analyses, 544 macros, 0 operations, 0 seed files, 1 source, 0 exposures, 0 metrics
2022-09-07 05:11:18 normalization > 05:11:18  
2022-09-07 05:11:18 normalization > 05:11:18  Concurrency: 8 threads (target='prod')
2022-09-07 05:11:18 normalization > 05:11:18  
2022-09-07 05:11:19 normalization > 05:11:19  1 of 1 START table model niaga.invoice.................................................................................. [RUN]
2022-09-07 05:11:20 DEBUG i.a.c.h.LogClientSingleton(setJobMdc):133 - Setting docker job mdc
2022-09-07 05:11:22 normalization > 05:11:22  1 of 1 OK created table model niaga.invoice............................................................................. [CREATE TABLE (0.0 rows, 0 processed) in 3.32s]
2022-09-07 05:11:22 normalization > 05:11:22  
2022-09-07 05:11:22 normalization > 05:11:22  Finished running 1 table model in 4.34s.
2022-09-07 05:11:22 normalization > 05:11:22  
2022-09-07 05:11:22 normalization > 05:11:22  Completed successfully
2022-09-07 05:11:22 normalization > 05:11:22  
2022-09-07 05:11:22 normalization > 05:11:22  Done. PASS=1 WARN=0 ERROR=0 SKIP=0 TOTAL=1
2022-09-07 05:11:22 DEBUG i.a.w.n.DefaultNormalizationRunner(close):157 - Closing normalization process
2022-09-07 05:11:22 INFO i.a.w.DefaultNormalizationWorker(run):71 - Normalization executed in 12 seconds.
2022-09-07 05:11:22 INFO i.a.w.DefaultNormalizationWorker(run):77 - Normalization summary: io.airbyte.config.NormalizationSummary@521a7302[startTime=1662527470174,endTime=1662527482887]
2022-09-07 05:11:22 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
2022-09-07 05:11:22 INFO i.a.w.t.TemporalUtils(withBackgroundHeartbeat):236 - Stopping temporal heartbeating...
2022-09-07 05:11:22 DEBUG i.a.c.h.LogClientSingleton(setJobMdc):133 - Setting docker job mdc
2022-09-07 05:11:22 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/32509/0/logs.log
2022-09-07 05:11:22 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: 0.36.4-alpha
2022-09-07 05:11:22 DEBUG i.a.c.h.LogClientSingleton(setJobMdc):133 - Setting docker job mdc
2022-09-07 05:11:22 INFO i.a.w.DbtTransformationWorker(run):44 - Running dbt transformation.
2022-09-07 05:11:22 INFO i.a.w.n.DefaultNormalizationRunner(runProcess):122 - Running with normalization version: airbyte/normalization:0.1.77
2022-09-07 05:11:22 INFO i.a.c.i.LineGobbler(voidCall):82 - Checking if airbyte/normalization:0.1.77 exists...
2022-09-07 05:11:22 INFO i.a.c.i.LineGobbler(voidCall):82 - airbyte/normalization:0.1.77 was found locally.
2022-09-07 05:11:22 INFO i.a.w.p.DockerProcessFactory(create):106 - Creating docker job ID: 32509
2022-09-07 05:11:22 INFO i.a.w.p.DockerProcessFactory(create):158 - Preparing command: docker run --rm --init -i -w /data/32509/0/transform --log-driver none --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e AIRBYTE_VERSION=0.36.4-alpha airbyte/normalization:0.1.77 configure-dbt --integration-type bigquery --config destination_config.json --git-repo https://ayyoubmaulana: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@github.com/hostinger/wmti-dbt.git --git-branch add/replication_models
2022-09-07 05:11:23 normalization > Running: git clone --depth 5 -b add/replication_models --single-branch  $GIT_REPO git_repo
2022-09-07 05:11:23 normalization > Cloning into 'git_repo'...
2022-09-07 05:11:26 normalization > Last 5 commits in git_repo:
2022-09-07 05:11:26 normalization > 1cb95e1 dbt: change dataset
2022-09-07 05:11:26 normalization > f7beb2c dbt: change scd
2022-09-07 05:11:26 normalization > 6f74b95 dbt: change schema
2022-09-07 05:11:26 normalization > 955179d airflow: remove raw data from airfbyte
2022-09-07 05:11:26 normalization > 2229ca6 airflow: remove scd post hook
2022-09-07 05:11:26 normalization > /data/32509/0/transform
2022-09-07 05:11:26 normalization > Running: transform-config --config destination_config.json --integration-type bigquery --out /data/32509/0/transform
2022-09-07 05:11:26 normalization > Namespace(config='destination_config.json', integration_type=<DestinationType.BIGQUERY: 'bigquery'>, out='/data/32509/0/transform')
2022-09-07 05:11:26 normalization > transform_bigquery
2022-09-07 05:11:26 INFO i.a.c.i.LineGobbler(voidCall):82 - Checking if xemuliam/dbt:1.0.4 exists...
2022-09-07 05:11:26 INFO i.a.c.i.LineGobbler(voidCall):82 - xemuliam/dbt:1.0.4 was found locally.
2022-09-07 05:11:26 INFO i.a.w.p.DockerProcessFactory(create):106 - Creating docker job ID: 32509
2022-09-07 05:11:26 INFO i.a.w.p.DockerProcessFactory(create):158 - Preparing command: docker run --rm --init -i -w /data/32509/0/transform --log-driver none --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e AIRBYTE_VERSION=0.36.4-alpha --entrypoint /bin/bash xemuliam/dbt:1.0.4 entrypoint.sh run --models db_replication.nipa.nipa_invoice
2022-09-07 05:11:26 dbt > Running from /data/32509/0/transform/git_repo
2022-09-07 05:11:26 dbt > detected no config file for ssh, assuming ssh is off.
2022-09-07 05:11:26 dbt > Running: dbt run --models db_replication.nipa.nipa_invoice --profiles-dir=/data/32509/0/transform --project-dir=/data/32509/0/transform/git_repo
2022-09-07 05:11:30 dbt > 05:11:30  Running with dbt=1.0.4
2022-09-07 05:11:30 dbt > 05:11:30  Unable to do partial parsing because of a dbt version mismatch. Saved manifest version: 1.1.0. Current version: 1.0.4.
2022-09-07 05:11:32 DEBUG i.a.c.h.LogClientSingleton(setJobMdc):133 - Setting docker job mdc
2022-09-07 05:11:35 dbt > 05:11:35  [WARNING]: Did not find matching node for patch with name 'kpi_document_directory' in the 'models' section of file 'models/bi_general/sources/wmti/schema.yml'
2022-09-07 05:11:35 dbt > 05:11:35  [WARNING]: Configuration paths exist in your dbt_project.yml file which do not apply to any resources.
2022-09-07 05:11:35 dbt > There are 2 unused configuration paths:
2022-09-07 05:11:35 dbt > - models.re_data
2022-09-07 05:11:35 dbt > - models.re_data.internal
2022-09-07 05:11:35 dbt > 
2022-09-07 05:11:36 dbt > 05:11:36  Found 583 models, 6 tests, 0 snapshots, 0 analyses, 426 macros, 0 operations, 0 seed files, 305 sources, 0 exposures, 0 metrics
2022-09-07 05:11:36 dbt > 05:11:36  
2022-09-07 05:11:37 dbt > 05:11:37  Concurrency: 8 threads (target='prod')
2022-09-07 05:11:37 dbt > 05:11:37  
2022-09-07 05:11:37 dbt > 05:11:37  1 of 1 START incremental model niaga_partner.invoice.................................................................... [RUN]
2022-09-07 05:11:42 DEBUG i.a.c.h.LogClientSingleton(setJobMdc):133 - Setting docker job mdc
2022-09-07 05:11:45 dbt > 05:11:45  1 of 1 ERROR creating incremental model niaga_partner.invoice........................................................... [ERROR in 7.90s]
2022-09-07 05:11:45 dbt > 05:11:45  
2022-09-07 05:11:45 dbt > 05:11:45  Finished running 1 incremental model in 9.65s.
2022-09-07 05:11:45 dbt > 05:11:45  
2022-09-07 05:11:45 dbt > 05:11:45  Completed with 1 error and 0 warnings:
2022-09-07 05:11:45 dbt > 05:11:45  
2022-09-07 05:11:45 dbt > 05:11:45  Runtime Error in model nipa_invoice (models/db_replication/nipa/nipa_invoice.sql)
2022-09-07 05:11:45 dbt > 05:11:45    404 Not found: Table niagahoster-data-warehouse:niaga.invoice_scd
2022-09-07 05:11:45 dbt > 05:11:45    
2022-09-07 05:11:45 dbt > 05:11:45    Location: US
2022-09-07 05:11:45 dbt > 05:11:45    Job ID: af736b0c-7c98-4d0c-b18c-069dcd45d7a3
2022-09-07 05:11:45 dbt > 05:11:45    
2022-09-07 05:11:45 dbt > 05:11:45  
2022-09-07 05:11:45 dbt > 05:11:45  Done. PASS=0 WARN=0 ERROR=1 SKIP=0 TOTAL=1
2022-09-07 05:11:46 DEBUG i.a.w.n.DefaultNormalizationRunner(close):157 - Closing normalization process
2022-09-07 05:11:46 DEBUG i.a.w.DbtTransformationRunner(close):132 - Closing dbt transformation process
2022-09-07 05:11:46 INFO i.a.w.t.TemporalAttemptExecution(lambda$getWorkerThread$2):161 - Completing future exceptionally...
io.airbyte.workers.WorkerException: Dbt Transformation Failed.
	at io.airbyte.workers.DbtTransformationWorker.run(DbtTransformationWorker.java:57) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at io.airbyte.workers.DbtTransformationWorker.run(DbtTransformationWorker.java:16) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at java.lang.Thread.run(Thread.java:833) [?:?]
Caused by: io.airbyte.workers.WorkerException: DBT Transformation Failed.
	at io.airbyte.workers.DbtTransformationWorker.run(DbtTransformationWorker.java:54) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	... 3 more
	Suppressed: io.airbyte.workers.WorkerException: Dbt transformation process wasn't successful
		at io.airbyte.workers.DbtTransformationRunner.close(DbtTransformationRunner.java:135) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
		at io.airbyte.workers.DbtTransformationWorker.run(DbtTransformationWorker.java:43) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
		at io.airbyte.workers.DbtTransformationWorker.run(DbtTransformationWorker.java:16) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
		at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
		at java.lang.Thread.run(Thread.java:833) [?:?]
2022-09-07 05:11:46 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
2022-09-07 05:11:46 INFO i.a.w.t.TemporalUtils(withBackgroundHeartbeat):236 - Stopping temporal heartbeating...
2022-09-07 05:11:46 WARN i.t.i.a.POJOActivityTaskHandler(activityFailureToResult):307 - Activity failure. ActivityId=2668c4a7-1f77-3219-a614-278d0fabed6a, activityType=Run, attempt=1
java.lang.RuntimeException: io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.WorkerException: Dbt Transformation Failed.
	at io.airbyte.workers.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:234) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at io.airbyte.workers.temporal.sync.DbtTransformationActivityImpl.run(DbtTransformationActivityImpl.java:77) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at jdk.internal.reflect.GeneratedMethodAccessor206.invoke(Unknown Source) ~[?:?]
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
	at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:214) ~[temporal-sdk-1.8.1.jar:?]
	at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:180) ~[temporal-sdk-1.8.1.jar:?]
	at io.temporal.internal.activity.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:120) ~[temporal-sdk-1.8.1.jar:?]
	at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:204) ~[temporal-sdk-1.8.1.jar:?]
	at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:164) ~[temporal-sdk-1.8.1.jar:?]
	at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.8.1.jar:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
	at java.lang.Thread.run(Thread.java:833) [?:?]
Caused by: io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.WorkerException: Dbt Transformation Failed.
	at io.temporal.serviceclient.CheckedExceptionWrapper.wrap(CheckedExceptionWrapper.java:56) ~[temporal-serviceclient-1.8.1.jar:?]
	at io.temporal.internal.sync.WorkflowInternal.wrap(WorkflowInternal.java:448) ~[temporal-sdk-1.8.1.jar:?]
	at io.temporal.activity.Activity.wrap(Activity.java:51) ~[temporal-sdk-1.8.1.jar:?]
	at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:138) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at io.airbyte.workers.temporal.sync.DbtTransformationActivityImpl.lambda$run$3(DbtTransformationActivityImpl.java:108) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at io.airbyte.workers.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:229) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	... 13 more
Caused by: java.util.concurrent.ExecutionException: io.airbyte.workers.WorkerException: Dbt Transformation Failed.
	at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[?:?]
	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073) ~[?:?]
	at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:132) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at io.airbyte.workers.temporal.sync.DbtTransformationActivityImpl.lambda$run$3(DbtTransformationActivityImpl.java:108) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at io.airbyte.workers.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:229) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	... 13 more
Caused by: io.airbyte.workers.WorkerException: Dbt Transformation Failed.
	at io.airbyte.workers.DbtTransformationWorker.run(DbtTransformationWorker.java:57) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at io.airbyte.workers.DbtTransformationWorker.run(DbtTransformationWorker.java:16) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	... 1 more
Caused by: io.airbyte.workers.WorkerException: DBT Transformation Failed.
	at io.airbyte.workers.DbtTransformationWorker.run(DbtTransformationWorker.java:54) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at io.airbyte.workers.DbtTransformationWorker.run(DbtTransformationWorker.java:16) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
	... 1 more
	Suppressed: io.airbyte.workers.WorkerException: Dbt transformation process wasn't successful
		at io.airbyte.workers.DbtTransformationRunner.close(DbtTransformationRunner.java:135) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
		at io.airbyte.workers.DbtTransformationWorker.run(DbtTransformationWorker.java:43) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
		at io.airbyte.workers.DbtTransformationWorker.run(DbtTransformationWorker.java:16) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
		at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.36.4-alpha.jar:?]
		at java.lang.Thread.run(Thread.java:833) [?:?]
2022-09-07 05:11:46 DEBUG i.a.s.a.JobSubmitter(lambda$submitJob$2):135 - Job id 32509 succeeded
2022-09-07 05:11:46 DEBUG i.a.s.a.JobSubmitter(lambda$submitJob$4):166 - Job id 32509 cleared