following logs of stopped containers

[muayyad-alsadi]

Is this a BUG REPORT or FEATURE REQUEST? (leave only one on its own line)

/kind bug

Description

when we create a container without starting it (podman create)
or when we stop a container

if we follow the logs using podman logs -f
on multiple containers one or more of them is running and one or more is stopped

later if it started logs are not shown.

Steps to reproduce the issue:

start two containers named sh1 sh2

stop sh1 only

follow logs with both the running sh2 and the stopped one sh1

on different terminal start sh1 (or using the command ( sleep 1; podman start sh1 )&)

$ podman run -d --name sh1 busybox /bin/sh -c 'for i in `seq 1000`; do echo "sh1 loop item $i"; sleep 0.5; done; exit 1'
b9dc35056841edf7b0fab5bd7b2c0b38b51a7e94b9432b23665a1d0a3fb07776
$ podman run -d --name sh2 busybox /bin/sh -c 'for i in `seq 1000`; do echo "sh2 loop item $i"; sleep 0.5; done; exit 1'
b11475c99dc07a4504fbf9e68267522e9dcba6623209d9baa4a0e64f783ea46d
$ podman stop -t=1 sh1
sh1
$ ( sleep 1; podman start sh1 )& podman logs -n --tail=0 -f sh1 sh2
[1] 114303
sh2 sh2 loop item 37
sh2 sh2 loop item 38
sh1
sh2 sh2 loop item 39
sh2 sh2 loop item 40
sh2 sh2 loop item 41
sh2 sh2 loop item 42
sh2 sh2 loop item 43

Describe the results you received:

output is only seen from sh2, no logs are shown from sh1 despite that it's started after 1 second

Describe the results you expected:

logs from both sh1 and sh2

Additional information you deem important (e.g. issue happens only occasionally):

in podman-compose I currently create containers without starting them
then start and attach each of them one by one each on a different thread because we can't attach to multiple

$ podman start -a sh1 sh2
Error: you cannot start and attach multiple containers at once

I want a way to start and follow the logs of multiple containers prefixing the name of the container to the output.

$ podman-compose up --exit-from=web
db: mysql started
redis: redis started
web: listing on 8080
....

internally this might be something like

podman create --name proj_db ...
podman create --name proj_redis ...
podman create --name proj_web ...

then either

podman logs --wait-once-for-non-started -n --tail=0 -f proj_db proj_redis proj_web &
podman start proj_db proj_redis proj_web

or

podman start -n -a proj_db proj_redis proj_web

or whatever you suggest

but the current behavior is that podman logs seems to be unaware of output created by container started after we run it.
I'm not sure what is the best way to achieve this.

Output of podman version:

Version:      3.4.2
API Version:  3.4.2
Go Version:   go1.16.8
Built:        Sun Nov 14 02:16:48 2021
OS/Arch:      linux/amd64

Output of podman info --debug:

host:
  arch: amd64
  buildahVersion: 1.23.1
  cgroupControllers:
  - memory
  - pids
  cgroupManager: systemd
  cgroupVersion: v2
  conmon:
    package: conmon-2.0.30-2.fc34.x86_64
    path: /usr/bin/conmon
    version: 'conmon version 2.0.30, commit: '
  cpus: 8
  distribution:
    distribution: fedora
    variant: workstation
    version: "34"
  eventLogger: journald
  hostname: alsadi-laptop.localdomain
  idMappings:
    gidmap:
    - container_id: 0
      host_id: 1000
      size: 1
    - container_id: 1
      host_id: 100000
      size: 65536
    uidmap:
    - container_id: 0
      host_id: 1000
      size: 1
    - container_id: 1
      host_id: 100000
      size: 65536
  kernel: 5.15.5-100.fc34.x86_64
  linkmode: dynamic
  logDriver: k8s-file
  memFree: 8793444352
  memTotal: 16652857344
  ociRuntime:
    name: crun
    package: crun-1.3-1.fc34.x86_64
    path: /usr/bin/crun
    version: |-
      crun version 1.3
      commit: 8e5757a4e68590326dafe8a8b1b4a584b10a1370
      spec: 1.0.0
      +SYSTEMD +SELINUX +APPARMOR +CAP +SECCOMP +EBPF +CRIU +YAJL
  os: linux
  remoteSocket:
    path: /run/user/1000/podman/podman.sock
  security:
    apparmorEnabled: false
    capabilities: CAP_CHOWN,CAP_DAC_OVERRIDE,CAP_FOWNER,CAP_FSETID,CAP_KILL,CAP_NET_BIND_SERVICE,CAP_SETFCAP,CAP_SETGID,CAP_SETPCAP,CAP_SETUID,CAP_SYS_CHROOT
    rootless: true
    seccompEnabled: true
    seccompProfilePath: /usr/share/containers/seccomp.json
    selinuxEnabled: true
  serviceIsRemote: false
  slirp4netns:
    executable: /usr/bin/slirp4netns
    package: slirp4netns-1.1.12-2.fc34.x86_64
    version: |-
      slirp4netns version 1.1.12
      commit: 7a104a101aa3278a2152351a082a6df71f57c9a3
      libslirp: 4.4.0
      SLIRP_CONFIG_VERSION_MAX: 3
      libseccomp: 2.5.3
  swapFree: 17012088832
  swapTotal: 17012088832
  uptime: 24h 31m 21.43s (Approximately 1.00 days)
plugins:
  log:
  - k8s-file
  - none
  - journald
  network:
  - bridge
  - macvlan
  volume:
  - local
registries:
  search:
  - registry.fedoraproject.org
  - registry.access.redhat.com
  - docker.io
  - quay.io
store:
  configFile: /home/alsadi/.config/containers/storage.conf
  containerStore:
    number: 11
    paused: 0
    running: 3
    stopped: 8
  graphDriverName: overlay
  graphOptions:
    overlay.mount_program:
      Executable: /usr/bin/fuse-overlayfs
      Package: fuse-overlayfs-1.7.1-2.fc34.x86_64
      Version: |-
        fusermount3 version: 3.10.4
        fuse-overlayfs: version 1.7.1
        FUSE library version 3.10.4
        using FUSE kernel interface version 7.31
  graphRoot: /home/alsadi/.local/share/containers/storage
  graphStatus:
    Backing Filesystem: extfs
    Native Overlay Diff: "false"
    Supports d_type: "true"
    Using metacopy: "false"
  imageStore:
    number: 8
  runRoot: /run/user/1000
  volumePath: /home/alsadi/.local/share/containers/storage/volumes
version:
  APIVersion: 3.4.2
  Built: 1636849008
  BuiltTime: Sun Nov 14 02:16:48 2021
  GitCommit: ""
  GoVersion: go1.16.8
  OsArch: linux/amd64
  Version: 3.4.2

Package info (e.g. output of rpm -q podman or apt list podman):

podman-3.4.2-1.fc34.x86_64

Have you tested with the latest version of Podman and have you checked the Podman Troubleshooting Guide? (https://github.com/containers/podman/blob/master/troubleshooting.md)

No

Additional environment details (AWS, VirtualBox, physical, etc.):
physical

[vrothberg]

Thanks for reaching out and providing the great reproducer.

It turns out that podman logs sh2 returns logs from container sh1.

[muayyad-alsadi]

$ ( sleep 1; podman start sh1 )& podman logs -n --tail=0 -f sh1 sh2
[1] 114303
sh2 sh2 loop item 37
sh2 sh2 loop item 38
sh1 <------------------------------- here is the output of "podman start sh1"
sh2 sh2 loop item 39
<------------------------------------- start from here we should see `sh1 sh1 loop item <NUM>` smaller than 39 (because it was stopped)
sh2 sh2 loop item 40

[vrothberg]

@muayyad-alsadi, can you retry with --tail=-1? That should display what you're looking for, does it?

[muayyad-alsadi]

podman run -d --name sh1 busybox /bin/sh -c 'for i in `seq 1000`; do echo "sh1 loop item $i"; sleep 0.5; done; exit 1'
podman run -d --name sh2 busybox /bin/sh -c 'for i in `seq 1000`; do echo "sh2 loop item $i"; sleep 0.5; done; exit 1'
sleep 2
podman stop -t=1 sh1
( sleep 5; podman start sh1 )& podman logs -n --tail=-1 -f sh1 sh2

output

b2d606ee286de1d5f55f48c596588e497a33a92929ef565b2fbc9a4cd34c4c7c
1132a725780ba7cad4a8dc5f69219f1fc83e0f1ef78088c6d62031a2ee9a7b85
sh1
[1] 243582
sh1 sh1 loop item 1
sh1 sh1 loop item 2
sh1 sh1 loop item 3
sh2 sh2 loop item 1
sh1 sh1 loop item 4
sh1 sh1 loop item 5
sh1 sh1 loop item 6
sh1 sh1 loop item 7
sh1 sh1 loop item 8 <---- it's stopped from here, no sh1 after this line
sh2 sh2 loop item 2
sh2 sh2 loop item 3
sh2 sh2 loop item 4
sh2 sh2 loop item 5
sh2 sh2 loop item 6
sh2 sh2 loop item 7
sh2 sh2 loop item 8
sh2 sh2 loop item 9
sh2 sh2 loop item 10
sh2 sh2 loop item 11
sh2 sh2 loop item 12
sh2 sh2 loop item 13
sh2 sh2 loop item 14
sh2 sh2 loop item 15
sh2 sh2 loop item 16
sh2 sh2 loop item 17
sh2 sh2 loop item 18
sh1 <------------------------- started
sh2 sh2 loop item 19 <------------ yet no output
sh2 sh2 loop item 20
sh2 sh2 loop item 21
sh2 sh2 loop item 22
sh2 sh2 loop item 23
sh2 sh2 loop item 24
sh2 sh2 loop item 25
sh2 sh2 loop item 26
sh2 sh2 loop item 27
sh2 sh2 loop item 28
^C

if I typed --tail=-1 again it will display things correctly

$ podman logs -n --tail=-1 -f sh1 sh2
sh1 sh1 loop item 1
sh1 sh1 loop item 2
sh1 sh1 loop item 3
sh1 sh1 loop item 4
sh1 sh1 loop item 5
sh1 sh1 loop item 6
sh2 sh2 loop item 1
sh1 sh1 loop item 7
sh2 sh2 loop item 2
sh2 sh2 loop item 3
sh2 sh2 loop item 4
sh2 sh2 loop item 5 <------ sh1 stopped
sh1 sh1 loop item 8
sh2 sh2 loop item 6
sh2 sh2 loop item 7
sh1 sh1 loop item 1 <---- sh1 started, but the number is smaller than sh2
sh2 sh2 loop item 8
sh2 sh2 loop item 9
sh2 sh2 loop item 10
sh1 sh1 loop item 2
sh1 sh1 loop item 3
sh2 sh2 loop item 11
sh1 sh1 loop item 4
sh1 sh1 loop item 5
sh1 sh1 loop item 6
sh1 sh1 loop item 7
sh2 sh2 loop item 12
sh2 sh2 loop item 13
sh1 sh1 loop item 8
sh2 sh2 loop item 14
sh2 sh2 loop item 15
sh1 sh1 loop item 9
sh1 sh1 loop item 10
sh1 sh1 loop item 11
sh2 sh2 loop item 16
sh1 sh1 loop item 12
sh2 sh2 loop item 17
sh1 sh1 loop item 13
sh2 sh2 loop item 18
sh1 sh1 loop item 14
sh1 sh1 loop item 15
sh1 sh1 loop item 16
sh1 sh1 loop item 17
sh1 sh1 loop item 18
sh2 sh2 loop item 19
sh2 sh2 loop item 20
sh1 sh1 loop item 19
sh2 sh2 loop item 21
sh2 sh2 loop item 22
sh1 sh1 loop item 20
sh2 sh2 loop item 23
sh1 sh1 loop item 21
sh2 sh2 loop item 24
sh2 sh2 loop item 25
sh2 sh2 loop item 26
sh2 sh2 loop item 27
sh2 sh2 loop item 28
^C

[muayyad-alsadi]

in short, if the container is stopped at the time of podman logs, then its logs will get followed even if it got started later.

[github-actions]

A friendly reminder that this issue had no activity for 30 days.

[rhatdan]

@vrothberg @mheon What should we do with this?

[vrothberg]

Needs to be fixed / prioritized but I am very short on cycles at the moment.

[github-actions]

A friendly reminder that this issue had no activity for 30 days.

[masch]

I have this issue, Is there a workaround until you could fix it?

[rhatdan]

@vrothberg A golden oldie, covered by stale-issue flag.