Skip to content

Fix returning last log line in docker operator#13793

Closed
davidcaron wants to merge 2 commits into
apache:masterfrom
davidcaron:fix-docker-xcom-push-last-line
Closed

Fix returning last log line in docker operator#13793
davidcaron wants to merge 2 commits into
apache:masterfrom
davidcaron:fix-docker-xcom-push-last-line

Conversation

@davidcaron

Copy link
Copy Markdown
Contributor

Iterable values in cli.attach(..., stream=True) are not necessarily single lines.
Lines can be merged together or split because of buffering.
When this split happens just before the last newline character, the returned value of execute is an empty byte string.

Also, fix the return type annotation (the return type is not changed, only the annotation).

I used these files to recreate the issue:

Dockerfile

FROM python:3.8-slim-buster
WORKDIR /code
ADD main.py .
CMD [ "python", "main.py" ]

main.py

from random import randint

for _ in range(randint(1, 100)):
    print(f"output")

print("last_line")

script.py

from docker import APIClient


cli = APIClient()


def run_image():
    container = cli.create_container(
        command="python main.py",
        host_config=cli.create_host_config(auto_remove=False),
        image="docker-bug",
        tty=True,
    )

    lines = cli.attach(container=container["Id"], stdout=True, stderr=True, stream=True)

    cli.start(container["Id"])

    line = list(lines)[-1]

    cli.wait(container["Id"])

    print("--- LAST LINES ---")
    print(repr(line))
    print(repr(cli.logs(container=container["Id"], tail=1).strip()))

    cli.remove_container(container["Id"])


if __name__ == "__main__":
    for i in range(1000):
        run_image()

When running:

$ docker build -t docker-bug .
$ python script.py

The output will look something like:

--- LAST LINES ---
b'output\r\noutput\r\noutput\r\noutput\r\noutput\r\noutput\r\noutput\r\nlast_line\r\n'
b'last_line'
--- LAST LINES ---
b'output\r\noutput\r\noutput\r\noutput\r\noutput\r\noutput\r\noutput\r\noutput\r\noutput\r\nlast_line\r\n'
b'last_line'
--- LAST LINES ---
b'output\r\noutput\r\nlast_line\r\n'
b'last_line'

Iterable values in `cli.attach(..., stream=True)` are not necessarily
single lines. Lines can be merged together or split
because of buffering.
When this split happens just before the last newline
character, the returned value of `execute` is an empty byte string.
@boring-cyborg

boring-cyborg Bot commented Jan 20, 2021

Copy link
Copy Markdown

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 Contribution Guide (https://github.com/apache/airflow/blob/master/CONTRIBUTING.rst)
Here are some useful points:

  • Pay attention to the quality of your code (flake8, pylint 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.
    Apache Airflow is a community-driven project and together we are making it better 🚀.
    In case of doubts contact the developers at:
    Mailing List: dev@airflow.apache.org
    Slack: https://s.apache.org/airflow-slack

@davidcaron

Copy link
Copy Markdown
Contributor Author

Related, but different issue: #13536 (converts return type to str, but this PR keeps bytes)

I believe execute should return a decoded str... but I kept the current return type, so there should be no breaking change in this PR.

if self.do_xcom_push:
ret = self.cli.logs(container=self.container['Id']) if self.xcom_all else line.encode('utf-8')
if self.xcom_all:
ret = self.cli.logs(container=self.container['Id'])

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

why not strip here also?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

I agree it should probably be stripped, but my intention was to keep the current behavior when do_xcom_push and xcom_all are all true.

return ret

def execute(self, context) -> Optional[str]:
def execute(self, context) -> Optional[bytes]:

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

should we perhaps decode utf-8 (assuming that's what comes out of logs, so that we return a string type? sincere question... 🤔

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

coincidence someone is doing exactly that: https://github.com/apache/airflow/pull/13536/files

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Yes, and I think this would make more sense, but again I wanted to avoid a breaking change...

I would actually be happy with this other PR being merged, as it now includes the fix in my PR.

@davidcaron

Copy link
Copy Markdown
Contributor Author

@dstandish Thanks for your review.

If #13536 gets merged, this one can be closed.

I would personally consider this PR a bug fix, and #13536 a breaking change.

@github-actions

Copy link
Copy Markdown
Contributor

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.

@github-actions github-actions Bot added the stale Stale PRs per the .github/workflows/stale.yml policy file label Mar 23, 2021
@github-actions github-actions Bot closed this Mar 29, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

stale Stale PRs per the .github/workflows/stale.yml policy file

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants