DockerOperateur TaskFlow - improve logs

[antoinetavant]

Closes #39319

This PR provide two minor changes :

• Two additional arguments are given to the python command to match the updates of the script interface python3 /tmp/script.py /tmp/script.in /tmp/script.out none /tmp/script.out Indeed, the script used in the DockerOperator in the same as the one in PythonVirtualenvOperator (see airflow/utils/python_virtualenv_script.jinja2 )
• The messages transferred from the docker container to the worker are split line by line to the logger, in order to
  • allow multiline messages such as Trace backs to maintain the indent (useful for PEP-657 )
  • Manage buffered messages that should be individually printed but could be differed
  • Sherry on the cake : filtering on the message level and the file display the totality of the multi-line message (instead of only the first line)

Illustration of the multiline splits

Before :

[2024-05-14T12:51:52.701+0000] {docker.py:436} INFO - + python3 /tmp/script.py /tmp/script.in /tmp/script.out none /tmp/script.out
[2024-05-14T12:51:52.741+0000] {docker.py:436} INFO - Traceback (most recent call last):
  File "/tmp/script.py", line 31, in <module>
    res = fails(*arg_dict["args"], **arg_dict["kwargs"])
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/tmp/script.py", line 17, in fails
    a = 1 / 0
        ~~^~~
ZeroDivisionError: division by zero
[2024-05-14T12:51:52.955+0000] {taskinstance.py:454} INFO - ::group::Post task execution logs

Now

[2024-05-14T12:50:17.655+0000] {docker.py:437} INFO - + python3 /tmp/script.py /tmp/script.in /tmp/script.out none /tmp/script.out
[2024-05-14T12:50:17.693+0000] {docker.py:437} INFO - Traceback (most recent call last):
[2024-05-14T12:50:17.694+0000] {docker.py:437} INFO -   File "/tmp/script.py", line 31, in <module>
[2024-05-14T12:50:17.694+0000] {docker.py:437} INFO -     res = fails(*arg_dict["args"], **arg_dict["kwargs"])
[2024-05-14T12:50:17.694+0000] {docker.py:437} INFO -           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[2024-05-14T12:50:17.695+0000] {docker.py:437} INFO -   File "/tmp/script.py", line 17, in fails
[2024-05-14T12:50:17.695+0000] {docker.py:437} INFO -     a = 1 / 0
[2024-05-14T12:50:17.696+0000] {docker.py:437} INFO -         ~~^~~
[2024-05-14T12:50:17.696+0000] {docker.py:437} INFO - ZeroDivisionError: division by zero
[2024-05-14T12:50:17.876+0000] {taskinstance.py:454} INFO - ::group::Post task execution logs

---

^ Add meaningful description above Read the Pull Request Guidelines for more information. In case of fundamental code changes, an Airflow Improvement Proposal (AIP) is needed. In case of a new dependency, check compliance with the ASF 3rd Party License Policy. In case of backwards incompatible changes please leave a note in a newsfragment file, named {pr_number}.significant.rst or {issue_number}.significant.rst, in newsfragments.

[boring-cyborg[bot]]

Congratulations on your first Pull Request and welcome to the Apache Airflow community! If you have any issues or are unsure about any anything please check our Contributors' Guide (https://github.com/apache/airflow/blob/main/contributing-docs/README.rst) Here are some useful points:

• Pay attention to the quality of your code (ruff, mypy and type annotations). Our pre-commits will help you with that.
• In case of a new feature add useful documentation (in docstrings or in docs/ directory). Adding a new operator? Check this short guide Consider adding an example DAG that shows how users should use it.
• Consider using Breeze environment for testing locally, it's a heavy docker but it ships with a working Airflow and a lot of integrations.
• Be patient and persistent. It might take some time to get a review or get the final approval from Committers.
• Please follow ASF Code of Conduct for all communication including (but not limited to) comments on Pull Requests, Mailing list and Slack.
• Be sure to read the Airflow Coding style.
• Always keep your Pull Requests rebased, otherwise your build might fail due to changes not related to your commits. Apache Airflow is a community-driven project and together we are making it better 🚀. In case of doubts contact the developers at: Mailing List: [email protected] Slack: https://s.apache.org/airflow-slack

[antoinetavant]

-0.9 Your PR makes the log more beautiful in Airflow webserver, but it also makes it harder to process and analyze via log tools (datadog, cloudwatch, ELK...)

Damn ! I did not expect that. I'm not using such tools...

Do you think there is a way to allow both approaches to work ?

I thought of indenting the multi-line messages with white spaces matching the length of the logging prefix, but unfortunately the buffering of the messages make such that it is not possible to differentiate one multiline message (such as a Trace back) or multiple messages that are sent at the same time.

[jscheffl]

-0.9 Your PR makes the log more beautiful in Airflow webserver, but it also makes it harder to process and analyze via log tools (datadog, cloudwatch, ELK...)

I would be a +0.5 for the log adjustments - nt using ELK but bothered with the output especially in conjunction as also reported in #39686 . My proposal is to make it configurable, maybe as a parameter on the operator?

[github-actions[bot]]

This pull request has been automatically marked as stale because it has not had recent activity. It will be closed in 5 days if no further activity occurs. Thank you for your contributions.

[jscheffl]

Oh, just realized by stale notifications that by accident #40489 of me also addressed the problem 2 proposed here, but lost track of the other PR being existing.

I'm not using the decorator (yet) but can imagine the point 1 in the PR is still valid.

[antoinetavant]

Hi @jscheffl , thanks for the notice I think I would have missed it ! I'm glad you fixed this point, I was not confident on the way to address it in a correct way following the different reviews.

I'll remove this part from the PR to only address the first point then !

[antoinetavant]

I've updated the PR by adding a regression test and only addressing the first point, as the second has been addressed.

[jscheffl]

Looks good, but fails in a single regression with Airflow 2.7... can you check this? Then I think.. LGTM!

[antoinetavant]

Looks good, but fails in a single regression with Airflow 2.7... can you check this? Then I think.. LGTM!

Thanks ! I've looking into it, I think I got the issue, but I struggle to test the regression to airflow 2.7 locally with breeze. Could you approve the Test workflow to check if the test passes ?

[potiuk]

There is quite detailed step-by-step guide how to run provider tests with older versions of airflow locally https://github.com/apache/airflow/blob/main/contributing-docs/testing/unit_tests.rst#running-the-compatibility-tests-locally

[potiuk]

In short breeze shell --use-airflow-version 2.7.3 --mount-sources providers-and-tests and then you can run pytest your_tests to run the tests.

[antoinetavant]

Thanks a lot @potiuk ! I misted it in the docs ! It really works like a breeze ! @jscheffl I can confirm that the regression with airflow==2.7.3 is fixed !

[boring-cyborg[bot]]

Awesome work, congrats on your first merged pull request! You are invited to check our Issue Tracker for additional contributions.

[potiuk]

I renamed the commit slighlty - to reflect that it's only #1 from the original PR.