DockerOperator loosing some initial container output

[the-horhe]

Apache Airflow version: 1.10.10

Environment: official docker image apache/airflow:1.10.10, docker api version: 1.40

What happened:
Don't see any container output in task logs when using DockerOperator with short living containers.

What you expected to happen:
Expected to see container stdout/stderr

It seems the problem is here: https://github.com/apache/airflow/blob/v1-10-stable/airflow/operators/docker_operator.py#L232

1. Containers is being started
2. We attach to container output

But all output between steep 1 and to 2 seems to be lost.

I found a simple solution - adding logs=True to self.cli.attach fixes the problem
https://github.com/apache/airflow/blob/v1-10-stable/airflow/operators/docker_operator.py#L235
According to docker API documentation (https://docs.docker.com/engine/api/v1.40.yaml - line 6052) solution seems legit.

How to reproduce it:

from datetime import timedelta
from airflow.utils.dates import days_ago
from airflow import DAG
from airflow.operators.docker_operator import DockerOperator


default_args = {
    'owner': 'airflow',
    'depends_on_past': True,
    'wait_for_downstream': True,
    'catchup': True,
    'start_date': days_ago(2),
    'retries': 1,
    'retry_delay': timedelta(minutes=5),
}
dag = DAG(
    'docker_dag',
    default_args=default_args,
    description='',
    schedule_interval=timedelta(days=1),
)

print_hello_world = DockerOperator(
    task_id='print_hello_world',
    image='centos:latest',
    api_version='auto',
    auto_remove=True,
    command='/bin/bash -c \'echo "HELLO WORLD!"\'',
    docker_url='unix://var/run/docker.sock',
    network_mode='bridge',
    dag=dag,
)

Output without logs=True:

Output without logs=True but with slow starting container (command /bin/bash -c \'sleep 5 && echo "HELLO WORLD!"\'):

^ ok - notice string with "INFO - HELLO WORLD!"

Output with original command and logs=True:

^ ok - notice string with "INFO - HELLO WORLD!"

[boring-cyborg]

Thanks for opening your first issue here! Be sure to follow the issue template!

[nullhack]

This issue can be related to a recently merged PR.

I tried to run using the docker image apache/airflow:master-ci and the output is as expected.

If this is the case, It's related to the auto_remove=True, (the container gets removed before The task can get the stdout). If not, can be related to the issue 1 of #9164

@the-horhe If you use DockerOperator often, can you give a feedback on this issue/PR I proposed some days ago ? Thanks.

[the-horhe]

Tested with auto_remove=False - it seems it has no effect. Did't try with apache/airflow:master-ci though yet.
Also modified command to /bin/bash -c \'echo "1" && sleep 5 && echo "2"\ and see only 2 in logs, so to me it seems the problem is a late container connection.

@nullhack it is the first time we try to use DockerOperator, so don't have much to say 8(

[alexkruc]

I tried to look at this issue, but I can't seem to reproduce it.
I tried running the (almost) the same code as was presented in the example:

  print_hello_world = DockerOperator(
      task_id='print_hello_world',
      image='centos:latest',
      api_version='auto',
      auto_remove=True,
      command='/bin/bash -c \'echo "HELLO WORLD!"\'',
      network_mode='bridge',
      dag=dag,
  )

But I got the output of the container proper...

Also tried running other tasks, with different containers and commands, and it all worked as expected - the output printed out immediately.

I see that the reported version of this issue was 1.10.10, there were A LOT of changes since then.
Can someone reproduce this issue on the most recent versions and share information?

[the-horhe]

Checked with 2.3.2 - can't reproduce it either. It seem some changes in provider or python docker client fixed the issue.