CDK: emit `AirbyteTraceMessage` with exception trace information #12593

pedroslopez · 2022-05-05T03:18:54Z

What

AirbyteTraceMessage has been introduced in the protocol to allow better debugging and attribution of failures when something in the connector goes wrong.

This change starts emitting AirbyteTraceMessages generically whenever an exception is raised. A future PR will make it easier to return better user-friendly messages.

closes #12472

How

Use sys.excepthook to register a global handler for uncaught exceptions. This handler is in charge of emitting the generic AirbyteTraceMessages.
Introduce an AirbyteTracedException class, which can be used to customize the trace message and provide better error messages.
Refactor the logger's secret filtering logic out into an AirbyteSecretHelper so it can be re-used to filter out secrets from trace messages.

Recommended reading order

utils/traced_exception.py
exception_handler.py
tests

airbyte-cdk/python/airbyte_cdk/sources/utils/transform.py

pedroslopez · 2022-05-05T03:24:45Z

airbyte-cdk/python/airbyte_cdk/utils/airbyte_secrets_utils.py

+class AirbyteSecretHelper:
+    _secrets: List[str] = []
+
+    @classmethod
+    def update_secrets(cls, secrets: List[str]):
+        """Update the list of secrets to be replaced"""
+        cls._secrets = secrets
+
+    @classmethod
+    def filter_secrets(cls, string: str) -> str:
+        """Filter secrets from a string by replacing them with ****"""
+        for secret in cls._secrets:
+            string = string.replace(secret, "****")
+        return string


Moved out the logic from AirbyteLogFormatter so it can be re-used (using this for trace messages now as well)

pedroslopez · 2022-05-05T03:25:11Z

airbyte-cdk/python/airbyte_cdk/utils/traced_exception.py

+            type=TraceType.ERROR,
+            emitted_at=now_millis,
+            error=AirbyteErrorTraceMessage(
+                message=self.message or "an error occurred with the source",


any suggestions on what this generic default message should be are welcome 😄

this isn't necessarily source, could also be destination.

How about Something went wrong in the connector. See the logs for more details. ?
Pointing them at the logs seems sensible given that this is always going to be non-specific at this level.

Are there any environment variables or system arguments we can use to know if we are a source or destination? e.g. looking at the docker container name (source-mailchimp)?

pedroslopez · 2022-05-05T03:28:10Z

airbyte-cdk/python/airbyte_cdk/exception_handler.py

+        # emit an AirbyteTraceMessage for any exception that gets to this spot
+        traced_exc = exception_value if exception_type == AirbyteTracedException else AirbyteTracedException.from_exception(exception_value)
+        message = traced_exc.as_airbyte_message()
+        message_json = message.json(exclude_unset=True)
+        print(AirbyteSecretHelper.filter_secrets(message_json))


This is the main part that is in charge of emitting the AirbyteTraceMessage: If the exception we get is already an AirbyteTracedException (which can be thrown from anywhere with appropriate messages and fields) we use it, if not then we build one from the exception. This is then turned into an AirbyteTraceMessage and filtered for secret values.

Phlair

Awesome! Mostly just comments on being pythonic, one open question around the AirbyteLogger which should be resolved before approve I think.

airbyte-cdk/python/airbyte_cdk/exception_handler.py

airbyte-cdk/python/airbyte_cdk/sources/utils/transform.py

airbyte-cdk/python/airbyte_cdk/utils/airbyte_secrets_utils.py

Phlair · 2022-05-05T11:27:59Z

airbyte-cdk/python/airbyte_cdk/utils/traced_exception.py

+            type=TraceType.ERROR,
+            emitted_at=now_millis,
+            error=AirbyteErrorTraceMessage(
+                message=self.message or "an error occurred with the source",


this isn't necessarily source, could also be destination.

How about Something went wrong in the connector. See the logs for more details. ?
Pointing them at the logs seems sensible given that this is always going to be non-specific at this level.

CLAassistant · 2022-05-05T13:06:55Z

All committers have signed the CLA.

Phlair · 2022-05-05T14:45:21Z

airbyte-cdk/python/airbyte_cdk/utils/traced_exception.py

+        super().__init__(internal_message)
+
+    def as_airbyte_message(self) -> AirbyteMessage:
+        now_millis = int(datetime.now().timestamp() * 1000)


this is a Double in the protocol so should technically be a float here in python, but I'm not sure it would actually matter

Oh interesting - the RecordMessage's emitted_at is an int 🤔 good catch!

changed in 65543d1

evantahler

I defer to other's Pythonic notes, but 👍 from me! The ergonomic suggestion is non-blocking.

evantahler · 2022-05-05T18:47:01Z

airbyte-cdk/python/airbyte_cdk/exception_handler.py

+        message_json = message.json(exclude_unset=True)
+        print(filter_secrets(message_json))
+
+    sys.excepthook = hook_fn


This is cool - like Node's process.on('uncaughtException')

airbyte-cdk/python/airbyte_cdk/exception_handler.py

evantahler · 2022-05-05T18:55:14Z

airbyte-cdk/python/unit_tests/test_exception_handler.py

+    with pytest.raises(subprocess.CalledProcessError) as err:
+        subprocess.check_output([sys.executable, "-c", cmd], stderr=subprocess.STDOUT)


That's a neat way to test that a process crashed!

Phlair

LGTM! Nice one 👍

pedroslopez · 2022-05-06T20:26:28Z

/publish-cdk dry-run=true

🕑 https://github.com/airbytehq/airbyte/actions/runs/2283881883
✅ https://github.com/airbytehq/airbyte/actions/runs/2283881883

this was causing circular dependency issues with later changes

… reuse

pedroslopez · 2022-05-06T21:03:17Z

/publish-cdk dry-run=false

🕑 https://github.com/airbytehq/airbyte/actions/runs/2284023169
✅ https://github.com/airbytehq/airbyte/actions/runs/2284023169

)

github-actions bot added the CDK Connector Development Kit label May 5, 2022

pedroslopez commented May 5, 2022

View reviewed changes

pedroslopez requested a review from Phlair May 5, 2022 03:29

Phlair reviewed May 5, 2022

View reviewed changes

pedroslopez marked this pull request as ready for review May 5, 2022 16:11

pedroslopez requested review from Phlair, sherifnada and evantahler May 5, 2022 16:11

evantahler approved these changes May 5, 2022

View reviewed changes

Phlair approved these changes May 6, 2022

View reviewed changes

pedroslopez added 12 commits May 6, 2022 16:40

remove usages of deprecated AirbyteLogger

9be6113

this was causing circular dependency issues with later changes

extract secret filtering functionality into AirbyteSecretHelper for…

6987b4c

… reuse

emit AirbyteTraceMessage for uncaught exceptions

913d110

remove unused imports

9ba677f

emitted_at is a float

67ac371

use issubclass for exception type comparison

6e206a8

dont use a static class for secret helper

0ab4dbd

add docs for traced exception

c6d77f2

update default user-facing message

10c4f18

check that secrets are filtered from trace messages

d86c524

bump version, update changelog

420c6d9

move print logic to AirbyteTracedException.emit_message()

b00fc78

pedroslopez force-pushed the pedroslopez/cdk-airbytetracemessage branch from 313b445 to b00fc78 Compare May 6, 2022 20:40

pedroslopez merged commit 73c7fad into master May 6, 2022

pedroslopez deleted the pedroslopez/cdk-airbytetracemessage branch May 6, 2022 21:16

pedroslopez mentioned this pull request May 6, 2022

bump GA connectors to latest version of python cdk #12685

Merged

14 tasks

octavia-squidington-iii mentioned this pull request May 9, 2022

Bump Airbyte version from 0.37.0-alpha to 0.37.1-alpha #12703

Merged

suhomud pushed a commit that referenced this pull request May 23, 2022

CDK: emit AirbyteTraceMessage with exception trace information (#12593

aec2bdc

)

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

CDK: emit `AirbyteTraceMessage` with exception trace information #12593

CDK: emit `AirbyteTraceMessage` with exception trace information #12593

pedroslopez commented May 5, 2022 •

edited

Loading

pedroslopez May 5, 2022

pedroslopez May 5, 2022

Phlair May 5, 2022

evantahler May 5, 2022

pedroslopez May 5, 2022

Phlair left a comment

Phlair May 5, 2022

CLAassistant commented May 5, 2022 •

edited

Loading

Phlair May 5, 2022 •

edited

Loading

pedroslopez May 5, 2022 •

edited

Loading

evantahler left a comment

evantahler May 5, 2022

evantahler May 5, 2022

Phlair left a comment •

edited

Loading

pedroslopez commented May 6, 2022 •

edited by github-actions bot

Loading

pedroslopez commented May 6, 2022 •

edited by github-actions bot

Loading

		with pytest.raises(subprocess.CalledProcessError) as err:
		subprocess.check_output([sys.executable, "-c", cmd], stderr=subprocess.STDOUT)

CDK: emit AirbyteTraceMessage with exception trace information #12593

CDK: emit AirbyteTraceMessage with exception trace information #12593

Conversation

pedroslopez commented May 5, 2022 • edited Loading

What

How

Recommended reading order

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Phlair left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

CLAassistant commented May 5, 2022 • edited Loading

Phlair May 5, 2022 • edited Loading

Choose a reason for hiding this comment

pedroslopez May 5, 2022 • edited Loading

Choose a reason for hiding this comment

evantahler left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Phlair left a comment • edited Loading

Choose a reason for hiding this comment

pedroslopez commented May 6, 2022 • edited by github-actions bot Loading

pedroslopez commented May 6, 2022 • edited by github-actions bot Loading

CDK: emit `AirbyteTraceMessage` with exception trace information #12593

CDK: emit `AirbyteTraceMessage` with exception trace information #12593

pedroslopez commented May 5, 2022 •

edited

Loading

CLAassistant commented May 5, 2022 •

edited

Loading

Phlair May 5, 2022 •

edited

Loading

pedroslopez May 5, 2022 •

edited

Loading

Phlair left a comment •

edited

Loading

pedroslopez commented May 6, 2022 •

edited by github-actions bot

Loading

pedroslopez commented May 6, 2022 •

edited by github-actions bot

Loading