airbyte icon indicating copy to clipboard operation
airbyte copied to clipboard

Published 20 hours ago • verified publisher icon airbytehq

🎉 New Destination: DuckDB

Open sspaeti opened this issue 2 years ago • 16 comments

What

  • initial version of a DuckDB destination
  • I added the dbt normalization

How

  • Implemented with the Python CDK very similar to destination-sqlite. The code is mostly a copy of that.

Recommended reading order

  1. Read the implementation of the duckdb destination
  2. check out the added dbt normalization
  3. check the comment here for some specialties that didn't work without help initially.

Pre-merge Checklist

Expand the relevant checklist and delete the others.

New Connector

Community member or Airbyter

  • [ ] Community member? Grant edit access to maintainers (instructions)
  • [ ] Secrets in the connector's spec are annotated with airbyte_secret
  • [x] Unit & integration tests added and passing. Community members, please provide proof of success locally e.g: screenshot or copy-paste unit, integration, and acceptance test output. To run acceptance tests for a Python connector, follow instructions in the README. For java connectors run ./gradlew :airbyte-integrations:connectors:<name>:integrationTest.
  • [ ] Code reviews completed
  • [ ] Documentation updated
    • [x] Connector's README.md
    • [ ] Connector's bootstrap.md. See description and examples
    • [x] docs/integrations/<source or destination>/<name>.md including changelog. See changelog example
    • [x] docs/integrations/README.md
    • [x] airbyte-integrations/builds.md
  • [x] PR name follows PR naming conventions

Airbyter

If this is a community PR, the Airbyte engineer reviewing this PR is responsible for the below items.

  • [x] Create a non-forked branch based on this PR and test the below items on it
  • [ ] Build is successful
  • [ ] If new credentials are required for use in CI, add them to GSM. Instructions.
  • [ ] /test connector=connectors/<name> command is passing
  • [ ] New Connector version released on Dockerhub by running the /publish command described here
  • [ ] After the connector is published, connector added to connector index as described here
  • [ ] Seed specs have been re-generated by building the platform and committing the changes to the seed spec files, as described here
Connector Generator
  • [x] Issue acceptance criteria met
  • [x] PR name follows PR naming conventions
  • [ ] If adding a new generator, add it to the list of scaffold modules being tested
  • [ ] The generator test modules (all connectors with -scaffold in their name) have been updated with the latest scaffold by running ./gradlew :airbyte-integrations:connector-templates:generator:testScaffoldTemplates then checking in your changes
  • [ ] Documentation which references the generator is updated as needed

Tests

Unit 
> Task :airbyte-integrations:connectors:destination-duckdb:unitTest
Name                                Stmts   Miss  Cover
-------------------------------------------------------
destination_duckdb/__init__.py          2      0   100%
destination_duckdb/destination.py      70     48    31%
-------------------------------------------------------
TOTAL                                  72     48    33%

Deprecated Gradle features were used in this build, making it incompatible with Gradle 8.0.

You can use '--warning-mode all' to show the individual deprecation warnings and determine if they come from your own scripts or plugins.

See https://docs.gradle.org/7.6/userguide/command_line_interface.html#sec:command_line_warnings

BUILD SUCCESSFUL in 21s
33 actionable tasks: 21 executed, 12 up-to-date
Integration 
> Task :airbyte-integrations:connectors:destination-duckdb:customIntegrationTests
Name                                Stmts   Miss  Cover
-------------------------------------------------------
destination_duckdb/__init__.py          2      0   100%
destination_duckdb/destination.py      70     15    79%
-------------------------------------------------------
TOTAL                                  72     15    79%

Deprecated Gradle features were used in this build, making it incompatible with Gradle 8.0.

You can use '--warning-mode all' to show the individual deprecation warnings and determine if they come from your own scripts or plugins.

See https://docs.gradle.org/7.6/userguide/command_line_interface.html#sec:command_line_warnings

BUILD SUCCESSFUL in 13s
33 actionable tasks: 15 executed, 18 up-to-date
Acceptance

Not found for Python

sspaeti avatar Oct 01 '22 20:10 sspaeti

Converting PR back to "draft" and trying to add normalization at the same time. Any help or hints are appreciated; there are quite a lot of files touched for normalization.

I followed the most recent destination: https://github.com/airbytehq/airbyte/pull/15592/.

sspaeti avatar Nov 02 '22 14:11 sspaeti

Hi @marcosmarxm

Could you or someone help me with this PR to finish the normalization part of the DuckDB destination, please?

Tests

The unit tests and integration tests are looking good (see description above) and I can run a sync successfully without normalization: image

added the destination manually like this

image

Error with Normalization

I have an error when running normalization with:

How I build and tested it:

SUB_BUILD=PLATFORM ./gradlew build
VERSION=dev docker-compose up

docker build ./airbyte-integrations/connectors/destination-duckdb -t airbyte/duckdb:dev

Unfortunately, I get an error on the normalization part I'm not sure what the problem is, suspicious part but it's only an WARN (see the full log below): airbyte-worker | 2022-11-28 20:18:21 WARN i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$5):366 - Schema validation errors found for stream Products. Error messages: [$.created_at is of an incorrect type. Expected it to be date-time, $.year is of an incorrect type. Expected it to be string]

Tail but do not really know what to do or debug:

airbyte-worker      | Caused by: io.temporal.failure.ApplicationFailure: message='io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.', type='java.lang.RuntimeException', nonRetryable=false
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:278) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.normalize(NormalizationActivityImpl.java:93) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method:0) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
airbyte-worker      |   at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:214) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:180) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:120) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:204) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:164) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.base/java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | Caused by: io.temporal.failure.ApplicationFailure: message='io.airbyte.workers.exception.WorkerException: Normalization Failed.', type='java.util.concurrent.ExecutionException', nonRetryable=false
airbyte-worker      |   at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[?:?]
airbyte-worker      |   at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073) ~[?:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:132) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.lambda$normalize$3(NormalizationActivityImpl.java:121) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:273) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.normalize(NormalizationActivityImpl.java:93) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method:0) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
airbyte-worker      |   at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:214) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:180) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:120) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:204) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:164) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.base/java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | Caused by: io.temporal.failure.ApplicationFailure: message='Normalization Failed.', type='io.airbyte.workers.exception.WorkerException', nonRetryable=false
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:92) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:27) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:161) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.base/java.lang.Thread.run(Thread.java:833) ~[?:?]

Any help is much appreciated.

Full log on normalization sync:

airbyte-server      | 2022-11-28 20:18:13 INFO i.a.w.t.TemporalClient(startNewManualSync):318 - Manual sync request
airbyte-server      | 2022-11-28 20:18:13 INFO i.a.w.t.ConnectionManagerUtils(signalWorkflowAndRepairIfNecessary):95 - Retrieved existing connection manager workflow for connection 90825c11-8204-410a-ad1d-a841a3ea02c8. Executing signal.
airbyte-worker      | 2022-11-28 20:18:13 INFO i.a.w.t.s.a.JobCreationAndStatusUpdateActivityImpl(createNewJob):110 - Found the following streams to reset for connection 90825c11-8204-410a-ad1d-a841a3ea02c8: []
airbyte-worker      | 2022-11-28 20:18:13 INFO i.a.p.j.DefaultJobPersistence(enqueueJob):160 - enqueuing pending job for scope: 90825c11-8204-410a-ad1d-a841a3ea02c8
airbyte-worker      | 2022-11-28 20:18:13 INFO i.a.w.t.s.a.JobCreationAndStatusUpdateActivityImpl(createNewJob):136 - New job created, with id: 3
airbyte-worker      | 2022-11-28 20:18:13 INFO i.a.a.LoggingTrackingClient(track):43 - track. version: null, userId: null, action: Connector Jobs, metadata: {job_type=sync, namespace_definition=source, frequency=1440 min, connector_source_definition_id=dfd88b22-b603-4c3d-aad7-3701784586b1, workspace_id=447352f0-70f1-4d70-8dde-d7c566db9a11, attempt_stage=STARTED, attempt_id=1, connector_destination=DuckDB, connector_destination_docker_repository=airbyte/destination-duckdb, table_prefix=false, workspace_name=447352f0-70f1-4d70-8dde-d7c566db9a11, catalog.destination_sync_mode.overwrite=set, number_of_streams=3, connector_source=Faker, connector_source_docker_repository=airbyte/source-faker, catalog.sync_mode.full_refresh=set, connection_id=90825c11-8204-410a-ad1d-a841a3ea02c8, job_id=3, connector_source_version=0.1.6, config.destination.destination_path=set, connector_destination_version=dev, config.source.records_per_sync=set, operation.normalization=1, config.source.records_per_slice=set, operation_count=1, connector_destination_definition_id=3417e215-ae62-4632-8179-0c8ac8fda975, config.source.count=set, config.source.seed=set}
airbyte-worker      | 2022-11-28 20:18:13 INFO i.a.w.t.s.ConnectionManagerWorkflowImpl(checkConnections):408 - SOURCE CHECK: Starting
airbyte-worker      | 2022-11-28 20:18:13 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/3/0/logs.log
airbyte-worker      | 2022-11-28 20:18:13 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: dev
airbyte-server      | 2022-11-28 20:18:13 INFO i.a.w.t.TemporalClient(startNewManualSync):346 - end of manual schedule
airbyte-server      | 2022-11-28 20:18:13 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/attempt/set_workflow_in_attempt - {"jobId":3,"attemptNumber":0,"workflowId":"connection_manager_90825c11-8204-410a-ad1d-a841a3ea02c8"}
airbyte-server      | 2022-11-28 20:18:13 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.4 POST 200 /api/v1/connections/sync - {"connectionId":"90825c11-8204-410a-ad1d-a841a3ea02c8"}
airbyte-webapp      | 172.18.0.1 - airbyte [28/Nov/2022:20:18:13 +0000] "POST /api/v1/connections/sync HTTP/1.1" 200 1696 "http://localhost:8000/workspaces/447352f0-70f1-4d70-8dde-d7c566db9a11/connections/90825c11-8204-410a-ad1d-a841a3ea02c8/status" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36" "-"
airbyte-worker      | 2022-11-28 20:18:13 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:13 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- START CHECK -----
airbyte-worker      | 2022-11-28 20:18:13 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:13 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/source-faker:0.1.6 exists...
airbyte-worker      | 2022-11-28 20:18:13 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/source-faker:0.1.6 was found locally.
airbyte-worker      | 2022-11-28 20:18:13 INFO i.a.w.p.DockerProcessFactory(create):119 - Creating docker container = source-faker-check-3-0-gdowk with resources io.airbyte.config.ResourceRequirements@1ba883d2[cpuRequest=,cpuLimit=,memoryRequest=,memoryLimit=]
airbyte-worker      | 2022-11-28 20:18:13 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/3/0 --log-driver none --name source-faker-check-3-0-gdowk --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e USE_STREAM_CAPABLE_STATE=true -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e WORKER_CONNECTOR_IMAGE=airbyte/source-faker:0.1.6 -e WORKER_JOB_ATTEMPT=0 -e AIRBYTE_VERSION=dev -e WORKER_JOB_ID=3 airbyte/source-faker:0.1.6 check --config source_config.json
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.w.i.DefaultAirbyteStreamFactory(internalLog):103 - Check succeeded
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- END CHECK -----
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.w.t.s.ConnectionManagerWorkflowImpl(checkConnections):415 - SOURCE CHECK: Successful
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.w.t.s.ConnectionManagerWorkflowImpl(checkConnections):425 - DESTINATION CHECK: Starting
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/3/0/logs.log
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: dev
airbyte-server      | 2022-11-28 20:18:14 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/attempt/set_workflow_in_attempt - {"jobId":3,"attemptNumber":0,"workflowId":"connection_manager_90825c11-8204-410a-ad1d-a841a3ea02c8"}
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- START CHECK -----
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/destination-duckdb:dev exists...
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/destination-duckdb:dev was found locally.
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.w.p.DockerProcessFactory(create):119 - Creating docker container = destination-duckdb-check-3-0-quolg with resources io.airbyte.config.ResourceRequirements@1ba883d2[cpuRequest=,cpuLimit=,memoryRequest=,memoryLimit=]
airbyte-worker      | 2022-11-28 20:18:14 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/3/0 --log-driver none --name destination-duckdb-check-3-0-quolg --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e USE_STREAM_CAPABLE_STATE=true -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e WORKER_CONNECTOR_IMAGE=airbyte/destination-duckdb:dev -e WORKER_JOB_ATTEMPT=0 -e AIRBYTE_VERSION=dev -e WORKER_JOB_ID=3 airbyte/destination-duckdb:dev check --config source_config.json
airbyte-webapp      | 172.18.0.1 - airbyte [28/Nov/2022:20:18:14 +0000] "GET /api/v1/health HTTP/1.1" 200 18 "http://localhost:8000/workspaces/447352f0-70f1-4d70-8dde-d7c566db9a11/connections/90825c11-8204-410a-ad1d-a841a3ea02c8/status" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36" "-"
airbyte-server      | 2022-11-28 20:18:14 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.4 GET 200 /api/v1/health
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- END CHECK -----
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.w.t.s.ConnectionManagerWorkflowImpl(checkConnections):432 - DESTINATION CHECK: Successful
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/3/0/logs.log
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: dev
airbyte-server      | 2022-11-28 20:18:15 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/attempt/set_workflow_in_attempt - {"jobId":3,"attemptNumber":0,"workflowId":"sync_3"}
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.c.f.EnvVariableFeatureFlags(getEnvOrDefault):50 - Using default value for environment variable LOG_CONNECTOR_MESSAGES: 'false'
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.c.EnvConfigs(getEnvOrDefault):1085 - Using default value for environment variable METRIC_CLIENT: ''
airbyte-worker      | 2022-11-28 20:18:15 WARN i.a.m.l.MetricClientFactory(initialize):60 - Metric client is already initialized to
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.c.f.EnvVariableFeatureFlags(getEnvOrDefault):50 - Using default value for environment variable LOG_CONNECTOR_MESSAGES: 'false'
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.w.g.DefaultReplicationWorker(run):122 - start sync worker. job id: 3 attempt id: 0
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.w.g.DefaultReplicationWorker(run):135 - configured sync modes: {null.Users=full_refresh - overwrite, null.Purchases=full_refresh - overwrite, null.Products=full_refresh - overwrite}
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.w.i.DefaultAirbyteDestination(start):69 - Running destination...
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- START REPLICATION -----
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/destination-duckdb:dev exists...
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/destination-duckdb:dev was found locally.
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.w.p.DockerProcessFactory(create):119 - Creating docker container = destination-duckdb-write-3-0-wmkdw with resources io.airbyte.config.ResourceRequirements@768f29b5[cpuRequest=,cpuLimit=,memoryRequest=,memoryLimit=]
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/3/0 --log-driver none --name destination-duckdb-write-3-0-wmkdw --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e USE_STREAM_CAPABLE_STATE=true -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e WORKER_CONNECTOR_IMAGE=airbyte/destination-duckdb:dev -e WORKER_JOB_ATTEMPT=0 -e AIRBYTE_VERSION=dev -e WORKER_JOB_ID=3 airbyte/destination-duckdb:dev write --config destination_config.json --catalog destination_catalog.json
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/source-faker:0.1.6 exists...
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/source-faker:0.1.6 was found locally.
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.w.p.DockerProcessFactory(create):119 - Creating docker container = source-faker-read-3-0-zsqrf with resources io.airbyte.config.ResourceRequirements@235a76e5[cpuRequest=,cpuLimit=,memoryRequest=,memoryLimit=]
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/3/0 --log-driver none --name source-faker-read-3-0-zsqrf --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e USE_STREAM_CAPABLE_STATE=true -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e WORKER_CONNECTOR_IMAGE=airbyte/source-faker:0.1.6 -e WORKER_JOB_ATTEMPT=0 -e AIRBYTE_VERSION=dev -e WORKER_JOB_ID=3 airbyte/source-faker:0.1.6 read --config source_config.json --catalog source_catalog.json --state input_state.json
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.w.g.DefaultReplicationWorker(run):177 - Waiting for source and destination threads to complete.
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.w.g.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$7):435 - Destination output thread started.
airbyte-worker      | 2022-11-28 20:18:15 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):322 - Replication thread started.
airbyte-worker      | 2022-11-28 20:18:15 destination > Begin writing to the destination...
airbyte-worker      | 2022-11-28 20:18:15 destination > Starting write to DuckDB with 3 streams
airbyte-worker      | 2022-11-28 20:18:15 destination > Opening DuckDB file at /local/test_duck.duckdb
airbyte-worker      | 2022-11-28 20:18:15 destination > --- {'Products', 'Purchases', 'Users'}
airbyte-worker      | 2022-11-28 20:18:15 destination > --- {'Products', 'Purchases', 'Users'}
airbyte-worker      | 2022-11-28 20:18:15 destination > --- {'Products', 'Purchases', 'Users'}
airbyte-server      | 2022-11-28 20:18:16 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.4 POST 200 /api/v1/jobs/list - {"configId":"90825c11-8204-410a-ad1d-a841a3ea02c8","configTypes":["sync","reset_connection"],"pagination":{"pageSize":25}}
airbyte-webapp      | 172.18.0.1 - airbyte [28/Nov/2022:20:18:16 +0000] "POST /api/v1/jobs/list HTTP/1.1" 200 11518 "http://localhost:8000/workspaces/447352f0-70f1-4d70-8dde-d7c566db9a11/connections/90825c11-8204-410a-ad1d-a841a3ea02c8/status" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36" "-"
airbyte-worker      | 2022-11-28 20:18:16 source > Sending data for stream: Users
airbyte-worker      | 2022-11-28 20:18:16 source > Sending data for stream: Products
airbyte-worker      | 2022-11-28 20:18:16 ERROR c.n.s.DateTimeValidator(tryParse):82 - Invalid date-time: No zone offset information found
airbyte-worker      | 2022-11-28 20:18:16 ERROR c.n.s.DateTimeValidator(tryParse):82 - Invalid date-time: No zone offset information found
airbyte-worker      | 2022-11-28 20:18:16 ERROR c.n.s.DateTimeValidator(tryParse):82 - Invalid date-time: No zone offset information found
airbyte-worker      | 2022-11-28 20:18:16 source > Sending data for stream: Purchases
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):355 - Source has no more messages, closing connection.
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):363 - Total records read: 103 (10 KB)
airbyte-worker      | 2022-11-28 20:18:16 WARN i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$5):366 - Schema validation errors found for stream Products. Error messages: [$.created_at is of an incorrect type. Expected it to be date-time, $.year is of an incorrect type. Expected it to be string]
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.g.DefaultReplicationWorker(run):182 - One of source or destination thread complete. Waiting on the other.
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.g.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$7):445 - State in DefaultReplicationWorker from destination: io.airbyte.protocol.models.AirbyteMessage@2b3fedc7[type=STATE,log=<null>,spec=<null>,connectionStatus=<null>,catalog=<null>,record=<null>,state=io.airbyte.protocol.models.AirbyteStateMessage@25f816d0[type=<null>,stream=<null>,global=<null>,data={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}},additionalProperties={}],trace=<null>,additionalProperties={}]
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.g.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$7):445 - State in DefaultReplicationWorker from destination: io.airbyte.protocol.models.AirbyteMessage@21c786b7[type=STATE,log=<null>,spec=<null>,connectionStatus=<null>,catalog=<null>,record=<null>,state=io.airbyte.protocol.models.AirbyteStateMessage@64c51ceb[type=<null>,stream=<null>,global=<null>,data={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}},additionalProperties={}],trace=<null>,additionalProperties={}]
airbyte-worker      | 2022-11-28 20:18:16 WARN i.a.w.i.AirbyteMessageTracker(handleDestinationEmittedState):196 - The message tracker encountered an issue that prevents committed record counts from being reliably computed.
airbyte-worker      | 2022-11-28 20:18:16 WARN i.a.w.i.AirbyteMessageTracker(handleDestinationEmittedState):197 - This only impacts metadata and does not indicate a problem with actual sync data.
airbyte-worker      | 2022-11-28 20:18:16 WARN i.a.w.i.AirbyteMessageTracker(handleDestinationEmittedState):198 - State hash 1340819859 was already committed, likely indicating a state hash collision
airbyte-worker      | io.airbyte.workers.internal.StateDeltaTracker$StateDeltaTrackerException: State hash 1340819859 was already committed, likely indicating a state hash collision
airbyte-worker      |   at io.airbyte.workers.internal.StateDeltaTracker.commitStateHash(StateDeltaTracker.java:114) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.internal.AirbyteMessageTracker.handleDestinationEmittedState(AirbyteMessageTracker.java:193) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.internal.AirbyteMessageTracker.acceptFromDestination(AirbyteMessageTracker.java:119) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.general.DefaultReplicationWorker.lambda$getDestinationOutputRunnable$7(DefaultReplicationWorker.java:446) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | 2022-11-28 20:18:16 destination > 4---mesage: type=<Type.STATE: 'STATE'> log=None spec=None connectionStatus=None catalog=None record=None state=AirbyteStateMessage(type=None, stream=None, global_=None, data={'Users': {'cursor': 100, 'seed': -1}, 'Products': {'product_count': 100}, 'Purchases': {'purchases_count': 119}}) trace=None control=None
airbyte-worker      | 2022-11-28 20:18:16 destination > query:
airbyte-worker      |                     INSERT INTO _airbyte_raw_Products
airbyte-worker      |                     VALUES (?,?,?)
airbyte-worker      |
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.g.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$7):445 - State in DefaultReplicationWorker from destination: io.airbyte.protocol.models.AirbyteMessage@30408461[type=STATE,log=<null>,spec=<null>,connectionStatus=<null>,catalog=<null>,record=<null>,state=io.airbyte.protocol.models.AirbyteStateMessage@556b5a2f[type=<null>,stream=<null>,global=<null>,data={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}},additionalProperties={}],trace=<null>,additionalProperties={}]
airbyte-worker      | 2022-11-28 20:18:16 destination > Writing complete.
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.g.DefaultReplicationWorker(run):184 - Source and destination threads complete.
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.g.DefaultReplicationWorker(run):279 - Source output at least one state message
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.g.DefaultReplicationWorker(run):285 - State capture: Updated state to: Optional[io.airbyte.config.State@67405e[state={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}}]]
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.g.DefaultReplicationWorker(run):300 - sync summary: {
airbyte-worker      |   "status" : "completed",
airbyte-worker      |   "recordsSynced" : 100,
airbyte-worker      |   "bytesSynced" : 10542,
airbyte-worker      |   "startTime" : 1669666695340,
airbyte-worker      |   "endTime" : 1669666696372,
airbyte-worker      |   "totalStats" : {
airbyte-worker      |     "recordsEmitted" : 100,
airbyte-worker      |     "bytesEmitted" : 10542,
airbyte-worker      |     "sourceStateMessagesEmitted" : 3,
airbyte-worker      |     "destinationStateMessagesEmitted" : 3,
airbyte-worker      |     "recordsCommitted" : 100,
airbyte-worker      |     "meanSecondsBeforeSourceStateMessageEmitted" : 0,
airbyte-worker      |     "maxSecondsBeforeSourceStateMessageEmitted" : 0,
airbyte-worker      |     "maxSecondsBetweenStateMessageEmittedandCommitted" : 0,
airbyte-worker      |     "meanSecondsBetweenStateMessageEmittedandCommitted" : 0
airbyte-worker      |   },
airbyte-worker      |   "streamStats" : [ {
airbyte-worker      |     "streamName" : "Products",
airbyte-worker      |     "stats" : {
airbyte-worker      |       "recordsEmitted" : 100,
airbyte-worker      |       "bytesEmitted" : 10542,
airbyte-worker      |       "recordsCommitted" : 100
airbyte-worker      |     }
airbyte-worker      |   } ]
airbyte-worker      | }
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.g.DefaultReplicationWorker(run):301 - failures: [ ]
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.t.s.ReplicationActivityImpl(lambda$replicate$3):159 - sync summary: io.airbyte.config.StandardSyncOutput@acf48b7[standardSyncSummary=io.airbyte.config.StandardSyncSummary@4fcdd78a[status=completed,recordsSynced=100,bytesSynced=10542,startTime=1669666695340,endTime=1669666696372,totalStats=io.airbyte.config.SyncStats@765dfcaf[recordsEmitted=100,bytesEmitted=10542,sourceStateMessagesEmitted=3,destinationStateMessagesEmitted=3,recordsCommitted=100,meanSecondsBeforeSourceStateMessageEmitted=0,maxSecondsBeforeSourceStateMessageEmitted=0,maxSecondsBetweenStateMessageEmittedandCommitted=0,meanSecondsBetweenStateMessageEmittedandCommitted=0,additionalProperties={}],streamStats=[io.airbyte.config.StreamSyncStats@7e48ba80[streamName=Products,stats=io.airbyte.config.SyncStats@e32cf0e[recordsEmitted=100,bytesEmitted=10542,sourceStateMessagesEmitted=<null>,destinationStateMessagesEmitted=<null>,recordsCommitted=100,meanSecondsBeforeSourceStateMessageEmitted=<null>,maxSecondsBeforeSourceStateMessageEmitted=<null>,maxSecondsBetweenStateMessageEmittedandCommitted=<null>,meanSecondsBetweenStateMessageEmittedandCommitted=<null>,additionalProperties={}]]]],normalizationSummary=<null>,state=io.airbyte.config.State@67405e[state={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}}],outputCatalog=io.airbyte.protocol.models.ConfiguredAirbyteCatalog@2fe228c5[streams=[io.airbyte.protocol.models.ConfiguredAirbyteStream@36c31112[stream=io.airbyte.protocol.models.AirbyteStream@d6421f0[name=Users,jsonSchema={"type":"object","$schema":"http://json-schema.org/draft-07/schema#","properties":{"id":{"type":"number"},"job":{"type":"string"},"sex":{"type":"string"},"ssn":{"type":"string"},"mail":{"type":"string"},"name":{"type":"string"},"address":{"type":"string"},"company":{"type":"string"},"website":{"type":"array"},"username":{"type":"string"},"residence":{"type":"string"},"created_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"},"updated_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"},"blood_group":{"type":"string"},"current_location":{"type":"array"}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[],namespace=<null>,additionalProperties={}],syncMode=full_refresh,cursorField=[],destinationSyncMode=overwrite,primaryKey=[],additionalProperties={}], io.airbyte.protocol.models.ConfiguredAirbyteStream@1536c5ed[stream=io.airbyte.protocol.models.AirbyteStream@2bac738e[name=Products,jsonSchema={"type":"object","$schema":"http://json-schema.org/draft-07/schema#","properties":{"id":{"type":"number"},"make":{"type":"string"},"year":{"type":"string"},"model":{"type":"string"},"price":{"type":"number"},"created_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"}}},supportedSyncModes=[full_refresh],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[],namespace=<null>,additionalProperties={}],syncMode=full_refresh,cursorField=[],destinationSyncMode=overwrite,primaryKey=[],additionalProperties={}], io.airbyte.protocol.models.ConfiguredAirbyteStream@549ac68[stream=io.airbyte.protocol.models.AirbyteStream@298e6690[name=Purchases,jsonSchema={"type":"object","$schema":"http://json-schema.org/draft-07/schema#","properties":{"id":{"type":"number"},"user_id":{"type":"number"},"product_id":{"type":"number"},"returned_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"},"purchased_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"},"added_to_cart_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[],namespace=<null>,additionalProperties={}],syncMode=full_refresh,cursorField=[],destinationSyncMode=overwrite,primaryKey=[],additionalProperties={}]],additionalProperties={}],failures=[]]
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.c.t.TemporalUtils(withBackgroundHeartbeat):280 - Stopping temporal heartbeating...
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- END REPLICATION -----
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-server      | 2022-11-28 20:18:16 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/state/get - {"connectionId":"90825c11-8204-410a-ad1d-a841a3ea02c8"}
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.c.f.EnvVariableFeatureFlags(getEnvOrDefault):50 - Using default value for environment variable NEED_STATE_VALIDATION: 'true'
airbyte-server      | 2022-11-28 20:18:16 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/state/create_or_update - {"connectionId":"90825c11-8204-410a-ad1d-a841a3ea02c8","connectionState":{"stateType":"legacy","connectionId":"90825c11-8204-410a-ad1d-a841a3ea02c8","state":{"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}}}}
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.t.s.SyncWorkflowImpl(run):82 - generating normalization input
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/3/0/logs.log
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: dev
airbyte-server      | 2022-11-28 20:18:16 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/attempt/set_workflow_in_attempt - {"jobId":3,"attemptNumber":0,"workflowId":"sync_3"}
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.w.n.DefaultNormalizationRunner(runProcess):139 - Running with normalization version: airbyte/normalization-duckdb:0.2.22
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- START DEFAULT NORMALIZATION -----
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/normalization-duckdb:0.2.22 exists...
airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/normalization-duckdb:0.2.22 not found locally. Attempting to pull the image...
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.c.i.LineGobbler(voidCall):114 - Image does not exist.
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.w.g.DefaultNormalizationWorker(run):82 - Normalization executed in 1 second.
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.w.t.TemporalAttemptExecution(lambda$getWorkerThread$2):164 - Completing future exceptionally...
airbyte-worker      | io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:92) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:27) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:161) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.c.t.TemporalUtils(withBackgroundHeartbeat):280 - Stopping temporal heartbeating...
airbyte-worker      | 2022-11-28 20:18:18 WARN i.t.i.a.POJOActivityTaskHandler(activityFailureToResult):307 - Activity failure. ActivityId=d6a39b7d-e9f2-34e1-9cd1-66f84363db7e, activityType=Normalize, attempt=1
airbyte-worker      | java.lang.RuntimeException: io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:278) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.normalize(NormalizationActivityImpl.java:93) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
airbyte-worker      |   at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:214) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:180) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:120) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:204) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:164) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | Caused by: io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at io.temporal.serviceclient.CheckedExceptionWrapper.wrap(CheckedExceptionWrapper.java:56) ~[temporal-serviceclient-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.WorkflowInternal.wrap(WorkflowInternal.java:448) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.activity.Activity.wrap(Activity.java:51) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:138) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.lambda$normalize$3(NormalizationActivityImpl.java:121) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:273) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   ... 14 more
airbyte-worker      | Caused by: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[?:?]
airbyte-worker      |   at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073) ~[?:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:132) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.lambda$normalize$3(NormalizationActivityImpl.java:121) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:273) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   ... 14 more
airbyte-worker      | Caused by: io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:92) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:27) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:161) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   ... 1 more
airbyte-worker      | 2022-11-28 20:18:18 ERROR i.t.i.s.WorkflowExecuteRunnable(logWorkflowExecutionException):125 - Workflow execution failure WorkflowId=sync_3, RunId=dc88198e-4209-41a5-9dce-d38747172504, WorkflowType=SyncWorkflow
airbyte-worker      | io.temporal.failure.ActivityFailure: scheduledEventId=31, startedEventId=32, activityType='Normalize', activityId='d6a39b7d-e9f2-34e1-9cd1-66f84363db7e', identity='1@d74c69727d08', retryState=RETRY_STATE_MAXIMUM_ATTEMPTS_REACHED
airbyte-worker      |   at java.lang.Thread.getStackTrace(Thread.java:1610) ~[?:?]
airbyte-worker      |   at io.temporal.internal.sync.ActivityStubBase.execute(ActivityStubBase.java:48) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.ActivityInvocationHandler.lambda$getActivityFunc$0(ActivityInvocationHandler.java:77) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.ActivityInvocationHandlerBase.invoke(ActivityInvocationHandlerBase.java:70) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at jdk.proxy2.$Proxy103.normalize(Unknown Source) ~[?:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.SyncWorkflowImpl.run(SyncWorkflowImpl.java:85) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at SyncWorkflowImplProxy.run$accessor$dJlyJFnl(Unknown Source) ~[?:?]
airbyte-worker      |   at SyncWorkflowImplProxy$auxiliary$kv776tte.call(Unknown Source) ~[?:?]
airbyte-worker      |   at io.airbyte.workers.temporal.support.TemporalActivityStubInterceptor.execute(TemporalActivityStubInterceptor.java:79) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at SyncWorkflowImplProxy.run(Unknown Source) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
airbyte-worker      |   at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
airbyte-worker      |   at io.temporal.internal.sync.POJOWorkflowImplementationFactory$POJOWorkflowImplementation$RootWorkflowInboundCallsInterceptor.execute(POJOWorkflowImplementationFactory.java:317) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.POJOWorkflowImplementationFactory$POJOWorkflowImplementation.execute(POJOWorkflowImplementationFactory.java:292) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.WorkflowExecuteRunnable.run(WorkflowExecuteRunnable.java:72) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.SyncWorkflow.lambda$start$0(SyncWorkflow.java:137) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.CancellationScopeImpl.run(CancellationScopeImpl.java:101) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.WorkflowThreadImpl$RunnableWrapper.run(WorkflowThreadImpl.java:111) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
airbyte-worker      |   at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | Caused by: io.temporal.failure.ApplicationFailure: message='io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.', type='java.lang.RuntimeException', nonRetryable=false
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:278) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.normalize(NormalizationActivityImpl.java:93) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method:0) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
airbyte-worker      |   at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:214) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:180) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:120) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:204) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:164) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.base/java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | Caused by: io.temporal.failure.ApplicationFailure: message='io.airbyte.workers.exception.WorkerException: Normalization Failed.', type='java.util.concurrent.ExecutionException', nonRetryable=false
airbyte-worker      |   at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[?:?]
airbyte-worker      |   at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073) ~[?:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:132) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.lambda$normalize$3(NormalizationActivityImpl.java:121) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:273) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.normalize(NormalizationActivityImpl.java:93) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method:0) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
airbyte-worker      |   at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:214) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:180) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:120) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:204) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:164) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.base/java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | Caused by: io.temporal.failure.ApplicationFailure: message='Normalization Failed.', type='io.airbyte.workers.exception.WorkerException', nonRetryable=false
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:92) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:27) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:161) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.base/java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.w.t.s.ConnectionManagerWorkflowImpl(ensureCleanJobState):630 - This workflow is already attached to a job, so no need to clean job state.
airbyte-server      | 2022-11-28 20:18:18 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.4 POST 200 /api/v1/jobs/list - {"configId":"90825c11-8204-410a-ad1d-a841a3ea02c8","configTypes":["sync","reset_connection"],"pagination":{"pageSize":25}}
airbyte-webapp      | 172.18.0.1 - airbyte [28/Nov/2022:20:18:18 +0000] "POST /api/v1/jobs/list HTTP/1.1" 200 14973 "http://localhost:8000/workspaces/447352f0-70f1-4d70-8dde-d7c566db9a11/connections/90825c11-8204-410a-ad1d-a841a3ea02c8/status" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36" "-"
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.a.LoggingTrackingClient(track):43 - track. version: null, userId: null, action: Connector Jobs, metadata: {job_type=sync, namespace_definition=source, frequency=1440 min, connector_source_definition_id=dfd88b22-b603-4c3d-aad7-3701784586b1, workspace_id=447352f0-70f1-4d70-8dde-d7c566db9a11, attempt_stage=STARTED, attempt_id=2, connector_destination=DuckDB, connector_destination_docker_repository=airbyte/destination-duckdb, table_prefix=false, workspace_name=447352f0-70f1-4d70-8dde-d7c566db9a11, catalog.destination_sync_mode.overwrite=set, number_of_streams=3, connector_source=Faker, connector_source_docker_repository=airbyte/source-faker, catalog.sync_mode.full_refresh=set, connection_id=90825c11-8204-410a-ad1d-a841a3ea02c8, job_id=3, connector_source_version=0.1.6, config.destination.destination_path=set, connector_destination_version=dev, config.source.records_per_sync=set, operation.normalization=1, config.source.records_per_slice=set, operation_count=1, connector_destination_definition_id=3417e215-ae62-4632-8179-0c8ac8fda975, config.source.count=set, config.source.seed=set}
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.w.t.s.ConnectionManagerWorkflowImpl(checkConnections):408 - SOURCE CHECK: Starting
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/3/1/logs.log
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: dev
airbyte-server      | 2022-11-28 20:18:18 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/attempt/set_workflow_in_attempt - {"jobId":3,"attemptNumber":1,"workflowId":"connection_manager_90825c11-8204-410a-ad1d-a841a3ea02c8"}
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- START CHECK -----
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/source-faker:0.1.6 exists...
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/source-faker:0.1.6 was found locally.
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.w.p.DockerProcessFactory(create):119 - Creating docker container = source-faker-check-3-1-yowjt with resources io.airbyte.config.ResourceRequirements@1ba883d2[cpuRequest=,cpuLimit=,memoryRequest=,memoryLimit=]
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/3/1 --log-driver none --name source-faker-check-3-1-yowjt --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e USE_STREAM_CAPABLE_STATE=true -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e WORKER_CONNECTOR_IMAGE=airbyte/source-faker:0.1.6 -e WORKER_JOB_ATTEMPT=1 -e AIRBYTE_VERSION=dev -e WORKER_JOB_ID=3 airbyte/source-faker:0.1.6 check --config source_config.json
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.w.i.DefaultAirbyteStreamFactory(internalLog):103 - Check succeeded
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- END CHECK -----
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.w.t.s.ConnectionManagerWorkflowImpl(checkConnections):415 - SOURCE CHECK: Successful
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.w.t.s.ConnectionManagerWorkflowImpl(checkConnections):425 - DESTINATION CHECK: Starting
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/3/1/logs.log
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: dev
airbyte-server      | 2022-11-28 20:18:19 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/attempt/set_workflow_in_attempt - {"jobId":3,"attemptNumber":1,"workflowId":"connection_manager_90825c11-8204-410a-ad1d-a841a3ea02c8"}
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- START CHECK -----
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/destination-duckdb:dev exists...
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/destination-duckdb:dev was found locally.
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.w.p.DockerProcessFactory(create):119 - Creating docker container = destination-duckdb-check-3-1-wbkzb with resources io.airbyte.config.ResourceRequirements@1ba883d2[cpuRequest=,cpuLimit=,memoryRequest=,memoryLimit=]
airbyte-worker      | 2022-11-28 20:18:19 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/3/1 --log-driver none --name destination-duckdb-check-3-1-wbkzb --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e USE_STREAM_CAPABLE_STATE=true -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e WORKER_CONNECTOR_IMAGE=airbyte/destination-duckdb:dev -e WORKER_JOB_ATTEMPT=1 -e AIRBYTE_VERSION=dev -e WORKER_JOB_ID=3 airbyte/destination-duckdb:dev check --config source_config.json
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- END CHECK -----
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.w.t.s.ConnectionManagerWorkflowImpl(checkConnections):432 - DESTINATION CHECK: Successful
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/3/1/logs.log
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: dev
airbyte-server      | 2022-11-28 20:18:20 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/attempt/set_workflow_in_attempt - {"jobId":3,"attemptNumber":1,"workflowId":"sync_3"}
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.c.f.EnvVariableFeatureFlags(getEnvOrDefault):50 - Using default value for environment variable LOG_CONNECTOR_MESSAGES: 'false'
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.c.EnvConfigs(getEnvOrDefault):1085 - Using default value for environment variable METRIC_CLIENT: ''
airbyte-worker      | 2022-11-28 20:18:20 WARN i.a.m.l.MetricClientFactory(initialize):60 - Metric client is already initialized to
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.c.f.EnvVariableFeatureFlags(getEnvOrDefault):50 - Using default value for environment variable LOG_CONNECTOR_MESSAGES: 'false'
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.w.g.DefaultReplicationWorker(run):122 - start sync worker. job id: 3 attempt id: 1
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- START REPLICATION -----
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.w.g.DefaultReplicationWorker(run):135 - configured sync modes: {null.Users=full_refresh - overwrite, null.Purchases=full_refresh - overwrite, null.Products=full_refresh - overwrite}
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.w.i.DefaultAirbyteDestination(start):69 - Running destination...
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/destination-duckdb:dev exists...
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/destination-duckdb:dev was found locally.
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.w.p.DockerProcessFactory(create):119 - Creating docker container = destination-duckdb-write-3-1-myfzj with resources io.airbyte.config.ResourceRequirements@2644d435[cpuRequest=,cpuLimit=,memoryRequest=,memoryLimit=]
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/3/1 --log-driver none --name destination-duckdb-write-3-1-myfzj --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e USE_STREAM_CAPABLE_STATE=true -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e WORKER_CONNECTOR_IMAGE=airbyte/destination-duckdb:dev -e WORKER_JOB_ATTEMPT=1 -e AIRBYTE_VERSION=dev -e WORKER_JOB_ID=3 airbyte/destination-duckdb:dev write --config destination_config.json --catalog destination_catalog.json
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/source-faker:0.1.6 exists...
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/source-faker:0.1.6 was found locally.
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.w.p.DockerProcessFactory(create):119 - Creating docker container = source-faker-read-3-1-seppl with resources io.airbyte.config.ResourceRequirements@34edbe22[cpuRequest=,cpuLimit=,memoryRequest=,memoryLimit=]
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/3/1 --log-driver none --name source-faker-read-3-1-seppl --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e USE_STREAM_CAPABLE_STATE=true -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e WORKER_CONNECTOR_IMAGE=airbyte/source-faker:0.1.6 -e WORKER_JOB_ATTEMPT=1 -e AIRBYTE_VERSION=dev -e WORKER_JOB_ID=3 airbyte/source-faker:0.1.6 read --config source_config.json --catalog source_catalog.json --state input_state.json
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.w.g.DefaultReplicationWorker(run):177 - Waiting for source and destination threads to complete.
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):322 - Replication thread started.
airbyte-worker      | 2022-11-28 20:18:20 INFO i.a.w.g.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$7):435 - Destination output thread started.
airbyte-worker      | 2022-11-28 20:18:20 destination > Begin writing to the destination...
airbyte-worker      | 2022-11-28 20:18:20 destination > Starting write to DuckDB with 3 streams
airbyte-worker      | 2022-11-28 20:18:20 destination > Opening DuckDB file at /local/test_duck.duckdb
airbyte-worker      | 2022-11-28 20:18:20 destination > --- {'Users', 'Purchases', 'Products'}
airbyte-worker      | 2022-11-28 20:18:20 destination > --- {'Users', 'Purchases', 'Products'}
airbyte-worker      | 2022-11-28 20:18:20 destination > --- {'Users', 'Purchases', 'Products'}
airbyte-worker      | 2022-11-28 20:18:21 source > Sending data for stream: Users
airbyte-worker      | 2022-11-28 20:18:21 source > Sending data for stream: Products
airbyte-worker      | 2022-11-28 20:18:21 ERROR c.n.s.DateTimeValidator(tryParse):82 - Invalid date-time: No zone offset information found
airbyte-worker      | 2022-11-28 20:18:21 ERROR c.n.s.DateTimeValidator(tryParse):82 - Invalid date-time: No zone offset information found
airbyte-worker      | 2022-11-28 20:18:21 ERROR c.n.s.DateTimeValidator(tryParse):82 - Invalid date-time: No zone offset information found
airbyte-worker      | 2022-11-28 20:18:21 source > Sending data for stream: Purchases
airbyte-server      | 2022-11-28 20:18:21 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.4 POST 200 /api/v1/jobs/list - {"configId":"90825c11-8204-410a-ad1d-a841a3ea02c8","configTypes":["sync","reset_connection"],"pagination":{"pageSize":25}}
airbyte-webapp      | 172.18.0.1 - airbyte [28/Nov/2022:20:18:21 +0000] "POST /api/v1/jobs/list HTTP/1.1" 200 14973 "http://localhost:8000/workspaces/447352f0-70f1-4d70-8dde-d7c566db9a11/connections/90825c11-8204-410a-ad1d-a841a3ea02c8/status" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36" "-"
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):355 - Source has no more messages, closing connection.
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):363 - Total records read: 103 (10 KB)
airbyte-worker      | 2022-11-28 20:18:21 WARN i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$5):366 - Schema validation errors found for stream Products. Error messages: [$.created_at is of an incorrect type. Expected it to be date-time, $.year is of an incorrect type. Expected it to be string]
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.g.DefaultReplicationWorker(run):182 - One of source or destination thread complete. Waiting on the other.
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$7):445 - State in DefaultReplicationWorker from destination: io.airbyte.protocol.models.AirbyteMessage@2fe9940b[type=STATE,log=<null>,spec=<null>,connectionStatus=<null>,catalog=<null>,record=<null>,state=io.airbyte.protocol.models.AirbyteStateMessage@212e6f86[type=<null>,stream=<null>,global=<null>,data={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}},additionalProperties={}],trace=<null>,additionalProperties={}]
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$7):445 - State in DefaultReplicationWorker from destination: io.airbyte.protocol.models.AirbyteMessage@2511ff7b[type=STATE,log=<null>,spec=<null>,connectionStatus=<null>,catalog=<null>,record=<null>,state=io.airbyte.protocol.models.AirbyteStateMessage@601365bd[type=<null>,stream=<null>,global=<null>,data={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}},additionalProperties={}],trace=<null>,additionalProperties={}]
airbyte-worker      | 2022-11-28 20:18:21 WARN i.a.w.i.AirbyteMessageTracker(handleDestinationEmittedState):196 - The message tracker encountered an issue that prevents committed record counts from being reliably computed.
airbyte-worker      | 2022-11-28 20:18:21 WARN i.a.w.i.AirbyteMessageTracker(handleDestinationEmittedState):197 - This only impacts metadata and does not indicate a problem with actual sync data.
airbyte-worker      | 2022-11-28 20:18:21 WARN i.a.w.i.AirbyteMessageTracker(handleDestinationEmittedState):198 - State hash 1340819859 was already committed, likely indicating a state hash collision
airbyte-worker      | io.airbyte.workers.internal.StateDeltaTracker$StateDeltaTrackerException: State hash 1340819859 was already committed, likely indicating a state hash collision
airbyte-worker      |   at io.airbyte.workers.internal.StateDeltaTracker.commitStateHash(StateDeltaTracker.java:114) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.internal.AirbyteMessageTracker.handleDestinationEmittedState(AirbyteMessageTracker.java:193) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.internal.AirbyteMessageTracker.acceptFromDestination(AirbyteMessageTracker.java:119) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.general.DefaultReplicationWorker.lambda$getDestinationOutputRunnable$7(DefaultReplicationWorker.java:446) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | 2022-11-28 20:18:21 destination > 4---mesage: type=<Type.STATE: 'STATE'> log=None spec=None connectionStatus=None catalog=None record=None state=AirbyteStateMessage(type=None, stream=None, global_=None, data={'Users': {'cursor': 100, 'seed': -1}, 'Products': {'product_count': 100}, 'Purchases': {'purchases_count': 119}}) trace=None control=None
airbyte-worker      | 2022-11-28 20:18:21 destination > query:
airbyte-worker      |                     INSERT INTO _airbyte_raw_Products
airbyte-worker      |                     VALUES (?,?,?)
airbyte-worker      |
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$7):445 - State in DefaultReplicationWorker from destination: io.airbyte.protocol.models.AirbyteMessage@339fc78[type=STATE,log=<null>,spec=<null>,connectionStatus=<null>,catalog=<null>,record=<null>,state=io.airbyte.protocol.models.AirbyteStateMessage@51b9e1c6[type=<null>,stream=<null>,global=<null>,data={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}},additionalProperties={}],trace=<null>,additionalProperties={}]
airbyte-worker      | 2022-11-28 20:18:21 destination > Writing complete.
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.g.DefaultReplicationWorker(run):184 - Source and destination threads complete.
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.g.DefaultReplicationWorker(run):279 - Source output at least one state message
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.g.DefaultReplicationWorker(run):285 - State capture: Updated state to: Optional[io.airbyte.config.State@6903dddf[state={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}}]]
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.g.DefaultReplicationWorker(run):300 - sync summary: {
airbyte-worker      |   "status" : "completed",
airbyte-worker      |   "recordsSynced" : 100,
airbyte-worker      |   "bytesSynced" : 10542,
airbyte-worker      |   "startTime" : 1669666700166,
airbyte-worker      |   "endTime" : 1669666701249,
airbyte-worker      |   "totalStats" : {
airbyte-worker      |     "recordsEmitted" : 100,
airbyte-worker      |     "bytesEmitted" : 10542,
airbyte-worker      |     "sourceStateMessagesEmitted" : 3,
airbyte-worker      |     "destinationStateMessagesEmitted" : 3,
airbyte-worker      |     "recordsCommitted" : 100,
airbyte-worker      |     "meanSecondsBeforeSourceStateMessageEmitted" : 0,
airbyte-worker      |     "maxSecondsBeforeSourceStateMessageEmitted" : 0,
airbyte-worker      |     "maxSecondsBetweenStateMessageEmittedandCommitted" : 0,
airbyte-worker      |     "meanSecondsBetweenStateMessageEmittedandCommitted" : 0
airbyte-worker      |   },
airbyte-worker      |   "streamStats" : [ {
airbyte-worker      |     "streamName" : "Products",
airbyte-worker      |     "stats" : {
airbyte-worker      |       "recordsEmitted" : 100,
airbyte-worker      |       "bytesEmitted" : 10542,
airbyte-worker      |       "recordsCommitted" : 100
airbyte-worker      |     }
airbyte-worker      |   } ]
airbyte-worker      | }
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.g.DefaultReplicationWorker(run):301 - failures: [ ]
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- END REPLICATION -----
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.t.s.ReplicationActivityImpl(lambda$replicate$3):159 - sync summary: io.airbyte.config.StandardSyncOutput@206f00a0[standardSyncSummary=io.airbyte.config.StandardSyncSummary@656d8ac9[status=completed,recordsSynced=100,bytesSynced=10542,startTime=1669666700166,endTime=1669666701249,totalStats=io.airbyte.config.SyncStats@74b5a45f[recordsEmitted=100,bytesEmitted=10542,sourceStateMessagesEmitted=3,destinationStateMessagesEmitted=3,recordsCommitted=100,meanSecondsBeforeSourceStateMessageEmitted=0,maxSecondsBeforeSourceStateMessageEmitted=0,maxSecondsBetweenStateMessageEmittedandCommitted=0,meanSecondsBetweenStateMessageEmittedandCommitted=0,additionalProperties={}],streamStats=[io.airbyte.config.StreamSyncStats@5442ed2b[streamName=Products,stats=io.airbyte.config.SyncStats@c709d03[recordsEmitted=100,bytesEmitted=10542,sourceStateMessagesEmitted=<null>,destinationStateMessagesEmitted=<null>,recordsCommitted=100,meanSecondsBeforeSourceStateMessageEmitted=<null>,maxSecondsBeforeSourceStateMessageEmitted=<null>,maxSecondsBetweenStateMessageEmittedandCommitted=<null>,meanSecondsBetweenStateMessageEmittedandCommitted=<null>,additionalProperties={}]]]],normalizationSummary=<null>,state=io.airbyte.config.State@6903dddf[state={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}}],outputCatalog=io.airbyte.protocol.models.ConfiguredAirbyteCatalog@5427586[streams=[io.airbyte.protocol.models.ConfiguredAirbyteStream@5c0cae2d[stream=io.airbyte.protocol.models.AirbyteStream@1fe43b32[name=Users,jsonSchema={"type":"object","$schema":"http://json-schema.org/draft-07/schema#","properties":{"id":{"type":"number"},"job":{"type":"string"},"sex":{"type":"string"},"ssn":{"type":"string"},"mail":{"type":"string"},"name":{"type":"string"},"address":{"type":"string"},"company":{"type":"string"},"website":{"type":"array"},"username":{"type":"string"},"residence":{"type":"string"},"created_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"},"updated_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"},"blood_group":{"type":"string"},"current_location":{"type":"array"}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[],namespace=<null>,additionalProperties={}],syncMode=full_refresh,cursorField=[],destinationSyncMode=overwrite,primaryKey=[],additionalProperties={}], io.airbyte.protocol.models.ConfiguredAirbyteStream@17743548[stream=io.airbyte.protocol.models.AirbyteStream@10c8c65[name=Products,jsonSchema={"type":"object","$schema":"http://json-schema.org/draft-07/schema#","properties":{"id":{"type":"number"},"make":{"type":"string"},"year":{"type":"string"},"model":{"type":"string"},"price":{"type":"number"},"created_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"}}},supportedSyncModes=[full_refresh],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[],namespace=<null>,additionalProperties={}],syncMode=full_refresh,cursorField=[],destinationSyncMode=overwrite,primaryKey=[],additionalProperties={}], io.airbyte.protocol.models.ConfiguredAirbyteStream@384837af[stream=io.airbyte.protocol.models.AirbyteStream@6cba63f[name=Purchases,jsonSchema={"type":"object","$schema":"http://json-schema.org/draft-07/schema#","properties":{"id":{"type":"number"},"user_id":{"type":"number"},"product_id":{"type":"number"},"returned_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"},"purchased_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"},"added_to_cart_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[],namespace=<null>,additionalProperties={}],syncMode=full_refresh,cursorField=[],destinationSyncMode=overwrite,primaryKey=[],additionalProperties={}]],additionalProperties={}],failures=[]]
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.c.t.TemporalUtils(withBackgroundHeartbeat):280 - Stopping temporal heartbeating...
airbyte-server      | 2022-11-28 20:18:21 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/state/get - {"connectionId":"90825c11-8204-410a-ad1d-a841a3ea02c8"}
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.c.f.EnvVariableFeatureFlags(getEnvOrDefault):50 - Using default value for environment variable NEED_STATE_VALIDATION: 'true'
airbyte-server      | 2022-11-28 20:18:21 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/state/create_or_update - {"connectionId":"90825c11-8204-410a-ad1d-a841a3ea02c8","connectionState":{"stateType":"legacy","connectionId":"90825c11-8204-410a-ad1d-a841a3ea02c8","state":{"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}}}}
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.t.s.SyncWorkflowImpl(run):82 - generating normalization input
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/3/1/logs.log
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: dev
airbyte-server      | 2022-11-28 20:18:21 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/attempt/set_workflow_in_attempt - {"jobId":3,"attemptNumber":1,"workflowId":"sync_3"}
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.w.n.DefaultNormalizationRunner(runProcess):139 - Running with normalization version: airbyte/normalization-duckdb:0.2.22
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- START DEFAULT NORMALIZATION -----
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/normalization-duckdb:0.2.22 exists...
airbyte-worker      | 2022-11-28 20:18:21 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/normalization-duckdb:0.2.22 not found locally. Attempting to pull the image...
airbyte-worker      | 2022-11-28 20:18:22 INFO i.a.c.i.LineGobbler(voidCall):114 - Image does not exist.
airbyte-worker      | 2022-11-28 20:18:22 INFO i.a.w.g.DefaultNormalizationWorker(run):82 - Normalization executed in 1 second.
airbyte-worker      | 2022-11-28 20:18:22 INFO i.a.w.t.TemporalAttemptExecution(lambda$getWorkerThread$2):164 - Completing future exceptionally...
airbyte-worker      | io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:92) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:27) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:161) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | 2022-11-28 20:18:22 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
airbyte-worker      | 2022-11-28 20:18:22 INFO i.a.c.t.TemporalUtils(withBackgroundHeartbeat):280 - Stopping temporal heartbeating...
airbyte-worker      | 2022-11-28 20:18:22 WARN i.t.i.a.POJOActivityTaskHandler(activityFailureToResult):307 - Activity failure. ActivityId=3202a752-fe5f-37c4-b8be-eb1b512075ab, activityType=Normalize, attempt=1
airbyte-worker      | java.lang.RuntimeException: io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:278) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.normalize(NormalizationActivityImpl.java:93) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
airbyte-worker      |   at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:214) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:180) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:120) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:204) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:164) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | Caused by: io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at io.temporal.serviceclient.CheckedExceptionWrapper.wrap(CheckedExceptionWrapper.java:56) ~[temporal-serviceclient-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.WorkflowInternal.wrap(WorkflowInternal.java:448) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.activity.Activity.wrap(Activity.java:51) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:138) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.lambda$normalize$3(NormalizationActivityImpl.java:121) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:273) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   ... 14 more
airbyte-worker      | Caused by: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[?:?]
airbyte-worker      |   at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073) ~[?:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:132) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.lambda$normalize$3(NormalizationActivityImpl.java:121) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:273) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   ... 14 more
airbyte-worker      | Caused by: io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:92) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:27) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:161) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   ... 1 more
airbyte-worker      | 2022-11-28 20:18:22 ERROR i.t.i.s.WorkflowExecuteRunnable(logWorkflowExecutionException):125 - Workflow execution failure WorkflowId=sync_3, RunId=ffff0cf9-bc24-4665-b371-c3e9a1ae428e, WorkflowType=SyncWorkflow
airbyte-worker      | io.temporal.failure.ActivityFailure: scheduledEventId=31, startedEventId=32, activityType='Normalize', activityId='3202a752-fe5f-37c4-b8be-eb1b512075ab', identity='1@d74c69727d08', retryState=RETRY_STATE_MAXIMUM_ATTEMPTS_REACHED
airbyte-worker      |   at java.lang.Thread.getStackTrace(Thread.java:1610) ~[?:?]
airbyte-worker      |   at io.temporal.internal.sync.ActivityStubBase.execute(ActivityStubBase.java:48) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.ActivityInvocationHandler.lambda$getActivityFunc$0(ActivityInvocationHandler.java:77) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.ActivityInvocationHandlerBase.invoke(ActivityInvocationHandlerBase.java:70) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at jdk.proxy2.$Proxy103.normalize(Unknown Source) ~[?:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.SyncWorkflowImpl.run(SyncWorkflowImpl.java:85) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at SyncWorkflowImplProxy.run$accessor$dJlyJFnl(Unknown Source) ~[?:?]
airbyte-worker      |   at SyncWorkflowImplProxy$auxiliary$kv776tte.call(Unknown Source) ~[?:?]
airbyte-worker      |   at io.airbyte.workers.temporal.support.TemporalActivityStubInterceptor.execute(TemporalActivityStubInterceptor.java:79) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at SyncWorkflowImplProxy.run(Unknown Source) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
airbyte-worker      |   at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
airbyte-worker      |   at io.temporal.internal.sync.POJOWorkflowImplementationFactory$POJOWorkflowImplementation$RootWorkflowInboundCallsInterceptor.execute(POJOWorkflowImplementationFactory.java:317) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.POJOWorkflowImplementationFactory$POJOWorkflowImplementation.execute(POJOWorkflowImplementationFactory.java:292) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.WorkflowExecuteRunnable.run(WorkflowExecuteRunnable.java:72) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.SyncWorkflow.lambda$start$0(SyncWorkflow.java:137) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.CancellationScopeImpl.run(CancellationScopeImpl.java:101) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.WorkflowThreadImpl$RunnableWrapper.run(WorkflowThreadImpl.java:111) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
airbyte-worker      |   at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | Caused by: io.temporal.failure.ApplicationFailure: message='io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.', type='java.lang.RuntimeException', nonRetryable=false
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:278) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.normalize(NormalizationActivityImpl.java:93) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method:0) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
airbyte-worker      |   at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:214) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:180) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:120) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:204) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:164) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.base/java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | Caused by: io.temporal.failure.ApplicationFailure: message='io.airbyte.workers.exception.WorkerException: Normalization Failed.', type='java.util.concurrent.ExecutionException', nonRetryable=false
airbyte-worker      |   at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[?:?]
airbyte-worker      |   at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073) ~[?:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:132) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.lambda$normalize$3(NormalizationActivityImpl.java:121) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:273) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.normalize(NormalizationActivityImpl.java:93) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method:0) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
airbyte-worker      |   at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:214) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:180) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:120) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:204) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:164) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.base/java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | Caused by: io.temporal.failure.ApplicationFailure: message='Normalization Failed.', type='io.airbyte.workers.exception.WorkerException', nonRetryable=false
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:92) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:27) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:161) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.base/java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | 2022-11-28 20:18:22 INFO i.a.w.t.s.ConnectionManagerWorkflowImpl(ensureCleanJobState):630 - This workflow is already attached to a job, so no need to clean job state.
airbyte-worker      | 2022-11-28 20:18:22 INFO i.a.a.LoggingTrackingClient(track):43 - track. version: null, userId: null, action: Connector Jobs, metadata: {job_type=sync, namespace_definition=source, frequency=1440 min, connector_source_definition_id=dfd88b22-b603-4c3d-aad7-3701784586b1, workspace_id=447352f0-70f1-4d70-8dde-d7c566db9a11, attempt_stage=STARTED, attempt_id=3, connector_destination=DuckDB, connector_destination_docker_repository=airbyte/destination-duckdb, table_prefix=false, workspace_name=447352f0-70f1-4d70-8dde-d7c566db9a11, catalog.destination_sync_mode.overwrite=set, number_of_streams=3, connector_source=Faker, connector_source_docker_repository=airbyte/source-faker, catalog.sync_mode.full_refresh=set, connection_id=90825c11-8204-410a-ad1d-a841a3ea02c8, job_id=3, connector_source_version=0.1.6, config.destination.destination_path=set, connector_destination_version=dev, config.source.records_per_sync=set, operation.normalization=1, config.source.records_per_slice=set, operation_count=1, connector_destination_definition_id=3417e215-ae62-4632-8179-0c8ac8fda975, config.source.count=set, config.source.seed=set}
airbyte-worker      | 2022-11-28 20:18:22 INFO i.a.w.t.s.ConnectionManagerWorkflowImpl(checkConnections):408 - SOURCE CHECK: Starting
airbyte-worker      | 2022-11-28 20:18:22 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/3/2/logs.log
airbyte-worker      | 2022-11-28 20:18:22 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: dev
airbyte-server      | 2022-11-28 20:18:22 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/attempt/set_workflow_in_attempt - {"jobId":3,"attemptNumber":2,"workflowId":"connection_manager_90825c11-8204-410a-ad1d-a841a3ea02c8"}
airbyte-worker      | 2022-11-28 20:18:22 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:22 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- START CHECK -----
airbyte-worker      | 2022-11-28 20:18:22 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:22 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/source-faker:0.1.6 exists...
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/source-faker:0.1.6 was found locally.
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.w.p.DockerProcessFactory(create):119 - Creating docker container = source-faker-check-3-2-tlrbm with resources io.airbyte.config.ResourceRequirements@1ba883d2[cpuRequest=,cpuLimit=,memoryRequest=,memoryLimit=]
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/3/2 --log-driver none --name source-faker-check-3-2-tlrbm --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e USE_STREAM_CAPABLE_STATE=true -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e WORKER_CONNECTOR_IMAGE=airbyte/source-faker:0.1.6 -e WORKER_JOB_ATTEMPT=2 -e AIRBYTE_VERSION=dev -e WORKER_JOB_ID=3 airbyte/source-faker:0.1.6 check --config source_config.json
airbyte-server      | 2022-11-28 20:18:23 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.4 POST 200 /api/v1/jobs/list - {"configId":"90825c11-8204-410a-ad1d-a841a3ea02c8","configTypes":["sync","reset_connection"],"pagination":{"pageSize":25}}
airbyte-webapp      | 172.18.0.1 - airbyte [28/Nov/2022:20:18:23 +0000] "POST /api/v1/jobs/list HTTP/1.1" 200 18420 "http://localhost:8000/workspaces/447352f0-70f1-4d70-8dde-d7c566db9a11/connections/90825c11-8204-410a-ad1d-a841a3ea02c8/status" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36" "-"
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.w.i.DefaultAirbyteStreamFactory(internalLog):103 - Check succeeded
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- END CHECK -----
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.w.t.s.ConnectionManagerWorkflowImpl(checkConnections):415 - SOURCE CHECK: Successful
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.w.t.s.ConnectionManagerWorkflowImpl(checkConnections):425 - DESTINATION CHECK: Starting
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/3/2/logs.log
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: dev
airbyte-server      | 2022-11-28 20:18:23 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/attempt/set_workflow_in_attempt - {"jobId":3,"attemptNumber":2,"workflowId":"connection_manager_90825c11-8204-410a-ad1d-a841a3ea02c8"}
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- START CHECK -----
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/destination-duckdb:dev exists...
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/destination-duckdb:dev was found locally.
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.w.p.DockerProcessFactory(create):119 - Creating docker container = destination-duckdb-check-3-2-jnawq with resources io.airbyte.config.ResourceRequirements@1ba883d2[cpuRequest=,cpuLimit=,memoryRequest=,memoryLimit=]
airbyte-worker      | 2022-11-28 20:18:23 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/3/2 --log-driver none --name destination-duckdb-check-3-2-jnawq --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e USE_STREAM_CAPABLE_STATE=true -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e WORKER_CONNECTOR_IMAGE=airbyte/destination-duckdb:dev -e WORKER_JOB_ATTEMPT=2 -e AIRBYTE_VERSION=dev -e WORKER_JOB_ID=3 airbyte/destination-duckdb:dev check --config source_config.json
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- END CHECK -----
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.w.t.s.ConnectionManagerWorkflowImpl(checkConnections):432 - DESTINATION CHECK: Successful
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/3/2/logs.log
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: dev
airbyte-server      | 2022-11-28 20:18:24 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/attempt/set_workflow_in_attempt - {"jobId":3,"attemptNumber":2,"workflowId":"sync_3"}
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.c.f.EnvVariableFeatureFlags(getEnvOrDefault):50 - Using default value for environment variable LOG_CONNECTOR_MESSAGES: 'false'
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.c.EnvConfigs(getEnvOrDefault):1085 - Using default value for environment variable METRIC_CLIENT: ''
airbyte-worker      | 2022-11-28 20:18:24 WARN i.a.m.l.MetricClientFactory(initialize):60 - Metric client is already initialized to
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.c.f.EnvVariableFeatureFlags(getEnvOrDefault):50 - Using default value for environment variable LOG_CONNECTOR_MESSAGES: 'false'
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.w.g.DefaultReplicationWorker(run):122 - start sync worker. job id: 3 attempt id: 2
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- START REPLICATION -----
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.w.g.DefaultReplicationWorker(run):135 - configured sync modes: {null.Users=full_refresh - overwrite, null.Purchases=full_refresh - overwrite, null.Products=full_refresh - overwrite}
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.w.i.DefaultAirbyteDestination(start):69 - Running destination...
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/destination-duckdb:dev exists...
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/destination-duckdb:dev was found locally.
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.w.p.DockerProcessFactory(create):119 - Creating docker container = destination-duckdb-write-3-2-mcemc with resources io.airbyte.config.ResourceRequirements@4023a4b[cpuRequest=,cpuLimit=,memoryRequest=,memoryLimit=]
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/3/2 --log-driver none --name destination-duckdb-write-3-2-mcemc --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e USE_STREAM_CAPABLE_STATE=true -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e WORKER_CONNECTOR_IMAGE=airbyte/destination-duckdb:dev -e WORKER_JOB_ATTEMPT=2 -e AIRBYTE_VERSION=dev -e WORKER_JOB_ID=3 airbyte/destination-duckdb:dev write --config destination_config.json --catalog destination_catalog.json
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/source-faker:0.1.6 exists...
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/source-faker:0.1.6 was found locally.
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.w.p.DockerProcessFactory(create):119 - Creating docker container = source-faker-read-3-2-lsknj with resources io.airbyte.config.ResourceRequirements@1f065749[cpuRequest=,cpuLimit=,memoryRequest=,memoryLimit=]
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/3/2 --log-driver none --name source-faker-read-3-2-lsknj --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e DEPLOYMENT_MODE=OSS -e USE_STREAM_CAPABLE_STATE=true -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e WORKER_CONNECTOR_IMAGE=airbyte/source-faker:0.1.6 -e WORKER_JOB_ATTEMPT=2 -e AIRBYTE_VERSION=dev -e WORKER_JOB_ID=3 airbyte/source-faker:0.1.6 read --config source_config.json --catalog source_catalog.json --state input_state.json
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.w.g.DefaultReplicationWorker(run):177 - Waiting for source and destination threads to complete.
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):322 - Replication thread started.
airbyte-worker      | 2022-11-28 20:18:24 INFO i.a.w.g.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$7):435 - Destination output thread started.
airbyte-worker      | 2022-11-28 20:18:24 destination > Begin writing to the destination...
airbyte-worker      | 2022-11-28 20:18:24 destination > Starting write to DuckDB with 3 streams
airbyte-worker      | 2022-11-28 20:18:24 destination > Opening DuckDB file at /local/test_duck.duckdb
airbyte-worker      | 2022-11-28 20:18:24 destination > --- {'Products', 'Purchases', 'Users'}
airbyte-worker      | 2022-11-28 20:18:24 destination > --- {'Products', 'Purchases', 'Users'}
airbyte-worker      | 2022-11-28 20:18:24 destination > --- {'Products', 'Purchases', 'Users'}
airbyte-worker      | 2022-11-28 20:18:25 source > Sending data for stream: Users
airbyte-worker      | 2022-11-28 20:18:25 source > Sending data for stream: Products
airbyte-worker      | 2022-11-28 20:18:25 ERROR c.n.s.DateTimeValidator(tryParse):82 - Invalid date-time: No zone offset information found
airbyte-worker      | 2022-11-28 20:18:25 ERROR c.n.s.DateTimeValidator(tryParse):82 - Invalid date-time: No zone offset information found
airbyte-worker      | 2022-11-28 20:18:25 ERROR c.n.s.DateTimeValidator(tryParse):82 - Invalid date-time: No zone offset information found
airbyte-worker      | 2022-11-28 20:18:25 source > Sending data for stream: Purchases
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):355 - Source has no more messages, closing connection.
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):363 - Total records read: 103 (10 KB)
airbyte-worker      | 2022-11-28 20:18:25 WARN i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$5):366 - Schema validation errors found for stream Products. Error messages: [$.created_at is of an incorrect type. Expected it to be date-time, $.year is of an incorrect type. Expected it to be string]
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.g.DefaultReplicationWorker(run):182 - One of source or destination thread complete. Waiting on the other.
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$7):445 - State in DefaultReplicationWorker from destination: io.airbyte.protocol.models.AirbyteMessage@2d27d836[type=STATE,log=<null>,spec=<null>,connectionStatus=<null>,catalog=<null>,record=<null>,state=io.airbyte.protocol.models.AirbyteStateMessage@23e023e2[type=<null>,stream=<null>,global=<null>,data={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}},additionalProperties={}],trace=<null>,additionalProperties={}]
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$7):445 - State in DefaultReplicationWorker from destination: io.airbyte.protocol.models.AirbyteMessage@27dfb346[type=STATE,log=<null>,spec=<null>,connectionStatus=<null>,catalog=<null>,record=<null>,state=io.airbyte.protocol.models.AirbyteStateMessage@62dd29d9[type=<null>,stream=<null>,global=<null>,data={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}},additionalProperties={}],trace=<null>,additionalProperties={}]
airbyte-worker      | 2022-11-28 20:18:25 WARN i.a.w.i.AirbyteMessageTracker(handleDestinationEmittedState):196 - The message tracker encountered an issue that prevents committed record counts from being reliably computed.
airbyte-worker      | 2022-11-28 20:18:25 WARN i.a.w.i.AirbyteMessageTracker(handleDestinationEmittedState):197 - This only impacts metadata and does not indicate a problem with actual sync data.
airbyte-worker      | 2022-11-28 20:18:25 WARN i.a.w.i.AirbyteMessageTracker(handleDestinationEmittedState):198 - State hash 1340819859 was already committed, likely indicating a state hash collision
airbyte-worker      | io.airbyte.workers.internal.StateDeltaTracker$StateDeltaTrackerException: State hash 1340819859 was already committed, likely indicating a state hash collision
airbyte-worker      |   at io.airbyte.workers.internal.StateDeltaTracker.commitStateHash(StateDeltaTracker.java:114) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.internal.AirbyteMessageTracker.handleDestinationEmittedState(AirbyteMessageTracker.java:193) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.internal.AirbyteMessageTracker.acceptFromDestination(AirbyteMessageTracker.java:119) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.general.DefaultReplicationWorker.lambda$getDestinationOutputRunnable$7(DefaultReplicationWorker.java:446) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | 2022-11-28 20:18:25 destination > 4---mesage: type=<Type.STATE: 'STATE'> log=None spec=None connectionStatus=None catalog=None record=None state=AirbyteStateMessage(type=None, stream=None, global_=None, data={'Users': {'cursor': 100, 'seed': -1}, 'Products': {'product_count': 100}, 'Purchases': {'purchases_count': 119}}) trace=None control=None
airbyte-worker      | 2022-11-28 20:18:25 destination > query:
airbyte-worker      |                     INSERT INTO _airbyte_raw_Products
airbyte-worker      |                     VALUES (?,?,?)
airbyte-worker      |
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$7):445 - State in DefaultReplicationWorker from destination: io.airbyte.protocol.models.AirbyteMessage@7128bbdc[type=STATE,log=<null>,spec=<null>,connectionStatus=<null>,catalog=<null>,record=<null>,state=io.airbyte.protocol.models.AirbyteStateMessage@53756928[type=<null>,stream=<null>,global=<null>,data={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}},additionalProperties={}],trace=<null>,additionalProperties={}]
airbyte-worker      | 2022-11-28 20:18:25 destination > Writing complete.
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.g.DefaultReplicationWorker(run):184 - Source and destination threads complete.
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.g.DefaultReplicationWorker(run):279 - Source output at least one state message
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.g.DefaultReplicationWorker(run):285 - State capture: Updated state to: Optional[io.airbyte.config.State@48615a15[state={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}}]]
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.g.DefaultReplicationWorker(run):300 - sync summary: {
airbyte-worker      |   "status" : "completed",
airbyte-worker      |   "recordsSynced" : 100,
airbyte-worker      |   "bytesSynced" : 10542,
airbyte-worker      |   "startTime" : 1669666704487,
airbyte-worker      |   "endTime" : 1669666705562,
airbyte-worker      |   "totalStats" : {
airbyte-worker      |     "recordsEmitted" : 100,
airbyte-worker      |     "bytesEmitted" : 10542,
airbyte-worker      |     "sourceStateMessagesEmitted" : 3,
airbyte-worker      |     "destinationStateMessagesEmitted" : 3,
airbyte-worker      |     "recordsCommitted" : 100,
airbyte-worker      |     "meanSecondsBeforeSourceStateMessageEmitted" : 0,
airbyte-worker      |     "maxSecondsBeforeSourceStateMessageEmitted" : 0,
airbyte-worker      |     "maxSecondsBetweenStateMessageEmittedandCommitted" : 0,
airbyte-worker      |     "meanSecondsBetweenStateMessageEmittedandCommitted" : 0
airbyte-worker      |   },
airbyte-worker      |   "streamStats" : [ {
airbyte-worker      |     "streamName" : "Products",
airbyte-worker      |     "stats" : {
airbyte-worker      |       "recordsEmitted" : 100,
airbyte-worker      |       "bytesEmitted" : 10542,
airbyte-worker      |       "recordsCommitted" : 100
airbyte-worker      |     }
airbyte-worker      |   } ]
airbyte-worker      | }
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.g.DefaultReplicationWorker(run):301 - failures: [ ]
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- END REPLICATION -----
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.t.s.ReplicationActivityImpl(lambda$replicate$3):159 - sync summary: io.airbyte.config.StandardSyncOutput@53be2dd2[standardSyncSummary=io.airbyte.config.StandardSyncSummary@16bcb9c1[status=completed,recordsSynced=100,bytesSynced=10542,startTime=1669666704487,endTime=1669666705562,totalStats=io.airbyte.config.SyncStats@7da48ee2[recordsEmitted=100,bytesEmitted=10542,sourceStateMessagesEmitted=3,destinationStateMessagesEmitted=3,recordsCommitted=100,meanSecondsBeforeSourceStateMessageEmitted=0,maxSecondsBeforeSourceStateMessageEmitted=0,maxSecondsBetweenStateMessageEmittedandCommitted=0,meanSecondsBetweenStateMessageEmittedandCommitted=0,additionalProperties={}],streamStats=[io.airbyte.config.StreamSyncStats@2760eccf[streamName=Products,stats=io.airbyte.config.SyncStats@592854c[recordsEmitted=100,bytesEmitted=10542,sourceStateMessagesEmitted=<null>,destinationStateMessagesEmitted=<null>,recordsCommitted=100,meanSecondsBeforeSourceStateMessageEmitted=<null>,maxSecondsBeforeSourceStateMessageEmitted=<null>,maxSecondsBetweenStateMessageEmittedandCommitted=<null>,meanSecondsBetweenStateMessageEmittedandCommitted=<null>,additionalProperties={}]]]],normalizationSummary=<null>,state=io.airbyte.config.State@48615a15[state={"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}}],outputCatalog=io.airbyte.protocol.models.ConfiguredAirbyteCatalog@7693468e[streams=[io.airbyte.protocol.models.ConfiguredAirbyteStream@2f990520[stream=io.airbyte.protocol.models.AirbyteStream@fbf8288[name=Users,jsonSchema={"type":"object","$schema":"http://json-schema.org/draft-07/schema#","properties":{"id":{"type":"number"},"job":{"type":"string"},"sex":{"type":"string"},"ssn":{"type":"string"},"mail":{"type":"string"},"name":{"type":"string"},"address":{"type":"string"},"company":{"type":"string"},"website":{"type":"array"},"username":{"type":"string"},"residence":{"type":"string"},"created_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"},"updated_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"},"blood_group":{"type":"string"},"current_location":{"type":"array"}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[],namespace=<null>,additionalProperties={}],syncMode=full_refresh,cursorField=[],destinationSyncMode=overwrite,primaryKey=[],additionalProperties={}], io.airbyte.protocol.models.ConfiguredAirbyteStream@1e96ced6[stream=io.airbyte.protocol.models.AirbyteStream@72dd5cbc[name=Products,jsonSchema={"type":"object","$schema":"http://json-schema.org/draft-07/schema#","properties":{"id":{"type":"number"},"make":{"type":"string"},"year":{"type":"string"},"model":{"type":"string"},"price":{"type":"number"},"created_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"}}},supportedSyncModes=[full_refresh],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[],namespace=<null>,additionalProperties={}],syncMode=full_refresh,cursorField=[],destinationSyncMode=overwrite,primaryKey=[],additionalProperties={}], io.airbyte.protocol.models.ConfiguredAirbyteStream@150af7c2[stream=io.airbyte.protocol.models.AirbyteStream@66d28c29[name=Purchases,jsonSchema={"type":"object","$schema":"http://json-schema.org/draft-07/schema#","properties":{"id":{"type":"number"},"user_id":{"type":"number"},"product_id":{"type":"number"},"returned_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"},"purchased_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"},"added_to_cart_at":{"type":"string","format":"date-time","airbyte_type":"timestamp_without_timezone"}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[],namespace=<null>,additionalProperties={}],syncMode=full_refresh,cursorField=[],destinationSyncMode=overwrite,primaryKey=[],additionalProperties={}]],additionalProperties={}],failures=[]]
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.c.t.TemporalUtils(withBackgroundHeartbeat):280 - Stopping temporal heartbeating...
airbyte-server      | 2022-11-28 20:18:25 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/state/get - {"connectionId":"90825c11-8204-410a-ad1d-a841a3ea02c8"}
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.c.f.EnvVariableFeatureFlags(getEnvOrDefault):50 - Using default value for environment variable NEED_STATE_VALIDATION: 'true'
airbyte-server      | 2022-11-28 20:18:25 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/state/create_or_update - {"connectionId":"90825c11-8204-410a-ad1d-a841a3ea02c8","connectionState":{"stateType":"legacy","connectionId":"90825c11-8204-410a-ad1d-a841a3ea02c8","state":{"Users":{"cursor":100,"seed":-1},"Products":{"product_count":100},"Purchases":{"purchases_count":119}}}}
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.t.s.SyncWorkflowImpl(run):82 - generating normalization input
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/3/2/logs.log
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: dev
airbyte-server      | 2022-11-28 20:18:25 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.7 POST 200 /api/v1/attempt/set_workflow_in_attempt - {"jobId":3,"attemptNumber":2,"workflowId":"sync_3"}
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.w.n.DefaultNormalizationRunner(runProcess):139 - Running with normalization version: airbyte/normalization-duckdb:0.2.22
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- START DEFAULT NORMALIZATION -----
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.c.i.LineGobbler(voidCall):114 -
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.c.i.LineGobbler(voidCall):114 - Checking if airbyte/normalization-duckdb:0.2.22 exists...
airbyte-worker      | 2022-11-28 20:18:25 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/normalization-duckdb:0.2.22 not found locally. Attempting to pull the image...
airbyte-server      | 2022-11-28 20:18:26 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.4 POST 200 /api/v1/jobs/list - {"configId":"90825c11-8204-410a-ad1d-a841a3ea02c8","configTypes":["sync","reset_connection"],"pagination":{"pageSize":25}}
airbyte-webapp      | 172.18.0.1 - airbyte [28/Nov/2022:20:18:26 +0000] "POST /api/v1/jobs/list HTTP/1.1" 200 18405 "http://localhost:8000/workspaces/447352f0-70f1-4d70-8dde-d7c566db9a11/connections/90825c11-8204-410a-ad1d-a841a3ea02c8/status" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36" "-"
airbyte-server      | 2022-11-28 20:18:28 INFO i.a.s.RequestLogger(filter):112 - REQ 172.18.0.4 POST 200 /api/v1/jobs/list - {"configId":"90825c11-8204-410a-ad1d-a841a3ea02c8","configTypes":["sync","reset_connection"],"pagination":{"pageSize":25}}
airbyte-webapp      | 172.18.0.1 - airbyte [28/Nov/2022:20:18:28 +0000] "POST /api/v1/jobs/list HTTP/1.1" 200 18420 "http://localhost:8000/workspaces/447352f0-70f1-4d70-8dde-d7c566db9a11/connections/90825c11-8204-410a-ad1d-a841a3ea02c8/status" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36" "-"
airbyte-worker      | 2022-11-28 20:18:29 INFO i.a.c.i.LineGobbler(voidCall):114 - Image does not exist.
airbyte-worker      | 2022-11-28 20:18:29 INFO i.a.w.g.DefaultNormalizationWorker(run):82 - Normalization executed in 3 seconds.
airbyte-worker      | 2022-11-28 20:18:29 INFO i.a.w.t.TemporalAttemptExecution(lambda$getWorkerThread$2):164 - Completing future exceptionally...
airbyte-worker      | io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:92) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:27) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:161) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | 2022-11-28 20:18:29 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling...
airbyte-worker      | 2022-11-28 20:18:29 INFO i.a.c.t.TemporalUtils(withBackgroundHeartbeat):280 - Stopping temporal heartbeating...
airbyte-worker      | 2022-11-28 20:18:29 WARN i.t.i.a.POJOActivityTaskHandler(activityFailureToResult):307 - Activity failure. ActivityId=bf7953f6-7961-396b-bed7-11850be40ac5, activityType=Normalize, attempt=1
airbyte-worker      | java.lang.RuntimeException: io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:278) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.normalize(NormalizationActivityImpl.java:93) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
airbyte-worker      |   at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:214) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:180) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:120) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:204) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:164) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | Caused by: io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at io.temporal.serviceclient.CheckedExceptionWrapper.wrap(CheckedExceptionWrapper.java:56) ~[temporal-serviceclient-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.WorkflowInternal.wrap(WorkflowInternal.java:448) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.activity.Activity.wrap(Activity.java:51) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:138) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.lambda$normalize$3(NormalizationActivityImpl.java:121) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:273) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   ... 14 more
airbyte-worker      | Caused by: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[?:?]
airbyte-worker      |   at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073) ~[?:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:132) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.lambda$normalize$3(NormalizationActivityImpl.java:121) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:273) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   ... 14 more
airbyte-worker      | Caused by: io.airbyte.workers.exception.WorkerException: Normalization Failed.
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:92) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:27) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:161) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   ... 1 more
airbyte-worker      | 2022-11-28 20:18:29 ERROR i.t.i.s.WorkflowExecuteRunnable(logWorkflowExecutionException):125 - Workflow execution failure WorkflowId=sync_3, RunId=933c5c7e-dfd4-45bd-810b-66b2d6ebdcdc, WorkflowType=SyncWorkflow
airbyte-worker      | io.temporal.failure.ActivityFailure: scheduledEventId=31, startedEventId=32, activityType='Normalize', activityId='bf7953f6-7961-396b-bed7-11850be40ac5', identity='1@d74c69727d08', retryState=RETRY_STATE_MAXIMUM_ATTEMPTS_REACHED
airbyte-worker      |   at java.lang.Thread.getStackTrace(Thread.java:1610) ~[?:?]
airbyte-worker      |   at io.temporal.internal.sync.ActivityStubBase.execute(ActivityStubBase.java:48) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.ActivityInvocationHandler.lambda$getActivityFunc$0(ActivityInvocationHandler.java:77) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.ActivityInvocationHandlerBase.invoke(ActivityInvocationHandlerBase.java:70) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at jdk.proxy2.$Proxy103.normalize(Unknown Source) ~[?:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.SyncWorkflowImpl.run(SyncWorkflowImpl.java:85) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at SyncWorkflowImplProxy.run$accessor$dJlyJFnl(Unknown Source) ~[?:?]
airbyte-worker      |   at SyncWorkflowImplProxy$auxiliary$kv776tte.call(Unknown Source) ~[?:?]
airbyte-worker      |   at io.airbyte.workers.temporal.support.TemporalActivityStubInterceptor.execute(TemporalActivityStubInterceptor.java:79) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at SyncWorkflowImplProxy.run(Unknown Source) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
airbyte-worker      |   at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
airbyte-worker      |   at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
airbyte-worker      |   at io.temporal.internal.sync.POJOWorkflowImplementationFactory$POJOWorkflowImplementation$RootWorkflowInboundCallsInterceptor.execute(POJOWorkflowImplementationFactory.java:317) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.POJOWorkflowImplementationFactory$POJOWorkflowImplementation.execute(POJOWorkflowImplementationFactory.java:292) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.WorkflowExecuteRunnable.run(WorkflowExecuteRunnable.java:72) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.SyncWorkflow.lambda$start$0(SyncWorkflow.java:137) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.CancellationScopeImpl.run(CancellationScopeImpl.java:101) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.sync.WorkflowThreadImpl$RunnableWrapper.run(WorkflowThreadImpl.java:111) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
airbyte-worker      |   at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | Caused by: io.temporal.failure.ApplicationFailure: message='io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.', type='java.lang.RuntimeException', nonRetryable=false
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:278) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.normalize(NormalizationActivityImpl.java:93) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method:0) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
airbyte-worker      |   at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:214) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:180) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:120) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:204) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:164) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.base/java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | Caused by: io.temporal.failure.ApplicationFailure: message='io.airbyte.workers.exception.WorkerException: Normalization Failed.', type='java.util.concurrent.ExecutionException', nonRetryable=false
airbyte-worker      |   at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[?:?]
airbyte-worker      |   at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073) ~[?:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:132) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.lambda$normalize$3(NormalizationActivityImpl.java:121) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.commons.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:273) ~[io.airbyte-airbyte-commons-temporal-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.normalize(NormalizationActivityImpl.java:93) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method:0) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
airbyte-worker      |   at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
airbyte-worker      |   at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:214) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:180) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.activity.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:120) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:204) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:164) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.8.1.jar:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
airbyte-worker      |   at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
airbyte-worker      |   at java.base/java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | Caused by: io.temporal.failure.ApplicationFailure: message='Normalization Failed.', type='io.airbyte.workers.exception.WorkerException', nonRetryable=false
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:92) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:27) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:161) ~[io.airbyte-airbyte-workers-0.40.10.jar:?]
airbyte-worker      |   at java.base/java.lang.Thread.run(Thread.java:833) ~[?:?]
airbyte-worker      | 2022-11-28 20:18:29 INFO i.a.a.LoggingTrackingClient(track):43 - track. version: null, userId: null, action: Connector Jobs, metadata: {job_type=sync, namespace_definition=source, frequency=1440 min, connector_source_definition_id=dfd88b22-b603-4c3d-aad7-3701784586b1, workspace_id=447352f0-70f1-4d70-8dde-d7c566db9a11, attempt_stage=ENDED, main_failure_reason={"failureOrigin":"normalization","failureType":null,"internalMessage":"message='io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.', type='java.lang.RuntimeException', nonRetryable=false","externalMessage":"Something went wrong during normalization","metadata":{"attemptNumber":0,"jobId":3},"retryable":null,"timestamp":1669666698432}, attempt_id=3, connector_destination=DuckDB, connector_destination_docker_repository=airbyte/destination-duckdb, table_prefix=false, workspace_name=447352f0-70f1-4d70-8dde-d7c566db9a11, failure_reasons=[{"failureOrigin":"normalization","failureType":null,"internalMessage":"message='io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.', type='java.lang.RuntimeException', nonRetryable=false","externalMessage":"Something went wrong during normalization","metadata":{"attemptNumber":0,"jobId":3},"retryable":null,"timestamp":1669666698432},{"failureOrigin":"normalization","failureType":null,"internalMessage":"message='io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.', type='java.lang.RuntimeException', nonRetryable=false","externalMessage":"Something went wrong during normalization","metadata":{"attemptNumber":1,"jobId":3},"retryable":null,"timestamp":1669666702781},{"failureOrigin":"normalization","failureType":null,"internalMessage":"message='io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed.', type='java.lang.RuntimeException', nonRetryable=false","externalMessage":"Something went wrong during normalization","metadata":{"attemptNumber":2,"jobId":3},"retryable":null,"timestamp":1669666709212}], catalog.destination_sync_mode.overwrite=set, number_of_streams=3, connector_source=Faker, connector_source_docker_repository=airbyte/source-faker, attempt_completion_status=FAILED, catalog.sync_mode.full_refresh=set, connection_id=90825c11-8204-410a-ad1d-a841a3ea02c8, job_id=3, connector_source_version=0.1.6, config.destination.destination_path=set, connector_destination_version=dev, config.source.records_per_sync=set, operation.normalization=1, config.source.records_per_slice=set, operation_count=1, connector_destination_definition_id=3417e215-ae62-4632-8179-0c8ac8fda975, config.source.count=set, config.source.seed=set}
airbyte-worker      | 2022-11-28 20:18:29 INFO i.a.c.f.EnvVariableFeatureFlags(autoDisablesFailingConnections):19 - Auto Disable Failing Connections: false

sspaeti avatar Nov 25 '22 15:11 sspaeti

this was buried pretty deeply - from the full logs:

airbyte-worker      | 2022-11-28 20:18:16 INFO i.a.c.i.LineGobbler(voidCall):114 - airbyte/normalization-duckdb:0.2.22 not found locally. Attempting to pull the image...
airbyte-worker      | 2022-11-28 20:18:18 INFO i.a.c.i.LineGobbler(voidCall):114 - Image does not exist.

if you run ./gradlew :airbyte-integrations:bases:base-normalization:airbyteDockerDuckDb, does that build an airbyte/normalization-duckdb:dev image locally? if yes, I think you could do docker tag airbyte/normalization-duckdb:dev airbyte/normalization-duckdb:0.2.22 to get this working.

Or just update this line to say = "dev"; and rebuild the platform.

edgao avatar Nov 28 '22 21:11 edgao

Latest update

  • DuckDB destination is working
  • Normalization part is having some errors.

Normalization

NOTE: DuckDB is the same as SQLite a single-file DB. Meaning, unlike BigQuery or others that stay persisted during the airbyte sync. This file will/should be generated or accessed from a local path.

The current assessment is, that the local duckdb-file is not persisted on my local MacBook filesystem, that way the normalization container will not have access to the duckdb-file that was generated inside the destination-duckdb container (stored in airbyte-worker and airbyte-server as well).

Question to check:

  • Is it possible to map a filesystem that is persisted outside of the containers? I tried the magic folder /tmp/airbyte_local that is mapped to /local/ as explained in the docs here. But I was not able to see any file on my local file system on my MacBook.
  • If the above is possible, does the normalization container support reading from that location as well? Or is that only intended to work for destination connectors?

Or do you have any other suggestion to persist the single DuckDB file on a central place?

sspaeti avatar Dec 22 '22 11:12 sspaeti

After correctly configure Docker Desktop as fixed with https://github.com/airbytehq/airbyte/pull/21004, the /tmp/airbyte_local is correctly accessed by the destination-duckdb container and tables are generated (there is a capital case in the table names that looks odd, but I tried to delete and adding without capitalized, and still got the error below).

/tmp/airbyte_local/duckdb                                                                                                                               destination-duckdb
❮ duckdb destination.duckdb
v0.6.0 2213f9c946
Enter ".help" for usage hints.
D select * from information_schema.tables;
┌───────────────┬──────────────┬──────────────────────┬────────────┬──────────────────────┬───┬──────────────────────┬────────────────────┬──────────┬───────────────┐
│ table_catalog │ table_schema │      table_name      │ table_type │ self_referencing_c…  │ … │ user_defined_type_…  │ is_insertable_into │ is_typed │ commit_action │
│     int32     │   varchar    │       varchar        │  varchar   │        int32         │   │        int32         │      varchar       │ varchar  │    varchar    │
├───────────────┼──────────────┼──────────────────────┼────────────┼──────────────────────┼───┼──────────────────────┼────────────────────┼──────────┼───────────────┤
│               │ main         │ _airbyte_raw_Users   │ BASE TABLE │                      │ … │                      │ YES                │ NO       │               │
│               │ main         │ _airbyte_raw_Produ…  │ BASE TABLE │                      │ … │                      │ YES                │ NO       │               │
│               │ main         │ _airbyte_raw_Purch…  │ BASE TABLE │                      │ … │                      │ YES                │ NO       │               │
├───────────────┴──────────────┴──────────────────────┴────────────┴──────────────────────┴───┴──────────────────────┴────────────────────┴──────────┴───────────────┤
│ 3 rows                                                                                                                                        12 columns (9 shown) │
└────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┘

The question now is if the irbyte/normalization-duckdb:0.2.22 can read that shared file on the mac local filesystem can access too. The log indicates that the volume is also mapped to the normalization container:

airbyte-worker | 2023-01-04 10:52:49 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/5/2/normalize --log-driver none --name normalization-duckdb-normalize-5-2-wjkqp --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=dev airbyte/normalization-duckdb:0.2.22 run --integration-type duckdb --config destination_config.json --catalog destination_catalog.json

Unfortunately the error still remains, that the dbt run seems not to see the tables, eventhouh they exists:

airbyte-worker      | 2023-01-04 10:53:58 normalization > 10:53:58  Running with dbt=1.0.8
airbyte-worker      | 2023-01-04 10:53:58 normalization > dbt version: 1.0.8
airbyte-worker      | 2023-01-04 10:53:58 normalization > python version: 3.9.9
airbyte-worker      | 2023-01-04 10:53:58 normalization > python path: /usr/local/bin/python
airbyte-worker      | 2023-01-04 10:53:58 normalization > os info: Linux-5.15.49-linuxkit-x86_64-with-glibc2.31
airbyte-worker      | 2023-01-04 10:53:58 normalization > Using profiles.yml file at /data/5/2/normalize/profiles.yml
airbyte-worker      | 2023-01-04 10:53:58 normalization > Using dbt_project.yml file at /data/5/2/normalize/dbt_project.yml
airbyte-worker      | 2023-01-04 10:53:58 INFO i.a.w.n.NormalizationAirbyteStreamFactory(filterOutAndHandleNonAirbyteMessageLines):104 -
airbyte-worker      | 2023-01-04 10:53:58 normalization > Configuration:
airbyte-worker      | 2023-01-04 10:53:58 normalization >   profiles.yml file [OK found and valid]
airbyte-worker      | 2023-01-04 10:53:58 normalization >   dbt_project.yml file [OK found and valid]
airbyte-worker      | 2023-01-04 10:53:58 INFO i.a.w.n.NormalizationAirbyteStreamFactory(filterOutAndHandleNonAirbyteMessageLines):104 -
airbyte-worker      | 2023-01-04 10:53:58 normalization > Required dependencies:
airbyte-worker      | 2023-01-04 10:53:58 normalization >  - git [OK found]
airbyte-worker      | 2023-01-04 10:53:58 INFO i.a.w.n.NormalizationAirbyteStreamFactory(filterOutAndHandleNonAirbyteMessageLines):104 -
airbyte-worker      | 2023-01-04 10:53:58 normalization > Connection:
airbyte-worker      | 2023-01-04 10:53:58 normalization >   database: main
airbyte-worker      | 2023-01-04 10:53:58 normalization >   schema: main
airbyte-worker      | 2023-01-04 10:53:58 normalization >   path: :memory:
airbyte-worker      | 2023-01-04 10:53:59 normalization >   Connection test: [OK connection ok]
airbyte-worker      | 2023-01-04 10:53:59 INFO i.a.w.n.NormalizationAirbyteStreamFactory(filterOutAndHandleNonAirbyteMessageLines):104 -
airbyte-worker      | 2023-01-04 10:53:59 normalization > All checks passed!
airbyte-worker      | 2023-01-04 10:53:59 INFO i.a.w.n.NormalizationAirbyteStreamFactory(filterOutAndHandleNonAirbyteMessageLines):104 -
airbyte-worker      | 2023-01-04 10:53:59 normalization > Forward dbt output logs to diagnose/debug errors (0):
airbyte-worker      | 2023-01-04 10:53:59 INFO i.a.w.n.NormalizationAirbyteStreamFactory(filterOutAndHandleNonAirbyteMessageLines):104 -
airbyte-worker      | 2023-01-04 10:53:59 normalization > Running with dbt=1.0.8
airbyte-worker      | 2023-01-04 10:53:59 normalization > Partial parse save file not found. Starting full parse.
airbyte-worker      | 2023-01-04 10:53:59 normalization > [WARNING]: Configuration paths exist in your dbt_project.yml file which do not apply to any resources.
airbyte-worker      | There are 2 unused configuration paths:
airbyte-worker      | - models.airbyte_utils.generated.airbyte_views
airbyte-worker      | - models.airbyte_utils.generated.airbyte_incremental
airbyte-worker      |
airbyte-worker      | 2023-01-04 10:53:59 normalization > Found 12 models, 0 tests, 0 snapshots, 0 analyses, 600 macros, 0 operations, 0 seed files, 3 sources, 0 exposures, 0 metrics
airbyte-worker      | 2023-01-04 10:53:59 normalization > Concurrency: 1 threads (target='prod')
airbyte-worker      | 2023-01-04 10:53:59 normalization > 1 of 3 START table model main.products.................................................................................. [RUN]
airbyte-worker      | 2023-01-04 10:53:59 normalization > 1 of 3 ERROR creating table model main.products......................................................................... [ERROR in 0.38s]
airbyte-worker      | 2023-01-04 10:53:59 normalization > 2 of 3 START table model main.purchases................................................................................. [RUN]
airbyte-worker      | 2023-01-04 10:53:59 normalization > 2 of 3 ERROR creating table model main.purchases........................................................................ [ERROR in 0.18s]
airbyte-worker      | 2023-01-04 10:53:59 normalization > 3 of 3 START table model main.users..................................................................................... [RUN]
airbyte-worker      | 2023-01-04 10:53:59 normalization > 3 of 3 ERROR creating table model main.users............................................................................ [ERROR in 0.20s]
airbyte-worker      | 2023-01-04 10:53:59 normalization > Finished running 3 table models in 2.77s.
airbyte-worker      | 2023-01-04 10:53:59 normalization > Completed with 3 errors and 0 warnings:
airbyte-worker      | 2023-01-04 10:53:59 normalization > Runtime Error in model products (models/generated/airbyte_tables/main/products.sql)
airbyte-worker      | 2023-01-04 10:53:59 normalization >   Catalog Error: Table with name _airbyte_raw_products does not exist!
airbyte-worker      | 2023-01-04 10:53:59 normalization >   Did you mean "sqlite_master"?
airbyte-worker      | 2023-01-04 10:53:59 normalization > Runtime Error in model purchases (models/generated/airbyte_tables/main/purchases.sql)
airbyte-worker      | 2023-01-04 10:53:59 normalization >   Catalog Error: Table with name _airbyte_raw_purchases does not exist!
airbyte-worker      | 2023-01-04 10:53:59 normalization >   Did you mean "sqlite_temp_schema"?
airbyte-worker      | 2023-01-04 10:53:59 normalization > Runtime Error in model users (models/generated/airbyte_tables/main/users.sql)
airbyte-worker      | 2023-01-04 10:53:59 normalization >   Catalog Error: Table with name _airbyte_raw_users does not exist!
airbyte-worker      | 2023-01-04 10:53:59 normalization >   Did you mean "sqlite_master"?
airbyte-worker      | 2023-01-04 10:53:59 normalization > Done. PASS=0 WARN=0 ERROR=3 SKIP=0 TOTAL=3
airbyte-worker      | 2023-01-04 10:53:59 normalization > WARNING: The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
airbyte-worker      | 2023-01-04 10:53:59 INFO i.a.w.g.DefaultNormalizationWorker(run):82 - Normalization executed in 1 minute 9 seconds.
airbyte-worker      | 2023-01-04 10:53:59 ERROR i.a.w.g.DefaultNormalizationWorker(run):90 - Normalization Failed.
airbyte-worker      | 2023-01-04 10:53:59 INFO i.a.w.g.DefaultNormalizationWorker(run):95 - Normalization summary: io.airbyte.config.NormalizationSummary@536822dc[startTime=1672829569837,endTime=1672829639447,failures=[io.airbyte.config.FailureReason@63f52866[failureOrigin=normalization,failureType=system_error,internalMessage=Catalog Error:

Full Log: a2cc2136_b476_493d_bb79_a034778885ec_logs_5_txt.txt

According to @edgao this is a sign that Normalization can't read the file. @evantahler do you know if that is possible?

Otherwise I will disable normalization for now and prepare the PR to do raw tables only without normalization.

sspaeti avatar Jan 04 '23 11:01 sspaeti

@sspaeti I think the capitalization is getting you in trouble. MacOS filesystems are case-insensitive, most linux filesystems are not. It looks like you are using source-faker. What version are you on? V2.0.0+ should have lower-case names for everything. Try refreshing your source schema

evantahler avatar Jan 04 '23 22:01 evantahler

Wow, dbt run and normalization finally worked. Thanks so much Evan.

image

I used version 1.6 of Faker, I updated to 2.0, but the error was the same. The problem was dbt used the wrong config, instead of destination_path which I used for the destination-duckdb, it must be path for profiles.yml in normalization: image

After that, I had to fix a small null handling, but then it worked!!! 🎉

sspaeti avatar Jan 06 '23 10:01 sspaeti

Affected Connector Report

NOTE ⚠️ Changes in this PR affect the following connectors. Make sure to do the following as needed:

  • Run integration tests
  • Bump connector or module version
  • Add changelog
  • Publish the new version

✅ Sources (0)
Connector Version Changelog Publish
  • See "Actionable Items" below for how to resolve warnings and errors.

❌ Destinations (16)
Connector Version Changelog Publish
destination-bigquery 1.2.13 ✅ ✅
destination-bigquery-denormalized 1.2.12 ✅ ❌
(diff seed version)
destination-clickhouse 0.2.2 ❌
(changelog missing)		 ✅
destination-clickhouse-strict-encrypt 0.2.2 🔵
(ignored)		 🔵
(ignored)
destination-jdbc 0.3.14 🔵
(ignored)		 🔵
(ignored)
destination-mssql 0.1.22 ✅ ✅
destination-mssql-strict-encrypt 0.1.22 🔵
(ignored)		 🔵
(ignored)
destination-mysql 0.1.20 ✅ ✅
destination-mysql-strict-encrypt ❌ 0.1.21
(mismatch: 0.1.20)		 🔵
(ignored)		 🔵
(ignored)
destination-oracle 0.1.19 ✅ ✅
destination-oracle-strict-encrypt 0.1.19 🔵
(ignored)		 🔵
(ignored)
destination-postgres 0.3.26 ✅ ✅
destination-postgres-strict-encrypt 0.3.26 🔵
(ignored)		 🔵
(ignored)
destination-redshift 0.3.56 ✅ ✅
destination-snowflake 0.4.47 ✅ ✅
destination-tidb 0.1.0 ✅ ✅
  • See "Actionable Items" below for how to resolve warnings and errors.

👀 Other Modules (1)
  • base-normalization

Actionable Items

(click to expand)
Category Status Actionable Item
Version ❌
mismatch		 The version of the connector is different from its normal variant. Please bump the version of the connector.
⚠
doc not found		 The connector does not seem to have a documentation file. This can be normal (e.g. basic connector like source-jdbc is not published or documented). Please double-check to make sure that it is not a bug.
Changelog ⚠
doc not found		 The connector does not seem to have a documentation file. This can be normal (e.g. basic connector like source-jdbc is not published or documented). Please double-check to make sure that it is not a bug.
❌
changelog missing		 There is no chnagelog for the current version of the connector. If you are the author of the current version, please add a changelog.
Publish ⚠
not in seed		 The connector is not in the seed file (e.g. source_definitions.yaml), so its publication status cannot be checked. This can be normal (e.g. some connectors are cloud-specific, and only listed in the cloud seed file). Please double-check to make sure that it is not a bug.
❌
diff seed version		 The connector exists in the seed file, but the latest version is not listed there. This usually means that the latest version is not published. Please use the /publish command to publish the latest version.

github-actions[bot] avatar Jan 06 '23 13:01 github-actions[bot]

Make sure your logo is a square SVG please. Add padding around the image if needed

Good to know, changed it to square.

sspaeti avatar Jan 06 '23 14:01 sspaeti

After merging the latest master into my branch, unfortunately, it does not work any longer.

Problem with:

airbyte-worker                    | 2023-01-09 07:14:40 ERROR i.a.w.g.DefaultNormalizationWorker(run):83 - Normalization failed for job 4.
airbyte-worker                    | java.lang.NullPointerException: Cannot invoke "String.toLowerCase()" because "this.normalizationIntegrationType" is null
airbyte-worker                    |     at io.airbyte.workers.normalization.DefaultNormalizationRunner.normalize(DefaultNormalizationRunner.java:111) ~[io.airbyte-airbyte-commons-worker-0.40.27.jar:?]
airbyte-worker                    |     at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:77) ~[io.airbyte-airbyte-commons-worker-0.40.27.jar:?]
airbyte-worker                    |     at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:34) ~[io.airbyte-airbyte-commons-worker-0.40.27.jar:?]
airbyte-worker                    |     at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$5(TemporalAttemptExecution.java:195) ~[io.airbyte-airbyte-workers-0.40.27.jar:?]
airbyte-worker                    |     at java.lang.Thread.run(Thread.java:1589) ~[?:?]

and the build:

> Task :airbyte-workers:compileTestJava
Note: Some input files use or override a deprecated API.
Note: Recompile with -Xlint:deprecation for details.
Note: Some input files use unchecked or unsafe operations.
Note: Recompile with -Xlint:unchecked for details.

> Task :airbyte-config:init:test

SpecFormatTest > testOnAllExistingConfig() FAILED
    java.lang.AssertionError:
    Expecting empty but was: [java.lang.RuntimeException: Fail JsonSecretsProcessor validation
        at io.airbyte.config.init.SpecFormatTest.lambda$testOnAllExistingConfig$3(SpecFormatTest.java:45)
        at org.assertj.core.api.iterable.ThrowingExtractor.apply(ThrowingExtractor.java:36)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        ...(96 remaining lines not displayed - this can be changed with Assertions.setMaxStackTraceElementsDisplayed)]
        at io.airbyte.config.init.SpecFormatTest.testOnAllExistingConfig(SpecFormatTest.java:54)

I saw that normalization got some refactoring with Remove NormalizationRunnerFactor/, therefore I added the normalization config new to https://github.com/airbytehq/airbyte/pull/17494/files#diff-cf6d9c25b8431c548f892f1628738b7906118ee3be857d15be354119a8130f0f, which most probably causes the error? image

Any hint on how to resolve that would be super helpful. As said, without these refactoring it worked, meaning one step might be missing for the duckdb refactoring.

FullLog: b295da17_db9d_43cf_9d17_ec7712374b40_logs_4_txt.txt

ReleaseStage

Also on a side note: When I start airbyte locally with:

SUB_BUILD=PLATFORM ./gradlew build
VERSION=dev docker-compose up

I see two duckdb version: image

I'm using the dev version. When I merge, is it correct, that my dev version will be running as alpha as defined in destination_definitions.yaml as releaseStage?

sspaeti avatar Jan 09 '23 08:01 sspaeti

After modifying the normalization config, you will need to both rebuild the platform and reboot your docker deployment. The bootloader will update your local database and then it should work.

evantahler avatar Jan 09 '23 19:01 evantahler

After modifying the normalization config, you will need to both rebuild the platform and reboot your docker deployment. The bootloader will update your local database and then it should work.

Thanks so much; unfortunately, I still have the same error java.lang.NullPointerException: Cannot invoke "String.toLowerCase()" because "this.normalizationIntegrationType" is null after restarting docker and airbyte.

@andriikorotkov or @pedroslopez, do you have any hint why https://github.com/airbytehq/airbyte/pull/17494#issuecomment-1375284633 should not work, or I'm getting this error? It worked with my old configurations from October on my branch.

In the meantime, I saw these two PRs that probably affected normalization: https://github.com/airbytehq/airbyte/pull/20245 and https://github.com/airbytehq/airbyte/pull/20573. If I'm wrong, please tell me. But I'm close to finalizing but I guess it's a problem that is beyond my knowledge as I'm not sure what changed in normalization. Thanks so much.

sspaeti avatar Jan 10 '23 06:01 sspaeti

Ready for Review

After adding the missing properties from spec.json to destination_specs.yaml solved the problem, see the commit here.

Then Normalization succeeded: image

Destination: image

Success Sync in Airbyte: image

As well I see the rows in the raw and normalized tables:

/tmp/airbyte_local/duck
❯ duckdb dest.duckdb
v0.6.0 2213f9c946
Enter ".help" for usage hints.
D select count(*) from main._airbyte_raw_Products;
┌──────────────┐
│ count_star() │
│    int64     │
├──────────────┤
│          100 │
└──────────────┘
D  select * from information_schema."tables";
┌───────────────┬──────────────┬──────────────────────┬────────────┬───┬──────────────────────┬────────────────────┬──────────┬───────────────┐
│ table_catalog │ table_schema │      table_name      │ table_type │ … │ user_defined_type_…  │ is_insertable_into │ is_typed │ commit_action │
│     int32     │   varchar    │       varchar        │  varchar   │   │        int32         │      varchar       │ varchar  │    varchar    │
├───────────────┼──────────────┼──────────────────────┼────────────┼───┼──────────────────────┼────────────────────┼──────────┼───────────────┤
│               │ main         │ purchases            │ BASE TABLE │ … │                      │ YES                │ NO       │               │
│               │ main         │ _airbyte_raw_purch…  │ BASE TABLE │ … │                      │ YES                │ NO       │               │
│               │ main         │ _airbyte_raw_users   │ BASE TABLE │ … │                      │ YES                │ NO       │               │
│               │ main         │ _airbyte_raw_produ…  │ BASE TABLE │ … │                      │ YES                │ NO       │               │
│               │ main         │ products             │ BASE TABLE │ … │                      │ YES                │ NO       │               │
│               │ main         │ users                │ BASE TABLE │ … │                      │ YES                │ NO       │               │
├───────────────┴──────────────┴──────────────────────┴────────────┴───┴──────────────────────┴────────────────────┴──────────┴───────────────┤
│ 6 rows                                                                                                                 12 columns (8 shown) │
└─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┘
D select count(*) from products;
┌──────────────┐
│ count_star() │
│    int64     │
├──────────────┤
│          100 │
└──────────────┘

sspaeti avatar Jan 11 '23 16:01 sspaeti

@edgao I finished the code review:

🎉 this is exciting! I left a number of comments. They're mostly nitpicky, but the stuff in destination.py is maybe actually important. But feel free to tell me I don't know what I'm talking about, you're the expert on this destination :)

Thank so much for your thoughtful review. I checked all cases, improved where possible, tested some things, and had to revert (all in the conversations/threads above). Now I have a working copy again with your changes. IMO it's ready to merge.

Also - when you run the integration tests locally, does it generate any sql files in normalization_test_output? (iirc it should, and you should commit those as well)

There is, but there are only two files normalization_test_output/duckdb/test_nested_streams/dbt_project.yml and normalization_test_output/duckdb/test_simple_streams/dbt_project.yml. Hope that's ok.

sspaeti avatar Jan 24 '23 10:01 sspaeti

Airbyte Code Coverage

There is no coverage information present for the Files changed

Total Project Coverage 24.53% :x:

github-actions[bot] avatar Jan 24 '23 10:01 github-actions[bot]

There's a couple conflicting files but overall looks good. I don't see any things that I would follow up on aside from the DESTINATION_SIZE_LIMIT you mentioned before

@marcosmarxm is there anything else that I should look out for when it comes to certifying a connector? This would be the first time I've done such a review and mostly been following the building a python destination documentation

For instance, would we need to set up the integration tests internally or does the build passing give that sanity check?

ryankfu avatar Jan 31 '23 02:01 ryankfu