Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Use LOG4J2 to wrap connectors logs to JSON format #15668

Merged
merged 22 commits into from
Sep 14, 2022

Conversation

yurii-bidiuk
Copy link
Contributor

What

Fixes airbytehq/airbyte-internal-issues#19

How

Use LOG4J2 and JsonTemplateLayout to wrap connectors logs in JSON format like AirbyteLogMessage

Recommended reading order

  1. x.java
  2. y.python

🚨 User Impact 🚨

Are there any breaking changes? What is the end result perceived by the user? If yes, please merge this PR with the 🚨🚨 emoji so changelog authors can further highlight this if needed.

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
  • 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
    • Connector's README.md
    • Connector's bootstrap.md. See description and examples
    • docs/integrations/<source or destination>/<name>.md including changelog. See changelog example
    • docs/integrations/README.md
    • airbyte-integrations/builds.md
  • 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.

  • 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
Updating a connector

Community member or Airbyter

  • Grant edit access to maintainers (instructions)
  • Secrets in the connector's spec are annotated with airbyte_secret
  • 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
    • Connector's README.md
    • Connector's bootstrap.md. See description and examples
    • Changelog updated in docs/integrations/<source or destination>/<name>.md including changelog. See changelog example
  • 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.

  • 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 and connector version bumped by running the /publish command described here
Connector Generator
  • Issue acceptance criteria met
  • 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

Put your unit tests output here.

Integration

Put your integration tests output here.

Acceptance

Put your acceptance tests output here.

@yurii-bidiuk yurii-bidiuk requested a review from a team as a code owner August 15, 2022 18:51
@yurii-bidiuk
Copy link
Contributor Author

yurii-bidiuk commented Aug 15, 2022

/test connector=connectors/source-postgres

🕑 connectors/source-postgres https://github.com/airbytehq/airbyte/actions/runs/2862778188
❌ connectors/source-postgres https://github.com/airbytehq/airbyte/actions/runs/2862778188
🐛 https://gradle.com/s/dwtw7nnscy5us

Build Failed

Test summary info:

Could not find result summary

@yurii-bidiuk
Copy link
Contributor Author

yurii-bidiuk commented Aug 15, 2022

With these changes, all connectors logs look like this:

{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable WORKER_ENVIRONMENT: 'DOCKER'"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable JOB_MAIN_CONTAINER_CPU_REQUEST: 'null'"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable JOB_MAIN_CONTAINER_CPU_LIMIT: 'null'"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable JOB_MAIN_CONTAINER_MEMORY_REQUEST: 'null'"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable JOB_MAIN_CONTAINER_MEMORY_LIMIT: 'null'"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable JOB_KUBE_TOLERATIONS: ''"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable JOB_KUBE_NODE_SELECTORS: ''"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable JOB_KUBE_ANNOTATIONS: ''"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable JOB_KUBE_MAIN_CONTAINER_IMAGE_PULL_SECRET: ''"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable JOB_KUBE_MAIN_CONTAINER_IMAGE_PULL_POLICY: 'IfNotPresent'"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable JOB_KUBE_SIDECAR_CONTAINER_IMAGE_PULL_POLICY: 'IfNotPresent'"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable JOB_KUBE_SOCAT_IMAGE: 'alpine/socat:1.7.4.3-r0'"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable JOB_KUBE_BUSYBOX_IMAGE: 'busybox:1.28'"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable JOB_KUBE_CURL_IMAGE: 'curlimages/curl:7.83.1'"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable WORKER_ENVIRONMENT: 'DOCKER'"}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable DEPLOYMENT_MODE: 'OSS'"}}
{"type":"LOG","log":{"level":"INFO","message":"Creating container for image: postgres:13-alpine"}}
{"type":"LOG","log":{"level":"INFO","message":"Container postgres:13-alpine is starting: 58a660cf9ec646caed3d5bb360dd6f9c70b1cd99ccf49c81c324d8648298e403"}}
{"type":"LOG","log":{"level":"INFO","message":"Container postgres:13-alpine started in PT1.344788305S"}}
{"type":"LOG","log":{"level":"INFO","message":"HikariPool-5 - Starting..."}}
{"type":"LOG","log":{"level":"INFO","message":"HikariPool-5 - Start completed."}}
{"type":"LOG","log":{"level":"INFO","message":"Using default value for environment variable USE_STREAM_CAPABLE_STATE: 'false'"}}
{"type":"LOG","log":{"level":"INFO","message":"Checking if airbyte/source-postgres:dev exists..."}}
{"type":"LOG","log":{"level":"INFO","message":"airbyte/source-postgres:dev was found locally."}}
{"type":"LOG","log":{"level":"INFO","message":"Creating docker job ID: 0"}}
{"type":"LOG","log":{"level":"INFO","message":"Preparing command: docker run --rm --init -i -w /data/job --log-driver none --name source-postgres-spec-0-0-torcr --network host -v /tmp/airbyte_tests/test7593383916175201673:/data -v /tmp/airbyte_tests/output846556706032332208:/local -e DEPLOYMENT_MODE=OSS -e USE_STREAM_CAPABLE_STATE=false -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e WORKER_CONNECTOR_IMAGE=airbyte/source-postgres:dev -e WORKER_JOB_ATTEMPT=0 -e AIRBYTE_VERSION= -e WORKER_JOB_ID=0 airbyte/source-postgres:dev spec"}}
{"type":"LOG","log":{"level":"INFO","message":"Running source under deployment mode: OSS"}}
{"type":"LOG","log":{"level":"INFO","message":"Starting source: io.airbyte.integrations.base.ssh.SshWrappedSource"}}
{"type":"LOG","log":{"level":"INFO","message":"integration args: {spec=null}"}}
{"type":"LOG","log":{"level":"INFO","message":"Running integration: io.airbyte.integrations.base.ssh.SshWrappedSource"}}
{"type":"LOG","log":{"level":"INFO","message":"Command: SPEC"}}
{"type":"LOG","log":{"level":"INFO","message":"Integration config: IntegrationConfig{command=SPEC, configPath='null', catalogPath='null', statePath='null'}"}}
{"type":"LOG","log":{"level":"INFO","message":"Completed integration: io.airbyte.integrations.base.ssh.SshWrappedSource"}}
{"type":"LOG","log":{"level":"INFO","message":"Completed source: io.airbyte.integrations.base.ssh.SshWrappedSource"}}


We can configure this structure using AirbyteLogMessageTemplate.json.

@yurii-bidiuk
Copy link
Contributor Author

yurii-bidiuk commented Aug 16, 2022

/test connector=connectors/source-mysql

🕑 connectors/source-mysql https://github.com/airbytehq/airbyte/actions/runs/2866705735
✅ connectors/source-mysql https://github.com/airbytehq/airbyte/actions/runs/2866705735
No Python unittests run

Build Passed

Test summary info:

All Passed

@yurii-bidiuk
Copy link
Contributor Author

yurii-bidiuk commented Aug 16, 2022

/test connector=connectors/source-postgres

🕑 connectors/source-postgres https://github.com/airbytehq/airbyte/actions/runs/2867414898
✅ connectors/source-postgres https://github.com/airbytehq/airbyte/actions/runs/2867414898
No Python unittests run

Build Passed

Test summary info:

All Passed

@yurii-bidiuk
Copy link
Contributor Author

yurii-bidiuk commented Aug 16, 2022

/test connector=connectors/source-postgres

🕑 connectors/source-postgres https://github.com/airbytehq/airbyte/actions/runs/2868700148
✅ connectors/source-postgres https://github.com/airbytehq/airbyte/actions/runs/2868700148
No Python unittests run

Build Passed

Test summary info:

All Passed

@edgao
Copy link
Contributor

edgao commented Aug 19, 2022

@yurii-bidiuk could you show an example of what an exception stacktrace looks like? (i.e. if the connector has a throw new RuntimeException("whatever"), does that also get wrapped correctly?)

And is https://github.com/airbytehq/airbyte-internal-issues/issues/19 an example of how the logs show up in the UI? (if yes: that looks correct to me - airbyte technically expects connectors to only output JSON, so the current behavior is actually violating the airbyte protocol)

@github-actions github-actions bot removed the area/connectors Connector related issues label Aug 19, 2022
@yurii-bidiuk
Copy link
Contributor Author

@edgao
I produced an exception (throw new RuntimeException("some error");) in connector and stack trace is not wrapped in JSON. JSON log contains only high-level error message.
{"type":"LOG","log":{"level":"ERROR","message":"Something went wrong in the connector. See the logs for more details."}}
Also, there is no original connector stack trace with a message. Instead, we get a stack trace from worker

2022-08-22 09:48:28 �[1;31mERROR�[m i.a.w.g.DefaultReplicationWorker(run):184 - Sync worker failed.
java.util.concurrent.ExecutionException: io.airbyte.workers.general.DefaultReplicationWorker$SourceException: Source cannot be stopped!
	at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[?:?]
	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073) ~[?:?]
	at io.airbyte.workers.general.DefaultReplicationWorker.run(DefaultReplicationWorker.java:177) ~[io.airbyte-airbyte-workers-0.40.0-alpha.jar:?]
	at io.airbyte.workers.general.DefaultReplicationWorker.run(DefaultReplicationWorker.java:65) ~[io.airbyte-airbyte-workers-0.40.0-alpha.jar:?]
	at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:155) ~[io.airbyte-airbyte-workers-0.40.0-alpha.jar:?]
	at java.lang.Thread.run(Thread.java:1589) [?:?]
	Suppressed: io.airbyte.workers.exception.WorkerException: Source process exit with code 1. This warning is normal if the job was cancelled.
		at io.airbyte.workers.internal.DefaultAirbyteSource.close(DefaultAirbyteSource.java:136) ~[io.airbyte-airbyte-workers-0.40.0-alpha.jar:?]
		at io.airbyte.workers.general.DefaultReplicationWorker.run(DefaultReplicationWorker.java:141) ~[io.airbyte-airbyte-workers-0.40.0-alpha.jar:?]
		at io.airbyte.workers.general.DefaultReplicationWorker.run(DefaultReplicationWorker.java:65) ~[io.airbyte-airbyte-workers-0.40.0-alpha.jar:?]
		at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:155) ~[io.airbyte-airbyte-workers-0.40.0-alpha.jar:?]
		at java.lang.Thread.run(Thread.java:1589) [?:?]
Caused by: io.airbyte.workers.general.DefaultReplicationWorker$SourceException: Source cannot be stopped!
	at io.airbyte.workers.general.DefaultReplicationWorker.lambda$getReplicationRunnable$6(DefaultReplicationWorker.java:340) ~[io.airbyte-airbyte-workers-0.40.0-alpha.jar:?]
	at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
	... 1 more
Caused by: io.airbyte.workers.exception.WorkerException: Source process exit with code 1. This warning is normal if the job was cancelled.
	at io.airbyte.workers.internal.DefaultAirbyteSource.close(DefaultAirbyteSource.java:136) ~[io.airbyte-airbyte-workers-0.40.0-alpha.jar:?]
	at io.airbyte.workers.general.DefaultReplicationWorker.lambda$getReplicationRunnable$6(DefaultReplicationWorker.java:338) ~[io.airbyte-airbyte-workers-0.40.0-alpha.jar:?]
	at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]

The original stack trace with a message is present in the sync summary log.

@edgao
Copy link
Contributor

edgao commented Aug 22, 2022

Does the original stacktrace never get logged? That seems problematic. Losing the original stacktrace will make debugging connector crashes a lot more difficult.

https://logging.apache.org/log4j/2.x/manual/json-template-layout.html says there are ways to add the exception stacktrace (the error.stack_trace entry), I think adding that would be really valuable. (not sure how to tell log4j to combine two different resolvers in a single entry though)

@yurii-bidiuk
Copy link
Contributor Author

yurii-bidiuk commented Aug 22, 2022

@edgao the original stack trace is logged only inside sync summary log.

https://logging.apache.org/log4j/2.x/manual/json-template-layout.html says there are ways to add the exception stacktrace

You're right and I've already tried this config, but it's not working for Airbyte and stack trace is ignored.
Also I didn't find a way how to combine two different resolvers. A possible way is to write custom resolver, something like RandomNumberResolver from https://logging.apache.org/log4j/2.x/manual/json-template-layout.html

@edgao
Copy link
Contributor

edgao commented Aug 23, 2022

I'd pretty strongly prefer to have the exception stacktrace logged immediately, rather than captured inside the sync summary log. Otherwise it could hide important information (e.g. timestamp).

@github-actions
Copy link
Contributor

NOTE ⚠️ Changes in this PR affect the following connectors. Make sure to run corresponding integration tests:

  • destination-oracle
  • source-db2
  • source-snowflake
  • source-db2-strict-encrypt
  • source-relational-db
  • destination-rockset
  • destination-oracle-strict-encrypt
  • source-mongodb-v2
  • destination-mysql
  • source-clickhouse-strict-encrypt
  • source-cockroachdb-strict-encrypt
  • destination-postgres-strict-encrypt
  • destination-keen
  • destination-mysql-strict-encrypt
  • destination-local-json
  • destination-redshift
  • destination-mongodb-strict-encrypt
  • source-e2e-test
  • destination-mongodb
  • destination-e2e-test
  • source-jdbc
  • source-oracle-strict-encrypt
  • source-scaffold-java-jdbc
  • destination-meilisearch
  • destination-elasticsearch
  • source-mysql
  • source-sftp
  • destination-bigquery
  • destination-mssql-strict-encrypt
  • destination-pubsub
  • source-clickhouse
  • destination-mqtt
  • source-postgres-strict-encrypt
  • source-kafka
  • destination-kafka
  • source-bigquery
  • destination-jdbc
  • destination-bigquery-denormalized
  • destination-databricks
  • destination-clickhouse
  • destination-pulsar
  • source-oracle
  • destination-snowflake
  • destination-dev-null
  • destination-cassandra
  • source-cockroachdb
  • source-mysql-strict-encrypt
  • source-elasticsearch
  • destination-redis
  • destination-kinesis
  • destination-postgres
  • destination-scylla
  • source-e2e-test-cloud
  • destination-dynamodb
  • source-postgres
  • destination-gcs
  • destination-mssql
  • source-mssql
  • destination-s3
  • destination-clickhouse-strict-encrypt
  • source-mssql-strict-encrypt
  • destination-mariadb-columnstore
  • source-mongodb-strict-encrypt
  • destination-csv
  • destination-azure-blob-storage
  • source-redshift
  • source-tidb

@github-actions
Copy link
Contributor

NOTE ⚠️ Changes in this PR affect the following connectors. Make sure to run corresponding integration tests:

  • destination-mssql-strict-encrypt
  • destination-clickhouse
  • destination-scylla
  • source-postgres
  • source-db2-strict-encrypt
  • destination-local-json
  • destination-bigquery-denormalized
  • source-e2e-test
  • source-elasticsearch
  • destination-snowflake
  • destination-pubsub
  • destination-mariadb-columnstore
  • source-snowflake
  • destination-mongodb
  • source-oracle
  • source-db2
  • destination-dynamodb
  • destination-cassandra
  • source-bigquery
  • destination-pulsar
  • destination-mysql
  • source-postgres-strict-encrypt
  • source-sftp
  • source-e2e-test-cloud
  • destination-meilisearch
  • source-mssql-strict-encrypt
  • destination-mongodb-strict-encrypt
  • source-kafka
  • source-oracle-strict-encrypt
  • destination-kinesis
  • destination-redis
  • source-redshift
  • destination-azure-blob-storage
  • destination-elasticsearch
  • destination-mssql
  • destination-postgres
  • source-tidb
  • source-cockroachdb
  • destination-s3
  • source-clickhouse-strict-encrypt
  • source-cockroachdb-strict-encrypt
  • destination-dev-null
  • destination-csv
  • destination-kafka
  • destination-gcs
  • destination-clickhouse-strict-encrypt
  • source-scaffold-java-jdbc
  • destination-rockset
  • source-mysql
  • destination-bigquery
  • destination-postgres-strict-encrypt
  • destination-oracle-strict-encrypt
  • source-mongodb-strict-encrypt
  • destination-oracle
  • source-mysql-strict-encrypt
  • destination-redshift
  • source-mssql
  • destination-e2e-test
  • destination-jdbc
  • destination-keen
  • destination-mysql-strict-encrypt
  • source-mongodb-v2
  • destination-databricks
  • destination-mqtt
  • source-jdbc
  • source-clickhouse
  • source-relational-db

@yurii-bidiuk
Copy link
Contributor Author

@edgao for some reason stack trace wasn't logged inside AirbyteExceptionHandler. So I manually added a logging stack trace as part of message and now we can see the original connector stack trace as part of the JSON log.
From the UI it has the following look:
Screenshot from 2022-08-26 16-44-21
And produced connector's log:

{"type":"LOG","log":{"level":"INFO","message":"HikariPool-1 - Shutdown initiated..."}}
{"type":"LOG","log":{"level":"INFO","message":"HikariPool-1 - Shutdown completed."}}
{"type":"LOG","log":{"level":"ERROR","message":"Exception occurred while getting the delegate read iterator, closing SSH tunnel"}}
{"type":"LOG","log":{"level":"ERROR","message":"Something went wrong in the connector. See the logs for more details.java.lang.IllegalStateException: Unexpected state blob, the state contains either multiple global or conflicting state type.\n\tat io.airbyte.config.helpers.StateMessageHelper.getTypedState(StateMessageHelper.java:72)\n\tat io.airbyte.integrations.source.relationaldb.AbstractDbSource.deserializeInitialState(AbstractDbSource.java:540)\n\tat io.airbyte.integrations.source.relationaldb.AbstractDbSource.read(AbstractDbSource.java:118)\n\tat io.airbyte.integrations.source.postgres.PostgresSource.read(PostgresSource.java:287)\n\tat io.airbyte.integrations.base.ssh.SshWrappedSource.read(SshWrappedSource.java:54)\n\tat io.airbyte.integrations.base.IntegrationRunner.runInternal(IntegrationRunner.java:136)\n\tat io.airbyte.integrations.base.IntegrationRunner.run(IntegrationRunner.java:97)\n\tat io.airbyte.integrations.base.adaptive.AdaptiveSourceRunner$Runner.run(AdaptiveSourceRunner.java:86)\n\tat io.airbyte.integrations.source.postgres.PostgresSourceRunner.main(PostgresSourceRunner.java:15)\n"}}

Can we move on with this?

@edgao
Copy link
Contributor

edgao commented Aug 27, 2022

does this mean that anywhere else we use the LOGGER.log("message", e) call, it needs to be replaced by the ExceptionUtils.getStackTrace style? (that doesn't sound ideal)

also @yurii-bidiuk @grishick feel free to tell me I'm being too nitpicky here :P

I wonder if we should just have a "stacktrace" field at the protocol level. Could be useful as a way to distinguish between technical vs non-technical error message?

@grishick
Copy link
Contributor

grishick commented Aug 27, 2022

does this mean that anywhere else we use the LOGGER.log("message", e) call, it needs to be replaced by the ExceptionUtils.getStackTrace style? (that doesn't sound ideal)

This does not sound good.

I wonder if we should just have a "stacktrace" field at the protocol level. Could be useful as a way to distinguish between technical vs non-technical error message?

This seems like a good idea tagging @airbytehq/protocol-reviewers to chime in

@evantahler
Copy link
Contributor

AirbyteTraceMessage already has these properties: stacktrace, failure-type, internal and external message. It might be the case that all exceptions should be AirbyteTraceMessage rather than AirbyteLogMessage?

It is probably right to say that we shouldn't be "plain" logging exceptions anywhere, and that we should have some sort of formatting utility class. In that utility, we can decide (in a single method) if we AirbyteTraceMessage or AirbyteLogMessage, or both.

@edgao
Copy link
Contributor

edgao commented Aug 27, 2022

aren't trace messages more "this is why the sync failed"? I think there's cases where we catch an exception but don't fail and still want to log it (e.g. LOGGER.warn("Caught xyz transient exception, retrying", e))

we shouldn't be "plain" logging exceptions anywhere

what do you mean by this? Like require that instead of using a log4j Logger, connector devs need to use some wrapper around it?

@evantahler
Copy link
Contributor

Ah! We are talking about non-fatal exceptions (because we catch them and retry).

I had initially assumed that exceptions were always fatal, and if that's the case, then we should be using AirbyteTraceMessage. If there are non-fatal exceptions, you can still send multiple AirbyteTraceMessage - if there are multiple AirbyteTraceMessage, it's safe to send multiple - the platform will use only the latest AirbyteTraceMessage as the main FailureReason. I guess the question is if the connector wants to "elevate" the information from those retryable exceptions to the platform or not.

Like require that instead of using a log4j Logger, connector devs need to use some wrapper around it?

Yep. I would suggest that there's a helper like:

const e = new Error("oh no");
airbyte.utils.logException(e); // yes, a new custom method

//

function logError(Exception e, Boolean toSendTraceMessage = true) {
  LOGGER.log("error", ExceptionUtils.getStackTrace(e));
  if (toSendTraceMessage) { emitAirbyteTraceMessage(e) } 
}

CC @alovew

@edgao
Copy link
Contributor

edgao commented Aug 29, 2022

This PR addresses both fatal and non-fatal exceptions, I'm just thinking through consequences for both cases. The fatal case is probably simple, since we can add a top-level try-catch to wrap it inside whatever we want. The non-fatal case is more interesting, because it requires code change everywhere non-fatal exceptions happen.

My concern with adding a new method is that we can't really enforce that it's used everywhere. E.g. the official BigQuery SDK (used in destination-bigquery) has an internal exception retry handler, which we have no (reasonable) way of modifying to use the airbyte exception logger util. In that case we basically must rely on log4j logs working properly.

(and yes, in that example, either we eventually succeed and therefore don't care about the retries, or it fails and throws a real exception. But I think there are cases where we want to see the exception log without it actually being fatal)

@github-actions
Copy link
Contributor

NOTE ⚠️ Changes in this PR affect the following connectors. Make sure to run corresponding integration tests:

  • destination-pubsub
  • destination-mysql
  • source-mongodb-v2
  • source-db2-strict-encrypt
  • destination-jdbc
  • destination-bigquery
  • source-e2e-test-cloud
  • source-cockroachdb
  • source-mysql
  • destination-snowflake
  • destination-cassandra
  • source-snowflake
  • source-bigquery
  • destination-kafka
  • source-alloydb
  • destination-tidb
  • destination-local-json
  • destination-kinesis
  • destination-redis
  • destination-gcs
  • source-relational-db
  • destination-dev-null
  • destination-clickhouse-strict-encrypt
  • source-oracle
  • source-postgres
  • destination-oracle
  • source-mssql-strict-encrypt
  • source-mongodb-strict-encrypt
  • destination-bigquery-denormalized
  • destination-clickhouse
  • source-kafka
  • source-clickhouse
  • destination-mysql-strict-encrypt
  • destination-databricks
  • destination-rockset
  • source-redshift
  • destination-mssql-strict-encrypt
  • source-sftp
  • destination-mongodb
  • destination-postgres-strict-encrypt
  • destination-e2e-test
  • destination-s3
  • source-e2e-test
  • source-mssql
  • destination-postgres
  • destination-scylla
  • source-scaffold-java-jdbc
  • source-postgres-strict-encrypt
  • destination-meilisearch
  • destination-mongodb-strict-encrypt
  • destination-mssql
  • source-oracle-strict-encrypt
  • destination-elasticsearch
  • destination-mqtt
  • source-jdbc
  • source-tidb
  • destination-keen
  • destination-dynamodb
  • destination-oracle-strict-encrypt
  • destination-mariadb-columnstore
  • source-db2
  • destination-redshift
  • source-mysql-strict-encrypt
  • source-cockroachdb-strict-encrypt
  • destination-csv
  • source-clickhouse-strict-encrypt
  • source-elasticsearch
  • destination-azure-blob-storage
  • destination-pulsar

@octavia-squidington-iii octavia-squidington-iii temporarily deployed to more-secrets September 14, 2022 13:03 Inactive
@github-actions
Copy link
Contributor

NOTE ⚠️ Changes in this PR affect the following connectors. Make sure to run corresponding integration tests:

  • destination-bigquery-denormalized
  • source-relational-db
  • source-e2e-test
  • destination-mysql
  • destination-dynamodb
  • source-oracle-strict-encrypt
  • destination-local-json
  • source-alloydb
  • source-clickhouse-strict-encrypt
  • source-bigquery
  • source-elasticsearch
  • source-sftp
  • destination-elasticsearch
  • destination-clickhouse
  • source-scaffold-java-jdbc
  • destination-rockset
  • destination-kafka
  • destination-clickhouse-strict-encrypt
  • destination-meilisearch
  • source-mysql
  • destination-mongodb
  • destination-csv
  • source-jdbc
  • source-redshift
  • destination-oracle
  • source-mongodb-v2
  • source-cockroachdb
  • destination-redshift
  • destination-postgres
  • source-e2e-test-cloud
  • source-cockroachdb-strict-encrypt
  • destination-mariadb-columnstore
  • source-tidb
  • destination-tidb
  • destination-pubsub
  • destination-keen
  • source-oracle
  • destination-scylla
  • destination-azure-blob-storage
  • destination-mssql
  • destination-mqtt
  • source-db2-strict-encrypt
  • source-postgres
  • destination-bigquery
  • source-snowflake
  • source-mssql-strict-encrypt
  • source-mysql-strict-encrypt
  • destination-gcs
  • destination-dev-null
  • destination-databricks
  • source-clickhouse
  • destination-postgres-strict-encrypt
  • destination-mysql-strict-encrypt
  • destination-cassandra
  • source-mongodb-strict-encrypt
  • source-db2
  • destination-mongodb-strict-encrypt
  • destination-redis
  • source-postgres-strict-encrypt
  • source-mssql
  • destination-s3
  • destination-pulsar
  • source-kafka
  • destination-e2e-test
  • destination-oracle-strict-encrypt
  • destination-kinesis
  • destination-mssql-strict-encrypt
  • destination-snowflake
  • destination-jdbc

@octavia-squidington-iii octavia-squidington-iii temporarily deployed to more-secrets September 14, 2022 13:09 Inactive
@github-actions
Copy link
Contributor

NOTE ⚠️ Changes in this PR affect the following connectors. Make sure to run corresponding integration tests:

  • source-sftp
  • destination-keen
  • source-tidb
  • source-oracle
  • destination-clickhouse-strict-encrypt
  • destination-local-json
  • destination-redshift
  • source-mongodb-strict-encrypt
  • destination-dev-null
  • destination-postgres
  • destination-azure-blob-storage
  • destination-tidb
  • source-mssql
  • destination-mqtt
  • source-snowflake
  • destination-pulsar
  • source-db2-strict-encrypt
  • destination-mssql
  • source-elasticsearch
  • source-db2
  • source-relational-db
  • destination-snowflake
  • source-clickhouse-strict-encrypt
  • source-kafka
  • destination-bigquery
  • destination-dynamodb
  • destination-s3
  • destination-mongodb
  • source-bigquery
  • destination-mariadb-columnstore
  • destination-mysql-strict-encrypt
  • destination-databricks
  • destination-meilisearch
  • destination-oracle
  • source-mongodb-v2
  • destination-mongodb-strict-encrypt
  • destination-postgres-strict-encrypt
  • source-jdbc
  • source-mysql
  • destination-clickhouse
  • source-oracle-strict-encrypt
  • destination-kafka
  • destination-gcs
  • destination-jdbc
  • destination-elasticsearch
  • destination-scylla
  • source-scaffold-java-jdbc
  • destination-rockset
  • destination-pubsub
  • destination-mysql
  • source-mysql-strict-encrypt
  • destination-bigquery-denormalized
  • destination-kinesis
  • source-redshift
  • source-e2e-test-cloud
  • source-postgres-strict-encrypt
  • source-e2e-test
  • source-mssql-strict-encrypt
  • destination-e2e-test
  • source-postgres
  • source-cockroachdb-strict-encrypt
  • source-cockroachdb
  • source-clickhouse
  • destination-csv
  • destination-oracle-strict-encrypt
  • destination-cassandra
  • source-alloydb
  • destination-redis
  • destination-mssql-strict-encrypt

@octavia-squidington-iii octavia-squidington-iii temporarily deployed to more-secrets September 14, 2022 13:53 Inactive
@yurii-bidiuk
Copy link
Contributor Author

yurii-bidiuk commented Sep 14, 2022

/publish connector=connectors/destination-mysql

🕑 Publishing the following connectors:
connectors/destination-mysql
https://github.com/airbytehq/airbyte/actions/runs/3053628185


Connector Did it publish? Were definitions generated?
connectors/destination-mysql

if you have connectors that successfully published but failed definition generation, follow step 4 here ▶️

@yurii-bidiuk
Copy link
Contributor Author

yurii-bidiuk commented Sep 14, 2022

/publish connector=connectors/destination-postgres

🕑 Publishing the following connectors:
connectors/destination-postgres
https://github.com/airbytehq/airbyte/actions/runs/3053629486


Connector Did it publish? Were definitions generated?
connectors/destination-postgres

if you have connectors that successfully published but failed definition generation, follow step 4 here ▶️

@yurii-bidiuk
Copy link
Contributor Author

yurii-bidiuk commented Sep 14, 2022

/publish connector=connectors/destination-mssql

🕑 Publishing the following connectors:
connectors/destination-mssql
https://github.com/airbytehq/airbyte/actions/runs/3053631129


Connector Did it publish? Were definitions generated?
connectors/destination-mssql

if you have connectors that successfully published but failed definition generation, follow step 4 here ▶️

@yurii-bidiuk
Copy link
Contributor Author

@grishick @edgao
Some of the connectors didn't publish because of errors (destination-postgres, destination-mssql, destination-mysql).
I suggest merging this PR without them to avoid a collision if someone tries to publish a connector with a published version in his PR.
I will create a separate PR because it can take more time to figure out and fix an issue with publishing.

@github-actions
Copy link
Contributor

NOTE ⚠️ Changes in this PR affect the following connectors. Make sure to run corresponding integration tests:

  • destination-keen
  • destination-bigquery-denormalized
  • source-oracle
  • source-oracle-strict-encrypt
  • source-sftp
  • destination-oracle-strict-encrypt
  • source-snowflake
  • destination-meilisearch
  • destination-databricks
  • source-clickhouse-strict-encrypt
  • source-kafka
  • source-clickhouse
  • source-mysql-strict-encrypt
  • source-mssql
  • source-cockroachdb-strict-encrypt
  • source-jdbc
  • source-db2
  • source-redshift
  • destination-redis
  • destination-snowflake
  • source-bigquery
  • source-mongodb-strict-encrypt
  • source-scaffold-java-jdbc
  • destination-redshift
  • destination-azure-blob-storage
  • destination-clickhouse-strict-encrypt
  • destination-cassandra
  • destination-oracle
  • source-mongodb-v2
  • destination-clickhouse
  • destination-mysql-strict-encrypt
  • destination-rockset
  • destination-dev-null
  • destination-bigquery
  • source-mssql-strict-encrypt
  • destination-kinesis
  • source-e2e-test
  • destination-s3
  • destination-kafka
  • source-postgres
  • destination-mssql
  • destination-mongodb
  • destination-mongodb-strict-encrypt
  • destination-pulsar
  • source-mysql
  • destination-jdbc
  • destination-mssql-strict-encrypt
  • destination-pubsub
  • destination-mqtt
  • source-alloydb
  • source-cockroachdb
  • destination-mariadb-columnstore
  • source-tidb
  • destination-tidb
  • destination-csv
  • destination-postgres
  • destination-e2e-test
  • destination-local-json
  • destination-elasticsearch
  • source-e2e-test-cloud
  • destination-mysql
  • destination-dynamodb
  • source-db2-strict-encrypt
  • destination-scylla
  • source-elasticsearch
  • destination-postgres-strict-encrypt
  • source-relational-db
  • source-postgres-strict-encrypt
  • destination-gcs

@yurii-bidiuk yurii-bidiuk temporarily deployed to more-secrets September 14, 2022 19:15 Inactive
@yurii-bidiuk yurii-bidiuk merged commit 10e4aae into master Sep 14, 2022
@yurii-bidiuk yurii-bidiuk deleted the bidiuk/659-wrap-logs-to-json branch September 14, 2022 20:27
letiescanciano added a commit that referenced this pull request Sep 15, 2022
* master: (200 commits)
  🪟 🧹 Display returned error messages on replication view (#16280)
  🎉 Source mixpanel: Use "Retry-After" header for backoff (#16770)
  🐛 Source google ads: mark custom query fields required (#15858)
  🪟 🔧Remove useRouter hook (#16598)
  CDK: improve TypeTransformer to convert simple types to array of simple types (#16636)
  CDK: TypeTransformer - warning message more informative (#16695)
  Source MySQL: Add Python SAT to detect backwards breaking changes (#16445)
  remove eager (#16756)
  bump com.networknt:json-schema-validator to latest version (#16619)
  Remove Cloud from Kafka docs (#16753)
  Normalization Summaries table and read/write methods (#16655)
  comment out flaky test suite while it is being investigated (#16752)
  Update ConfigRepository to read protocol version (#16670)
  Use LOG4J2 to wrap connectors logs to JSON format (#15668)
  Update connector catalog (#16749)
  🪟 🎨 Remove feedback modal from UI (#16548)
  Add missing env var for Kube overlays (#16747)
  Prepare for React v18 upgrade (#16694)
  🪟 🐛 Fix direct job linking to work with pagination (#16517)
  Fix formatting (#16743)
  ...
robbinhan pushed a commit to robbinhan/airbyte that referenced this pull request Sep 29, 2022
* Use LOG4J2 to wrap connectors logs to JSON format

* log connector's stack trace directly as a message

* add stack_trace field to json template

* bump versions

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* revert versions for destinations: postgres, mssql, mysql

Co-authored-by: Octavia Squidington III <octavia-squidington-iii@users.noreply.github.com>
jhammarstedt pushed a commit to jhammarstedt/airbyte that referenced this pull request Oct 31, 2022
* Use LOG4J2 to wrap connectors logs to JSON format

* log connector's stack trace directly as a message

* add stack_trace field to json template

* bump versions

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* auto-bump connector version [ci skip]

* revert versions for destinations: postgres, mssql, mysql

Co-authored-by: Octavia Squidington III <octavia-squidington-iii@users.noreply.github.com>
prateekmukhedkar added a commit that referenced this pull request Feb 13, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment