- Is this your first time deploying Airbyte?: No
- OS Version / Instance: Ubuntu
- Memory / Disk: you can use something like 8Gb / 1 Tb
- Deployment: Are you using Docker or Kubernetes deployment? Docker
- Airbyte Version: What version are you using now? 0.40.23
- Source name/version: postgres 1.0.28
- Destination name/version: postgres 0.3.26
- Step: The issue is happening during sync, creating the connection or a new source? creating the connection
- Description: Hello. Following a recent upgrade of our airbyte server to the above version, my postgrest to postgres transformation is now failing in the normalization step.
I am able to setup the connection just fine without any custom dbt. As a test, I’ve simplified the connection to just move one table between the database. However, it fails on normalization without me touching it with the error at the end of this post.
I then noticed when I head to the transformations page, no matter what I enter, after hitting save and refreshing the page my transformations are always back to “Raw Data (JSON)” and all custom DBT is cleared. The save operation succeeds, and a glance at the network inspector shows it as doing so, returning a 200.
What can I do about this? Is there something I can clear in the docker volumes to try sorting this out. To be clear, the issue manifested itself following an upgrade to 0.40.23 which I did by running the steps in the docker upgrade guide, using the wget method to download the new config.
2022-12-01 11:32:07 e[32mINFOe[m i.a.w.g.DefaultReplicationWorker(getReplicationOutput):409 - failures: [ ]
2022-12-01 11:32:07 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(get):163 - Stopping cancellation check scheduling...
2022-12-01 11:32:07 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):114 -
2022-12-01 11:32:07 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):114 - ----- END REPLICATION -----
2022-12-01 11:32:07 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):114 -
2022-12-01 11:32:07 e[32mINFOe[m i.a.w.t.s.ReplicationActivityImpl(lambda$replicate$3):198 - sync summary: io.airbyte.config.StandardSyncOutput@179366db[standardSyncSummary=io.airbyte.config.StandardSyncSummary@6f72a1b3[status=completed,recordsSynced=2874,bytesSynced=282320,startTime=1669894314645,endTime=1669894327689,totalStats=io.airbyte.config.SyncStats@3833b98d[recordsEmitted=2874,bytesEmitted=282320,sourceStateMessagesEmitted=0,destinationStateMessagesEmitted=0,recordsCommitted=2874,meanSecondsBeforeSourceStateMessageEmitted=0,maxSecondsBeforeSourceStateMessageEmitted=0,maxSecondsBetweenStateMessageEmittedandCommitted=0,meanSecondsBetweenStateMessageEmittedandCommitted=0,replicationStartTime=1669894314645,replicationEndTime=1669894327689,sourceReadStartTime=1669894314834,sourceReadEndTime=1669894327156,destinationWriteStartTime=1669894315063,destinationWriteEndTime=1669894327688,additionalProperties={}],streamStats=[io.airbyte.config.StreamSyncStats@5bee7c89[streamName=dkd2_curated_organisations,streamNamespace=dkd,stats=io.airbyte.config.SyncStats@57c77c91[recordsEmitted=2874,bytesEmitted=282320,sourceStateMessagesEmitted=<null>,destinationStateMessagesEmitted=<null>,recordsCommitted=2874,meanSecondsBeforeSourceStateMessageEmitted=<null>,maxSecondsBeforeSourceStateMessageEmitted=<null>,maxSecondsBetweenStateMessageEmittedandCommitted=<null>,meanSecondsBetweenStateMessageEmittedandCommitted=<null>,replicationStartTime=<null>,replicationEndTime=<null>,sourceReadStartTime=<null>,sourceReadEndTime=<null>,destinationWriteStartTime=<null>,destinationWriteEndTime=<null>,additionalProperties={}]]]],normalizationSummary=<null>,webhookOperationSummary=<null>,state=<null>,outputCatalog=io.airbyte.protocol.models.ConfiguredAirbyteCatalog@2d4230e3[streams=[io.airbyte.protocol.models.ConfiguredAirbyteStream@8180b17[stream=io.airbyte.protocol.models.AirbyteStream@20ba34a9[name=dkd2_curated_organisations,jsonSchema={"type":"object","properties":{"name":{"type":"string"},"org_id":{"type":"number","airbyte_type":"integer"},"is_active":{"type":"boolean"},"description":{"type":"string"}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[[org_id]],namespace=dkd,additionalProperties={}],syncMode=full_refresh,cursorField=[],destinationSyncMode=overwrite,primaryKey=[[org_id]],additionalProperties={}]],additionalProperties={}],failures=[]]
2022-12-01 11:32:07 e[32mINFOe[m i.a.w.t.s.ReplicationActivityImpl(lambda$replicate$3):203 - Sync summary length: 2328
2022-12-01 11:32:07 e[32mINFOe[m i.a.c.t.TemporalUtils(withBackgroundHeartbeat):283 - Stopping temporal heartbeating...
2022-12-01 11:32:07 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(get):136 - Docker volume job log path: /tmp/workspace/500/2/logs.log
2022-12-01 11:32:07 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(get):141 - Executing worker wrapper. Airbyte version: 0.40.23
2022-12-01 11:32:07 e[32mINFOe[m i.a.a.c.AirbyteApiClient(retryWithJitter):179 - Attempt 0 to save workflow id for cancellation
2022-12-01 11:32:07 e[1;31mERRORe[m i.a.w.n.NormalizationRunnerFactory(create):50 - The normalization image name or tag in the definition file is different from the normalization image or tag in the NormalizationRunnerFactory!
2022-12-01 11:32:07 e[1;31mERRORe[m i.a.w.n.NormalizationRunnerFactory(create):52 - the definition file value - airbyte/normalization-postgres:0.2.24, the NormalizationRunnerFactory value - airbyte/normalization:0.2.24
2022-12-01 11:32:07 e[32mINFOe[m i.a.w.g.DbtTransformationWorker(run):58 - Running dbt transformation.
2022-12-01 11:32:07 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):114 -
2022-12-01 11:32:07 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):114 - ----- START DBT TRANSFORMATION -----
2022-12-01 11:32:07 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):114 -
2022-12-01 11:32:07 e[32mINFOe[m i.a.w.n.DefaultNormalizationRunner(runProcess):141 - Running with normalization version: airbyte/normalization:0.2.24
2022-12-01 11:32:07 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/normalization:0.2.24 exists...
2022-12-01 11:32:07 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):114 - airbyte/normalization:0.2.24 was found locally.
2022-12-01 11:32:07 e[32mINFOe[m i.a.w.p.DockerProcessFactory(create):119 - Creating docker container = normalization-normalize-500-2-youpr with resources io.airbyte.config.ResourceRequirements@10ec5ceb[cpuRequest=,cpuLimit=,memoryRequest=,memoryLimit=]
2022-12-01 11:32:07 e[32mINFOe[m i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/500/2/transform --log-driver none --name normalization-normalize-500-2-youpr --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e AIRBYTE_VERSION=0.40.23 airbyte/normalization:0.2.24 configure-dbt --integration-type postgres --config destination_config.json --git-repo https://github.com/visformatics/dmt-dbt.git
2022-12-01 11:32:08 e[42mnormalizatione[0m > Running: git clone --depth 5 --single-branch $GIT_REPO git_repo
2022-12-01 11:32:08 e[32mINFOe[m i.a.w.n.DefaultNormalizationRunner(close):204 - Terminating normalization process 1112...
2022-12-01 11:32:08 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(lambda$getWorkerThread$5):198 - Completing future exceptionally...
io.airbyte.workers.exception.WorkerException: Dbt Transformation Failed.
at io.airbyte.workers.general.DbtTransformationWorker.run(DbtTransformationWorker.java:72) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
at io.airbyte.workers.general.DbtTransformationWorker.run(DbtTransformationWorker.java:26) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$5(TemporalAttemptExecution.java:195) ~[io.airbyte-airbyte-workers-0.40.23.jar:?]
at java.lang.Thread.run(Thread.java:1589) ~[?:?]
Caused by: io.airbyte.workers.exception.WorkerException: DBT Transformation Failed.
at io.airbyte.workers.general.DbtTransformationWorker.run(DbtTransformationWorker.java:68) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
... 3 more
Suppressed: io.airbyte.workers.exception.WorkerException: Normalization process 1112 did not terminate normally (exit code: 128)
at io.airbyte.workers.normalization.DefaultNormalizationRunner.close(DefaultNormalizationRunner.java:215) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
at io.airbyte.workers.general.DbtTransformationRunner.close(DbtTransformationRunner.java:127) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
at io.airbyte.workers.general.DbtTransformationWorker.run(DbtTransformationWorker.java:57) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
at io.airbyte.workers.general.DbtTransformationWorker.run(DbtTransformationWorker.java:26) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$5(TemporalAttemptExecution.java:195) ~[io.airbyte-airbyte-workers-0.40.23.jar:?]
at java.lang.Thread.run(Thread.java:1589) ~[?:?]
2022-12-01 11:32:08 e[42mnormalizatione[0m > Cloning into 'git_repo'...
2022-12-01 11:32:08 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(get):163 - Stopping cancellation check scheduling...
2022-12-01 11:32:08 e[42mnormalizatione[0m > fatal: could not read Username for 'https://github.com': No such device or address
2022-12-01 11:32:08 e[32mINFOe[m i.a.c.t.TemporalUtils(withBackgroundHeartbeat):283 - Stopping temporal heartbeating...
2022-12-01 11:32:08 e[33mWARNe[m i.t.i.a.ActivityTaskExecutors$BaseActivityTaskExecutor(execute):114 - Activity failure. ActivityId=6d99e50a-b8ed-3ef7-984e-49887067a2aa, activityType=Run, attempt=1
java.lang.RuntimeException: io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Dbt Transformation Failed.
at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:281) ~[io.airbyte-airbyte-commons-temporal-0.40.23.jar:?]
at io.airbyte.workers.temporal.sync.DbtTransformationActivityImpl.run(DbtTransformationActivityImpl.java:101) ~[io.airbyte-airbyte-workers-0.40.23.jar:?]
at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:578) ~[?:?]
at io.temporal.internal.activity.RootActivityInboundCallsInterceptor$POJOActivityInboundCallsInterceptor.executeActivity(RootActivityInboundCallsInterceptor.java:64) ~[temporal-sdk-1.17.0.jar:?]
at io.temporal.internal.activity.RootActivityInboundCallsInterceptor.execute(RootActivityInboundCallsInterceptor.java:43) ~[temporal-sdk-1.17.0.jar:?]
at io.temporal.internal.activity.ActivityTaskExecutors$BaseActivityTaskExecutor.execute(ActivityTaskExecutors.java:95) ~[temporal-sdk-1.17.0.jar:?]
at io.temporal.internal.activity.ActivityTaskHandlerImpl.handle(ActivityTaskHandlerImpl.java:92) ~[temporal-sdk-1.17.0.jar:?]
at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handleActivity(ActivityWorker.java:241) ~[temporal-sdk-1.17.0.jar:?]
at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:206) ~[temporal-sdk-1.17.0.jar:?]
at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:179) ~[temporal-sdk-1.17.0.jar:?]
at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.17.0.jar:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
at java.lang.Thread.run(Thread.java:1589) ~[?:?]
Caused by: io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Dbt Transformation Failed.
at io.temporal.serviceclient.CheckedExceptionWrapper.wrap(CheckedExceptionWrapper.java:57) ~[temporal-serviceclient-1.17.0.jar:?]
at io.temporal.internal.sync.WorkflowInternal.wrap(WorkflowInternal.java:461) ~[temporal-sdk-1.17.0.jar:?]
at io.temporal.activity.Activity.wrap(Activity.java:52) ~[temporal-sdk-1.17.0.jar:?]
at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:167) ~[io.airbyte-airbyte-workers-0.40.23.jar:?]
at io.airbyte.workers.temporal.sync.DbtTransformationActivityImpl.lambda$run$3(DbtTransformationActivityImpl.java:132) ~[io.airbyte-airbyte-workers-0.40.23.jar:?]
at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:276) ~[io.airbyte-airbyte-commons-temporal-0.40.23.jar:?]
... 14 more
Caused by: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.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:161) ~[io.airbyte-airbyte-workers-0.40.23.jar:?]
at io.airbyte.workers.temporal.sync.DbtTransformationActivityImpl.lambda$run$3(DbtTransformationActivityImpl.java:132) ~[io.airbyte-airbyte-workers-0.40.23.jar:?]
at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:276) ~[io.airbyte-airbyte-commons-temporal-0.40.23.jar:?]
... 14 more
Caused by: io.airbyte.workers.exception.WorkerException: Dbt Transformation Failed.
at io.airbyte.workers.general.DbtTransformationWorker.run(DbtTransformationWorker.java:72) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
at io.airbyte.workers.general.DbtTransformationWorker.run(DbtTransformationWorker.java:26) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$5(TemporalAttemptExecution.java:195) ~[io.airbyte-airbyte-workers-0.40.23.jar:?]
... 1 more
Caused by: io.airbyte.workers.exception.WorkerException: DBT Transformation Failed.
at io.airbyte.workers.general.DbtTransformationWorker.run(DbtTransformationWorker.java:68) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
at io.airbyte.workers.general.DbtTransformationWorker.run(DbtTransformationWorker.java:26) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$5(TemporalAttemptExecution.java:195) ~[io.airbyte-airbyte-workers-0.40.23.jar:?]
... 1 more
Suppressed: io.airbyte.workers.exception.WorkerException: Normalization process 1112 did not terminate normally (exit code: 128)
at io.airbyte.workers.normalization.DefaultNormalizationRunner.close(DefaultNormalizationRunner.java:215) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
at io.airbyte.workers.general.DbtTransformationRunner.close(DbtTransformationRunner.java:127) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
at io.airbyte.workers.general.DbtTransformationWorker.run(DbtTransformationWorker.java:57) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
at io.airbyte.workers.general.DbtTransformationWorker.run(DbtTransformationWorker.java:26) ~[io.airbyte-airbyte-commons-worker-0.40.23.jar:?]
at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$5(TemporalAttemptExecution.java:195) ~[io.airbyte-airbyte-workers-0.40.23.jar:?]
at java.lang.Thread.run(Thread.java:1589) ~[?:?]
2022-12-01 11:32:09 e[32mINFOe[m i.a.n.SlackNotificationClient(notify):149 - Successful notification (200): ok
2022-12-01 11:32:09 e[32mINFOe[m i.a.v.j.JsonSchemaValidator(test):130 - JSON schema validation failed.
errors: $.mode: must be a constant value disable
2022-12-01 11:32:09 e[32mINFOe[m i.a.v.j.JsonSchemaValidator(test):130 - JSON schema validation failed.
errors: $.mode: must be a constant value allow
2022-12-01 11:32:09 e[32mINFOe[m i.a.v.j.JsonSchemaValidator(test):130 - JSON schema validation failed.
errors: $.mode: must be a constant value prefer
2022-12-01 11:32:09 e[32mINFOe[m i.a.v.j.JsonSchemaValidator(test):130 - JSON schema validation failed.
errors: $.mode: must be a constant value require
2022-12-01 11:32:09 e[32mINFOe[m i.a.v.j.JsonSchemaValidator(test):130 - JSON schema validation failed.
errors: $.client_key: object found, string expected, $.ca_certificate: object found, string expected, $.client_certificate: object found, string expected
2022-12-01 11:32:09 e[32mINFOe[m i.a.v.j.JsonSchemaValidator(test):130 - JSON schema validation failed.
errors: $.mode: must be a constant value verify-full, $.client_key: object found, string expected, $.ca_certificate: object found, string expected, $.client_certificate: object found, string expected
2022-12-01 11:32:09 e[32mINFOe[m i.a.v.j.JsonSchemaValidator(test):130 - JSON schema validation failed.
errors: $.mode: must be a constant value disable, $.mode: does not have a value in the enumeration [disable]
2022-12-01 11:32:09 e[32mINFOe[m i.a.v.j.JsonSchemaValidator(test):130 - JSON schema validation failed.
errors: $.mode: must be a constant value allow, $.mode: does not have a value in the enumeration [allow]
2022-12-01 11:32:09 e[32mINFOe[m i.a.c.f.EnvVariableFeatureFlags(autoDisablesFailingConnections):20 - Auto Disable Failing Connections: false