search

airbytehq / airbyte

The leading data integration platform for ETL / ELT data pipelines from APIs, databases & files to data warehouses, data lakes & data lakehouses. Both self-hosted and Cloud-hosted.
https://airbyte.com
Other
15.94k stars 4.09k forks source link

Airbyte basic normalization fails for mssql after successful raw load from Oracle source #7536

Closed walkabout21 closed 2 years ago

walkabout21 commented 2 years ago

Current behavior: see attached log

walkabout21 commented 2 years ago 
2021-10-29 18:35:59 INFO () WorkerRun(call):49 - Executing worker wrapper. Airbyte version: 0.30.23-alpha
2021-10-29 18:35:59 INFO () TemporalAttemptExecution(get):94 - Executing worker wrapper. Airbyte version: 0.30.23-alpha
2021-10-29 18:35:59 WARN () Databases(createPostgresDatabaseWithRetry):38 - Waiting for database to become available...
2021-10-29 18:35:59 INFO () JobsDatabaseInstance(lambda$static$2):25 - Testing if jobs database is ready...
2021-10-29 18:35:59 INFO () Databases(createPostgresDatabaseWithRetry):55 - Database available!
2021-10-29 18:35:59 INFO () DefaultReplicationWorker(run):82 - start sync worker. job id: 10 attempt id: 0
2021-10-29 18:35:59 INFO () DefaultReplicationWorker(run):91 - configured sync modes: {CSPROJECTS.PROJ_PROJECT=full_refresh - overwrite}
2021-10-29 18:35:59 INFO () DefaultAirbyteDestination(start):58 - Running destination...
2021-10-29 18:35:59 INFO () LineGobbler(voidCall):65 - Checking if airbyte/destination-mssql:0.1.10 exists...
2021-10-29 18:35:59 INFO () LineGobbler(voidCall):65 - airbyte/destination-mssql:0.1.10 was found locally.
2021-10-29 18:35:59 INFO () DockerProcessFactory(create):127 - Preparing command: docker run --rm --init -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/10/0 --network host --log-driver none airbyte/destination-mssql:0.1.10 write --config destination_config.json --catalog destination_catalog.json
2021-10-29 18:35:59 INFO () LineGobbler(voidCall):65 - Checking if airbyte/source-oracle:0.3.8 exists...
2021-10-29 18:35:59 INFO () LineGobbler(voidCall):65 - airbyte/source-oracle:0.3.8 was found locally.
2021-10-29 18:35:59 INFO () DockerProcessFactory(create):127 - Preparing command: docker run --rm --init -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/10/0 --network host --log-driver none airbyte/source-oracle:0.3.8 read --config source_config.json --catalog source_catalog.json
2021-10-29 18:35:59 INFO () DefaultReplicationWorker(run):119 - Waiting for source thread to join.
2021-10-29 18:35:59 INFO () DefaultReplicationWorker(lambda$getDestinationOutputRunnable$3):226 - Destination output thread started.
2021-10-29 18:35:59 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):190 - Replication thread started.
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 INFO i.a.i.d.m.MSSQLDestination(main):96 - {} - starting destination: class io.airbyte.integrations.destination.mssql.MSSQLDestination
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 INFO i.a.i.b.IntegrationRunner(run):76 - {} - Running integration: io.airbyte.integrations.base.ssh.SshWrappedDestination
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 INFO i.a.i.b.IntegrationCliParser(parseOptions):115 - {} - integration args: {catalog=destination_catalog.json, write=null, config=destination_config.json}
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 INFO i.a.i.b.IntegrationRunner(run):80 - {} - Command: WRITE
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 INFO i.a.i.b.IntegrationRunner(run):81 - {} - Integration config: IntegrationConfig{command=WRITE, configPath='destination_config.json', catalogPath='destination_catalog.json', statePath='null'}
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 INFO i.a.i.s.o.OracleSource(main):174 - {} - starting source: class io.airbyte.integrations.source.oracle.OracleSource
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 WARN c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword order - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 WARN c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword examples - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 WARN c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword airbyte_secret - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 WARN c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword multiline - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 INFO i.a.i.b.IntegrationRunner(run):76 - {} - Running integration: io.airbyte.integrations.base.ssh.SshWrappedSource
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 INFO i.a.i.b.IntegrationCliParser(parseOptions):115 - {} - integration args: {read=null, catalog=source_catalog.json, config=source_config.json}
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 INFO i.a.i.b.IntegrationRunner(run):80 - {} - Command: READ
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 INFO i.a.i.b.IntegrationRunner(run):81 - {} - Integration config: IntegrationConfig{command=READ, configPath='source_config.json', catalogPath='source_catalog.json', statePath='null'}
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 WARN c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword airbyte_secret - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 WARN c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword order - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 WARN c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword multiline - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 WARN c.n.s.JsonMetaSchema(newValidator):338 - {} - Unknown keyword examples - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword
2021-10-29 18:36:00 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:00 INFO i.a.i.b.s.SshTunnel(getInstance):170 - {} - Starting connection with method: NO_TUNNEL
2021-10-29 18:36:01 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:01 INFO i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$toWriteConfig$0):96 - {} - Write config: WriteConfig{streamName=airbyte_test_PROJ_PROJECT, namespace=null, outputSchemaName=dbo, tmpTableName=_airbyte_tmp_nha_airbyte_test_PROJ_PROJECT, outputTableName=_airbyte_raw_airbyte_test_PROJ_PROJECT, syncMode=overwrite}
2021-10-29 18:36:01 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:01 INFO i.a.i.d.b.BufferedStreamConsumer(startTracked):123 - {} - class io.airbyte.integrations.destination.buffered_stream_consumer.BufferedStreamConsumer started.
2021-10-29 18:36:01 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:01 INFO i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):119 - {} - Preparing tmp tables in destination started for 1 streams
2021-10-29 18:36:01 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:01 INFO i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):123 - {} - Preparing tmp table in destination started for stream airbyte_test_PROJ_PROJECT. schema: dbo, tmp table name: _airbyte_tmp_nha_airbyte_test_PROJ_PROJECT
2021-10-29 18:36:01 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:01 INFO i.a.i.b.s.SshTunnel(getInstance):170 - {} - Starting connection with method: NO_TUNNEL
2021-10-29 18:36:01 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:01 INFO i.a.i.s.r.CdcStateManager(<init>):26 - {} - Initialized CDC state with: null
2021-10-29 18:36:01 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:01 INFO i.a.i.s.r.StateManager(createCursorInfoForStream):118 - {} - No cursor field set in catalog but not present in state. Stream: AirbyteStreamNameNamespacePair{name='PROJ_PROJECT', namespace='CSPROJECTS'}, New Cursor Field: null. Resetting cursor value
2021-10-29 18:36:02 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:02 INFO i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):129 - {} - Preparing tables in destination completed.
2021-10-29 18:36:03 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:03 INFO i.a.i.s.r.AbstractRelationalDbSource(queryTableFullRefresh):35 - {} - Queueing query for table: PROJ_PROJECT
2021-10-29 18:36:04 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):203 - Records read: 1000
2021-10-29 18:36:04 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):203 - Records read: 2000
2021-10-29 18:36:04 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):203 - Records read: 3000
2021-10-29 18:36:05 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):203 - Records read: 4000
2021-10-29 18:36:05 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):203 - Records read: 5000
2021-10-29 18:36:05 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):203 - Records read: 6000
2021-10-29 18:36:05 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):203 - Records read: 7000
2021-10-29 18:36:06 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):203 - Records read: 8000
2021-10-29 18:36:06 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):203 - Records read: 9000
2021-10-29 18:36:06 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:06 INFO i.a.i.s.r.AbstractDbSource(lambda$read$2):121 - {} - Closing database connection pool.
2021-10-29 18:36:06 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:06 INFO i.a.i.s.r.AbstractDbSource(lambda$read$2):123 - {} - Closed database connection pool.
2021-10-29 18:36:06 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:06 INFO i.a.i.b.IntegrationRunner(run):133 - {} - Completed integration: io.airbyte.integrations.base.ssh.SshWrappedSource
2021-10-29 18:36:06 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:06 INFO i.a.i.s.o.OracleSource(main):176 - {} - completed source: class io.airbyte.integrations.source.oracle.OracleSource
2021-10-29 18:36:06 INFO () DefaultReplicationWorker(run):121 - Source thread complete.
2021-10-29 18:36:06 INFO () DefaultReplicationWorker(run):122 - Waiting for destination thread to join.
2021-10-29 18:36:06 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:06 INFO i.a.i.b.FailureTrackingAirbyteMessageConsumer(close):60 - {} - Airbyte message consumer: succeeded.
2021-10-29 18:36:06 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:06 INFO i.a.i.d.b.BufferedStreamConsumer(close):192 - {} - executing on success close procedure.
2021-10-29 18:36:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:30 INFO i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):156 - {} - Finalizing tables in destination started for 1 streams
2021-10-29 18:36:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:30 INFO i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):161 - {} - Finalizing stream airbyte_test_PROJ_PROJECT. schema dbo, tmp table _airbyte_tmp_nha_airbyte_test_PROJ_PROJECT, final table _airbyte_raw_airbyte_test_PROJ_PROJECT
2021-10-29 18:36:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:30 INFO i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):174 - {} - Executing finalization of tables.
2021-10-29 18:36:31 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:31 INFO i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):176 - {} - Finalizing tables in destination completed.
2021-10-29 18:36:31 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:31 INFO i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):179 - {} - Cleaning tmp tables in destination started for 1 streams
2021-10-29 18:36:31 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:31 INFO i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):183 - {} - Cleaning tmp table in destination started for stream airbyte_test_PROJ_PROJECT. schema dbo, tmp table name: _airbyte_tmp_nha_airbyte_test_PROJ_PROJECT
2021-10-29 18:36:31 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:31 INFO i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):188 - {} - Cleaning tmp tables in destination completed.
2021-10-29 18:36:31 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:31 INFO i.a.i.b.IntegrationRunner(run):133 - {} - Completed integration: io.airbyte.integrations.base.ssh.SshWrappedDestination
2021-10-29 18:36:31 INFO () DefaultAirbyteStreamFactory(lambda$create$0):53 - 2021-10-29 18:36:31 INFO i.a.i.d.m.MSSQLDestination(main):98 - {} - completed destination: class io.airbyte.integrations.destination.mssql.MSSQLDestination
2021-10-29 18:36:31 INFO () DefaultReplicationWorker(run):124 - Destination thread complete.
2021-10-29 18:36:31 INFO () DefaultReplicationWorker(run):152 - sync summary: io.airbyte.config.ReplicationAttemptSummary@73d88bcd[status=completed,recordsSynced=9974,bytesSynced=13120563,startTime=1635532559217,endTime=1635532591855]
2021-10-29 18:36:31 INFO () DefaultReplicationWorker(run):161 - Source did not output any state messages
2021-10-29 18:36:31 WARN () DefaultReplicationWorker(run):172 - State capture: No state retained.
2021-10-29 18:36:31 INFO () TemporalAttemptExecution(get):115 - Stopping cancellation check scheduling...
2021-10-29 18:36:31 INFO () SyncWorkflow$ReplicationActivityImpl(replicate):178 - sync summary: io.airbyte.config.StandardSyncOutput@3c15414c[standardSyncSummary=io.airbyte.config.StandardSyncSummary@224293ae[status=completed,recordsSynced=9974,bytesSynced=13120563,startTime=1635532559217,endTime=1635532591855],state=<null>,outputCatalog=io.airbyte.protocol.models.ConfiguredAirbyteCatalog@2ada887c[streams=[io.airbyte.protocol.models.ConfiguredAirbyteStream@2e52a257[stream=io.airbyte.protocol.models.AirbyteStream@385b99f0[name=airbyte_test_PROJ_PROJECT,jsonSchema={"type":"object","properties":{"ID":{"type":"number"},"BUH":{"type":"number"},"URL":{"type":"string"},"PM_ID":{"type":"number"},"TITLE":{"type":"string"},"AVP_ID":{"type":"number"},"FOAPAL":{"type":"string"},"FYGOAL":{"type":"number"},"VPLIST":{"type":"number"},"TYPE_ID":{"type":"number"},"INCIDENT":{"type":"string"},"SPON_MGR":{"type":"string"},"START_AT":{"type":"string"},"VALUE_ID":{"type":"number"},"EST_HOURS":{"type":"number"},"IS_PUBLIC":{"type":"number"},"ORG_LVL_2":{"type":"string"},"ORG_LVL_3":{"type":"string"},"ORG_LVL_4":{"type":"string"},"ORG_LVL_5":{"type":"string"},"REQ_START":{"type":"string"},"SPON_UNIT":{"type":"string"},"STATUS_ID":{"type":"number"},"TARGET_AT":{"type":"string"},"TENANT_ID":{"type":"number"},"CREATED_AT":{"type":"string"},"CREATED_BY":{"type":"number"},"IS_DELETED":{"type":"number"},"LIAISON_ID":{"type":"number"},"REQ_TARGET":{"type":"string"},"SPONSER_ID":{"type":"number"},"SPON_EMAIL":{"type":"string"},"SPON_PHONE":{"type":"string"},"UPDATED_AT":{"type":"string"},"APPROVED_ID":{"type":"number"},"CATEGORY_ID":{"type":"number"},"CLOSED_DATE":{"type":"string"},"DESCRIPTION":{"type":"string"},"IS_ARCHIVED":{"type":"number"},"IS_BILLABLE":{"type":"number"},"TECHLEAD_ID":{"type":"number"},"ACTUAL_HOURS":{"type":"number"},"EST_DURATION":{"type":"number"},"VP_ATTENTION":{"type":"number"},"APPROVAL_DATE":{"type":"string"},"COMPCENTER_ID":{"type":"number"},"DEPARTMENT_ID":{"type":"number"},"EST_RESOURCES":{"type":"string"},"JUSTIFICATION":{"type":"string"},"SPON_MGR_UNIT":{"type":"string"},"TRAFFIC_LIGHT":{"type":"number"},"ANTICIPATED_ID":{"type":"number"},"BENEFITAREA_ID":{"type":"number"},"DELIVERABLE_ID":{"type":"number"},"FUNDINGTIER_ID":{"type":"number"},"ORIG_EST_HOURS":{"type":"string"},"SETUP_COMPLETE":{"type":"number"},"SPON_MGR_EMAIL":{"type":"string"},"SPON_MGR_PHONE":{"type":"string"},"BUDGET_APPROVED":{"type":"number"},"MULTI_PORTFOLIO":{"type":"number"},"ORG_TITLE_LVL_2":{"type":"string"},"ORG_TITLE_LVL_3":{"type":"string"},"ORG_TITLE_LVL_4":{"type":"string"},"ORG_TITLE_LVL_5":{"type":"string"},"PERCENT_COMPLETE":{"type":"number"},"POP_IMPACTED_AMT":{"type":"number"},"CLASSIFICATION_ID":{"type":"number"},"CREATED_BY_ACTUAL":{"type":"number"}}},supportedSyncModes=[full_refresh, incremental],sourceDefinedCursor=<null>,defaultCursorField=[],sourceDefinedPrimaryKey=[[ID]],namespace=<null>,additionalProperties={}],syncMode=full_refresh,cursorField=[],destinationSyncMode=overwrite,primaryKey=[[ID]],additionalProperties={}]],additionalProperties={}]]
2021-10-29 18:36:31 INFO () TemporalAttemptExecution(get):94 - Executing worker wrapper. Airbyte version: 0.30.23-alpha
2021-10-29 18:36:31 WARN () Databases(createPostgresDatabaseWithRetry):38 - Waiting for database to become available...
2021-10-29 18:36:31 INFO () JobsDatabaseInstance(lambda$static$2):25 - Testing if jobs database is ready...
2021-10-29 18:36:31 INFO () Databases(createPostgresDatabaseWithRetry):55 - Database available!
2021-10-29 18:36:31 INFO () DefaultNormalizationWorker(run):46 - Running normalization.
2021-10-29 18:36:31 INFO () DefaultNormalizationRunner(runProcess):108 - Running with normalization version: airbyte/normalization-mssql:0.1.56
2021-10-29 18:36:31 INFO () LineGobbler(voidCall):65 - Checking if airbyte/normalization-mssql:0.1.56 exists...
2021-10-29 18:36:31 INFO () LineGobbler(voidCall):65 - airbyte/normalization-mssql:0.1.56 was found locally.
2021-10-29 18:36:31 INFO () DockerProcessFactory(create):127 - Preparing command: docker run --rm --init -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/10/0/normalize --network host --log-driver none airbyte/normalization-mssql:0.1.56 run --integration-type mssql --config destination_config.json --catalog destination_catalog.json
2021-10-29 18:36:32 INFO () LineGobbler(voidCall):65 - Running: transform-config --config destination_config.json --integration-type mssql --out /data/10/0/normalize
2021-10-29 18:36:32 INFO () LineGobbler(voidCall):65 - Namespace(config='destination_config.json', integration_type=<DestinationType.mssql: 'mssql'>, out='/data/10/0/normalize')
2021-10-29 18:36:32 INFO () LineGobbler(voidCall):65 - transform_mssql
2021-10-29 18:36:32 INFO () LineGobbler(voidCall):65 - Running: transform-catalog --integration-type mssql --profile-config-dir /data/10/0/normalize --catalog destination_catalog.json --out /data/10/0/normalize/models/generated/ --json-column _airbyte_data
2021-10-29 18:36:32 INFO () LineGobbler(voidCall):65 - Processing destination_catalog.json...
2021-10-29 18:36:32 INFO () LineGobbler(voidCall):65 -   Generating airbyte_ctes/dbo/airbyte_test_proj_project_ab1.sql from airbyte_test_PROJ_PROJECT
2021-10-29 18:36:32 INFO () LineGobbler(voidCall):65 -   Generating airbyte_ctes/dbo/airbyte_test_proj_project_ab2.sql from airbyte_test_PROJ_PROJECT
2021-10-29 18:36:32 INFO () LineGobbler(voidCall):65 -   Generating airbyte_ctes/dbo/airbyte_test_proj_project_ab3.sql from airbyte_test_PROJ_PROJECT
2021-10-29 18:36:32 INFO () LineGobbler(voidCall):65 -   Generating airbyte_tables/dbo/airbyte_test_proj_project.sql from airbyte_test_PROJ_PROJECT
2021-10-29 18:36:32 INFO () LineGobbler(voidCall):65 - detected no config file for ssh, assuming ssh is off.
2021-10-29 18:36:33 INFO () LineGobbler(voidCall):65 - Running with dbt=0.19.0
2021-10-29 18:36:35 INFO () LineGobbler(voidCall):65 - [WARNING]: Configuration paths exist in your dbt_project.yml file which do not apply to any resources.
2021-10-29 18:36:35 INFO () LineGobbler(voidCall):65 - There are 1 unused configuration paths:
2021-10-29 18:36:35 INFO () LineGobbler(voidCall):65 - - models.airbyte_utils.generated.airbyte_views
2021-10-29 18:36:35 INFO () LineGobbler(voidCall):65 - 
2021-10-29 18:36:35 INFO () LineGobbler(voidCall):65 - Found 4 models, 0 tests, 0 snapshots, 0 analyses, 440 macros, 0 operations, 0 seed files, 1 source, 0 exposures
2021-10-29 18:36:35 INFO () LineGobbler(voidCall):65 - 
2021-10-29 18:36:35 INFO () LineGobbler(voidCall):65 - ERROR: Database Error
2021-10-29 18:36:35 INFO () LineGobbler(voidCall):65 -   ('08001', '[08001] [Microsoft][ODBC Driver 17 for SQL Server]TCP Provider: Error code 0x2746 (10054) (SQLDriverConnect)')
2021-10-29 18:36:36 INFO () TemporalAttemptExecution(lambda$getWorkerThread$1):148 - Completing future exceptionally...
io.airbyte.workers.WorkerException: Normalization Failed.
    at io.airbyte.workers.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:60) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
    at io.airbyte.workers.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:18) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
    at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$1(TemporalAttemptExecution.java:145) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
    at java.lang.Thread.run(Thread.java:832) [?:?]
Caused by: io.airbyte.workers.WorkerException: Normalization Failed.
    at io.airbyte.workers.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:57) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
    ... 3 more
    Suppressed: io.airbyte.workers.WorkerException: Normalization process wasn't successful
        at io.airbyte.workers.normalization.DefaultNormalizationRunner.close(DefaultNormalizationRunner.java:136) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
        at io.airbyte.workers.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:45) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
        at io.airbyte.workers.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:18) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
        at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$1(TemporalAttemptExecution.java:145) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
        at java.lang.Thread.run(Thread.java:832) [?:?]
2021-10-29 18:36:36 INFO () TemporalAttemptExecution(get):115 - Stopping cancellation check scheduling...
2021-10-29 18:36:36 WARN () POJOActivityTaskHandler$POJOActivityImplementation(execute):243 - Activity failure. ActivityId=b2a76dc4-6d36-37eb-8bdd-2ad7f5545148, activityType=Normalize, attempt=1
java.util.concurrent.ExecutionException: io.airbyte.workers.WorkerException: Normalization Failed.
    at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395) ~[?:?]
    at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2063) ~[?:?]
    at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:113) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
    at io.airbyte.workers.temporal.SyncWorkflow$NormalizationActivityImpl.normalize(SyncWorkflow.java:303) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.lang.reflect.Method.invoke(Method.java:564) ~[?:?]
    at io.temporal.internal.sync.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:277) ~[temporal-sdk-1.0.4.jar:?]
    at io.temporal.internal.sync.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:216) ~[temporal-sdk-1.0.4.jar:?]
    at io.temporal.internal.sync.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:181) ~[temporal-sdk-1.0.4.jar:?]
    at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:192) ~[temporal-sdk-1.0.4.jar:?]
    at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:154) ~[temporal-sdk-1.0.4.jar:?]
    at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:73) ~[temporal-sdk-1.0.4.jar:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) [?:?]
    at java.lang.Thread.run(Thread.java:832) [?:?]
Caused by: io.airbyte.workers.WorkerException: Normalization Failed.
    at io.airbyte.workers.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:60) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
    at io.airbyte.workers.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:18) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
    at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$1(TemporalAttemptExecution.java:145) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
    ... 1 more
Caused by: io.airbyte.workers.WorkerException: Normalization Failed.
    at io.airbyte.workers.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:57) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
    at io.airbyte.workers.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:18) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
    at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$1(TemporalAttemptExecution.java:145) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
    ... 1 more
    Suppressed: io.airbyte.workers.WorkerException: Normalization process wasn't successful
        at io.airbyte.workers.normalization.DefaultNormalizationRunner.close(DefaultNormalizationRunner.java:136) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
        at io.airbyte.workers.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:45) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
        at io.airbyte.workers.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:18) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
        at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$1(TemporalAttemptExecution.java:145) ~[io.airbyte-airbyte-workers-0.30.23-alpha.jar:?]
        at java.lang.Thread.run(Thread.java:832) [?:?]
brywhi commented 2 years ago

I am also seeing this behavior.

marcosmarxm commented 2 years ago

@walkabout21 could you try with latest version of Airbyte?

marcosmarxm commented 2 years ago

Closed by #11204

walkabout21 commented 2 years ago

@marcosmarxm unfortunately I'm stuck with a flyway version issue that is preventing the docker image from building. Until I can resolve that I can't retry.

022-07-08 14:38:10 ERROR i.a.w.WorkerApp(main):540 - Worker app failed
airbyte-worker      | io.airbyte.db.check.DatabaseCheckException: Timeout while waiting for database to fulfill minimum flyway migration version..
marcosmarxm commented 2 years ago

Did you upgrade to the mandatory 0.32.0-alpha version first? https://docs.airbyte.com/operator-guides/upgrading-airbyte#mandatory-intermediate-upgrade

walkabout21 commented 2 years ago

I'm just running docker-compose from the repo. Something is wrong with the dockerfile in main.

On July 8, 2022 12:16:36 PM EDT, Marcos Marx @.***> wrote:

Did you upgrade to the mandatory 0.32.0-alpha version first? https://docs.airbyte.com/operator-guides/upgrading-airbyte#mandatory-intermediate-upgrade

-- Reply to this email directly or view it on GitHub: https://github.com/airbytehq/airbyte/issues/7536#issuecomment-1179160673 You are receiving this because you were mentioned.

Message ID: @.***>

walkabout21 commented 2 years ago

looks the same as open issue #9502

marcosmarxm commented 2 years ago

@walkabout21 did you check my latest question? You're running a version before the MANDATORY upgrade 0.32.0-alpha. Did you first upgrade to that version of only update to latest one?

walkabout21 commented 2 years ago

@marcosmarxm looks like I had some orphaned configs that were prevent the docker file from building properly. I think that's fixed. Will re-check sql server normalization when I get a chance