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

connectors-ci: improve pytest result evaluation #28767

Conversation

alafanechere
Copy link
Contributor

@alafanechere alafanechere commented Jul 27, 2023

What

Relates to #27425 , #28423

Original problem

When running pytest in a dagger container we face two challenges:

  • When a pytest suite is empty or all tests are skipped pytest will return a 5 exit code. exit code >0 in Dagger raise ExecError, but we want to mark this step as skipped and not fail.
  • When CAT (which is a pytest suite) is failing still need to perform after the facts operations to retrieve updated connector configurations from the container. When a container raises an ExecError we can't interact with it's filesystem without raising the same ExecError again.

How we overcame this problem so far

We installed a pytest plugin to always make pytest suite exit with code 0: pytest-custom_exit_code. We inferred success / failure / skipping of test by parsing the stdout log. This is not robust as the stdout content can change according to the pytest version or if a CAT run outputs unexpected stuff to stdout. This led to the false positive errors mentioned in #27425

The new approach to overcome this problem

We still make CAT exec artificially exit with a 0 exit code, but we store the original exit code to a file in the container filesystem: /exit_code. We get_step_result is run it will check if such a file exist on the container and return the in file exit code value instead of the pure container exit code. This allows us to capture the actual exit code that pytest returned.

How

The new approach mentioned above is mainly introduced via:

I tried to thoroughly unit test these change to show how async test with a dagger client work:

Additional refactor

Centralizing the AcceptanceTest logic

The logic to build the CAT container was in the environment.with_connector_acceptance_test function. I decided to move it to common.AcceptanceTest._build_connector_acceptance_test as environment functions are originally made to be reused in multiple steps. This function is very specific to AcceptanceTest.

Make all step write the stdout / stderr to a log file

(Relates to #28423)
We originally only wrote CAT output logs to a local directory. I figured that this logic can easily apply to all steps and would provide more debugging abilities to developers. Logs are written when the step results are built in get_step_results

await self.write_log_files(stdout, stderr)

Wrap acceptance test into its own dagger Pipeline.

(Relates to #28423)
I created Step specific dagger client in AcceptanceTest in order to showcase how we could make step execution wrapped into a dagger Pipeline: this will make the CAT dagger operations grouped in a explicit way in the dagger UI.

def dagger_client(self) -> Container:

Recommended reading order

  1. class AcceptanceTests(PytestStep):

@octavia-squidington-iii
Copy link
Collaborator

source-pokeapi test report (commit 9ae813c9e4) - ❌

⏲️ Total pipeline duration: 02mn32s

Step Result
Validate airbyte-integrations/connectors/source-pokeapi/metadata.yaml
Connector version semver check
QA checks
Code format checks
Connector package install
Build source-pokeapi docker image for platform linux/x86_64
Unit tests
Acceptance tests

🔗 View the logs here

Please note that tests are only run on PR ready for review. Please set your PR to draft mode to not flood the CI engine and upstream service on following commits.
You can run the same pipeline locally on this branch with the airbyte-ci tool with the following command

airbyte-ci connectors --name=source-pokeapi test

@octavia-squidington-iii
Copy link
Collaborator

source-openweather test report (commit 9ae813c9e4) - ✅

⏲️ Total pipeline duration: 03mn46s

Step Result
Validate airbyte-integrations/connectors/source-openweather/metadata.yaml
Connector version semver check
QA checks
Code format checks
Connector package install
Build source-openweather docker image for platform linux/x86_64
Unit tests
Acceptance tests

🔗 View the logs here

Please note that tests are only run on PR ready for review. Please set your PR to draft mode to not flood the CI engine and upstream service on following commits.
You can run the same pipeline locally on this branch with the airbyte-ci tool with the following command

airbyte-ci connectors --name=source-openweather test

This reverts commit 9ae813c.
Copy link
Contributor

@bnchrch bnchrch left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A few comments but the only one I think is a hard blocker is referencing context.connector in Step

on:
push:
branches:
- !master
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

are our tests now passing for pipelines? Did I miss that PR?!

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sorry, it was a WIP push from a different branch: #28857

@@ -124,19 +106,23 @@ def run_duration(self) -> timedelta:
@property
def logger(self) -> logging.Logger:
if self.should_log:
return self.context.logger
return logging.getLogger(f"{self.context.pipeline_name} - {self.title}")
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍

return []

written_log_files = []
log_directory = Path(f"{self.context.connector.code_directory}/airbyte_ci_logs/{slugify(self.context.pipeline_name)}")
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we use connector here if this is our generic Step class?


written_log_files = []
log_directory = Path(f"{self.context.connector.code_directory}/airbyte_ci_logs/{slugify(self.context.pipeline_name)}")
await log_directory.mkdir(exist_ok=True, parents=True)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Doing all this manual stderr/out handling and log writing makes me nervous.

Particularly now that they write to not just our ci folder but also the connector folder

My worries generally come down to If we keep writing log handling at a low level

  1. We will have to keep repeating our logging code
  2. More importantly we keep repeating if statments like if self.context.is_local and self.should_persist_stdout_stderr_logs: which if missed lead to tricky bugs
  3. And if we go this route for too long, it will be very hard to go back as there will be alot of code to refactor.

This leads me to ask What is stopping us from moving all our log writing/handling to the dagger client boundary here:
https://github.com/airbytehq/airbyte/blob/master/airbyte-ci/connectors/pipelines/pipelines/pipelines/connectors.py#L85

For example a possible solution could be

  1. Write our own logger that extends the typical python logger by adding pipeline specific context
    1. pipeline name
    2. pipeline step
    3. etc.
  2. Write our own subclass of TextIOWrapper that based on the new pipeline context we stuff into the logger
    1. writes a log file per pipeline
    2. writes a log file per step
    3. writes a root log file representing everything
    4. Decides if we are also writing to stdout/stderr
    5. Decides if we need to send these logs anywhere else (e.g. sentry, datadog, cloudwatch etc)

If this is possible and is a good idea.

can we make a small step towards this now by

  1. Moving the decision of whether or not we write to a log file the decision of a custom logger
  2. Moving the writing logic to the logger

e.g. https://stackoverflow.com/questions/6386698/how-to-write-to-a-file-using-the-logging-python-module

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@bnchrch let's keep the logging change for a different PR then.
But just to react on top of your comment:

My worries generally come down to If we keep writing log handling at a low level

This is not low level IMO because it's a change made at the Step class level, so we centralize all the logging logic on the base class.

Write our own logger that extends the typical python logger by adding pipeline specific context

This is what this change did: the step have a specific logger with pipeline and step name.

Write our own subclass of TextIOWrapper that based on the new pipeline context we stuff into the logger

In this context you mean parsing the dagger client logs. Splitting them into different per step/pipeline logs file will be very brittle as we have no control on the shape of the dagger logs, I'd rather ask the dagger team to provide such a feature and IMO it directly overlaps with the log access in the Dagger Web UI.
Moreover, if steps are cached their stdout are not shown in the logs (and replaced with CACHED).

can we make a small step towards this now by
Moving the decision of whether or not we write to a log file the decision of a custom logger
Moving the writing logic to the logger.

Yep you're right that using a combo of logging to stdout + write logic can definitely be handled at the logger level. Let's do it later and groom #28423 a bit more.
I think we should be clearer in differentiating what we mean by Dagger logs, steps logs, pipeline logs stp.

return self.pytest_logs_to_step_result(logs)
return step_result

def get_cache_buster(self) -> str:
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍

"""
return datetime.datetime.utcnow().strftime("%Y%m%d")

async def _build_connector_acceptance_test(self, connector_under_test_image_tar: File) -> Container:
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

well done function.

But Im starting to notice we have a lot of connector code, that isnt obvious based on the file structure.

For example this is in test/common

should we start making it more specific. e.g.:

  • test/connector_acceptance/common.py
  • actions/connectors/tests.py

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The test/common module is originally made to receive connector testing step that are agnostic to the connector language. This is why AcceptanceTest belongs here.
The actions module was originally made to receive re-usable code. But I think I overused it and suffed action/environements with code that is not re-used in multiple context.

Copy link
Contributor

@bnchrch bnchrch left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

lgtm!

@alafanechere alafanechere merged commit 502134f into master Aug 1, 2023
16 checks passed
@alafanechere alafanechere deleted the augustin/connectors-ci/change-pytest-step-result-evaluation branch August 1, 2023 09:29
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants