docker/compose

[BUG] Logs not available after graceful stop

RasmusN opened this issue · 5 comments

RasmusN commented

Description

It seems like stdout doesn't gets flushed to the logs properly after graceful stop.

Steps To Reproduce

  1. In this environment
$ tree .
.
|-- docker-compose.yml
`-- service_a
    |-- Dockerfile
    `-- app.py

docker-compose.yml

services:
  service_a:
    build:
      context: ./service_a
    command: python app.py

service_a/Dockerfile

FROM python:3.9-slim
WORKDIR /app
COPY app.py .
CMD ["python", "app.py"]

service_a/app.py

import time

print("Hello from A.")
while(True):
    time.sleep(1)

  1. Run this command
    docker compose build && docker compose up

  2. Send keyboard interrupt (Press ctrl+c)

  3. Check logs
    docker compose logs -t service_a

Ideally I'd like to see "Hello from A." directly after step 2, but it doesn't even show after step 4.
If I run the image directly with Docker the stdout is printed after sending keyboard interrupt.

Compose Version

$ docker compose version
Docker Compose version v2.30.3-desktop.1

$ docker-compose version
Docker Compose version v2.29.1-desktop.1

Docker Environment

$ docker info
Client:
 Version:    27.3.1
 Context:    default
 Debug Mode: false
 Plugins:
  ai: Ask Gordon - Docker Agent (Docker Inc.)
    Version:  v0.1.0
    Path:     C:\Program Files\Docker\cli-plugins\docker-ai.exe
  buildx: Docker Buildx (Docker Inc.)
    Version:  v0.18.0-desktop.2
    Path:     C:\Program Files\Docker\cli-plugins\docker-buildx.exe
  compose: Docker Compose (Docker Inc.)
    Version:  v2.30.3-desktop.1
    Path:     C:\Program Files\Docker\cli-plugins\docker-compose.exe
  debug: Get a shell into any image or container (Docker Inc.)
    Version:  0.0.37
    Path:     C:\Program Files\Docker\cli-plugins\docker-debug.exe
  desktop: Docker Desktop commands (Alpha) (Docker Inc.)
    Version:  v0.0.15
    Path:     C:\Program Files\Docker\cli-plugins\docker-desktop.exe
  dev: Docker Dev Environments (Docker Inc.)
    Version:  v0.1.2
    Path:     C:\Program Files\Docker\cli-plugins\docker-dev.exe
  extension: Manages Docker extensions (Docker Inc.)
    Version:  v0.2.27
    Path:     C:\Program Files\Docker\cli-plugins\docker-extension.exe
  feedback: Provide feedback, right in your terminal! (Docker Inc.)
    Version:  v1.0.5
    Path:     C:\Program Files\Docker\cli-plugins\docker-feedback.exe
  init: Creates Docker-related starter files for your project (Docker Inc.)
    Version:  v1.4.0
    Path:     C:\Program Files\Docker\cli-plugins\docker-init.exe
  sbom: View the packaged-based Software Bill Of Materials (SBOM) for an image (Anchore Inc.)
    Version:  0.6.0
    Path:     C:\Program Files\Docker\cli-plugins\docker-sbom.exe
  scout: Docker Scout (Docker Inc.)
    Version:  v1.15.0
    Path:     C:\Program Files\Docker\cli-plugins\docker-scout.exe

Server:
 Containers: 15
  Running: 0
  Paused: 0
  Stopped: 15
 Images: 10
 Server Version: 27.3.1
 Storage Driver: overlayfs
  driver-type: io.containerd.snapshotter.v1
 Logging Driver: json-file
 Cgroup Driver: cgroupfs
 Cgroup Version: 1
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local splunk syslog
 Swarm: inactive
 Runtimes: io.containerd.runc.v2 nvidia runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 472731909fa34bd7bc9c087e4c27943f9835f111
 runc version: v1.1.13-0-g58aa920
 init version: de40ad0
 Security Options:
  seccomp
   Profile: unconfined
 Kernel Version: 5.15.153.1-microsoft-standard-WSL2
 Operating System: Docker Desktop
 OSType: linux
 Architecture: x86_64
 CPUs: 8
 Total Memory: 7.623GiB
 Name: docker-desktop
 ID: 61370a9b-7979-412e-8218-83c440bc26ac
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 HTTP Proxy: http.docker.internal:3128
 HTTPS Proxy: http.docker.internal:3128
 No Proxy: hubproxy.docker.internal
 Labels:
  com.docker.desktop.address=npipe://\\.\pipe\docker_cli
 Experimental: false
 Insecure Registries:
  hubproxy.docker.internal:5555
  127.0.0.0/8
 Live Restore Enabled: false

WARNING: No blkio throttle.read_bps_device support
WARNING: No blkio throttle.write_bps_device support
WARNING: No blkio throttle.read_iops_device support
WARNING: No blkio throttle.write_iops_device support
WARNING: daemon is not using the default seccomp profile

Anything else?

No response

ndeloof commented

This is Docker Compose behavior since it's origin: after request to interrupt services, compose detaches from container and stop piping logs. This also allows to render stop status as a progress UX with resources being removed

There's no plan to change this behavior

RasmusN commented

This is Docker Compose behavior since it's origin: after request to interrupt services, compose detaches from container and stop piping logs. This also allows to render stop status as a progress UX with resources being removed

There's no plan to change this behavior

Ok, I understand.

How come it doesn't print the message in real-time?

ndeloof commented

Compose (same as docker/cli) use ContainerAttach API to get container output in real-time. But python ran in your container has it's own buffering and flush mechanism accessing stdout. This is why you don't get the "Hello" message before you interrupt container, even running with docker run ...

  • 👍1
nejtr0n commented

Hello. Any workaround of this behaviour ?
Some application do extra job after catching stop signals (e.g. close connections, clear buffers etc)
So we need to see logs after stop signal till process done.
May be add some extra flag to compose up ?