[root@controller-0 plugins]# ps -aef|grep -e  "podman ps" -e "podman exec"
root      182773  174374  0 07:44 pts/2    00:00:00 timeout 300s podman exec ovn-dbs-bundle-podman-0 ovn-nbctl show
root      182777  182773  0 07:44 pts/2    00:00:00 podman exec ovn-dbs-bundle-podman-0 ovn-nbctl show
root      184552  174374  0 07:44 pts/2    00:00:00 timeout 300s podman ps
root      184555  184552  0 07:44 pts/2    00:00:00 podman ps
root      197528  142445  0 07:46 pts/3    00:00:00 grep --color=auto -e podman ps -e podman exec

[root@controller-0 plugins]# strace -f -p 182777
strace: Process 182777 attached with 11 threads
[pid 182815] --- stopped by SIGTTIN ---
[pid 182814] --- stopped by SIGTTIN ---
[pid 182811] --- stopped by SIGTTIN ---
[pid 182795] --- stopped by SIGTTIN ---
[pid 182794] --- stopped by SIGTTIN ---
[pid 182785] --- stopped by SIGTTIN ---
[pid 182784] --- stopped by SIGTTIN ---
[pid 182783] --- stopped by SIGTTIN ---
[pid 182781] --- stopped by SIGTTIN ---
[pid 182780] --- stopped by SIGTTIN ---
[pid 182777] --- stopped by SIGTTIN ---

[root@controller-0 plugins]# strace -f -p 184555
strace: Process 184555 attached with 11 threads
[pid 184619] futex(0xc0004a39c8, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 184576] futex(0xc000614148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 184575] epoll_pwait(4,  <unfinished ...>
[pid 184563] futex(0xc0004a2148, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 184561] fcntl(89, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=0} <unfinished ...>
[pid 184559] futex(0x561bf778bd98, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 184555] futex(0x561bf776e628, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 184564] futex(0x561bf776da10, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 184558] restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
[pid 184557] futex(0x561bf778bec0, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 184564] <... futex resumed> )      = 0
[pid 184564] epoll_wait(12,  <unfinished ...>
[pid 184556] restart_syscall(<... resuming interrupted futex ...>) = -1 EAGAIN (Resource temporarily unavailable)
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
[pid 184556] futex(0x561bf776da10, FUTEX_WAIT_PRIVATE, 0, {tv_sec=60, tv_nsec=0}

Something appears to have paused the 'podman exec' process while it is holding the container lock. 'podman ps' cannot proceed as it cannot acquire a lock necessary for operation.

I don't really know if I consider this a Podman bug - I'll check our expected behavior, but I'm fairly sure we don't expect 'exec' to continue executing after it gets a SIGTTIN. Then again, I'm not certain how we expect 'exec' to work in the background if that's true. I'll look into it.

Any update o this bugzilla?

(In reply to Daniel Walsh from comment #7)
> Any update o this bugzilla?

I would love to have this bug fixed. As currently it causes either of problems:

- either sosreport (the basic debugging tool used on support on majority of support cases) will not collect "podman ps" that substantially helps troubleshooting, I expect
- or sosreport with that command will hang (even worse option)

Both negatively impacts customer support, as it prolongs the time to obtain required troubleshooting data from a customer.

Matt, Valentin is it possible to put a timeout on lock waits?

Perhaps this is useful to determine if it's really a bug or not...


[root@controller-0 ~]# podman exec ovn-dbs-bundle-podman-0 ls  &
[1] 909385
[root@controller-0 ~]#
[1]+  Stopped                 podman exec ovn-dbs-bundle-podman-0 ls
[root@controller-0 ~]#
[root@controller-0 ~]#
[root@controller-0 ~]# podman ps
..... hanging until you kill the 'podman exec' command

When I control-C 'podman ps' and 'fg' the 'podman exec' command this is what I get:

^C
[root@controller-0 ~]# fg
podman exec ovn-dbs-bundle-podman-0 ls
Error: timed out waiting for runtime to create pidfile for exec session in container 3b763d3a55f54df6475a565e068c7536965f2607195c30615513822daf4fce6a: timed out waiting for file /var/run/containers/storage/overlay-containers/3b763d3a55f54df6475a565e068c7536965f2607195c30615513822daf4fce6a/userdata/exec_pid_082bdc5b83648a3b705f7222893d8c4b0fa3c01f2eb25f817bcea2bcd9f7fc7a: internal libpod error

Hello,
could you pretty please pay attention to this bug? It seems it can impact sosreport more than we expected, see recent

https://github.com/sosreport/sos/pull/1873#issuecomment-564456122

We introduced a workaround in sosreport that is not ideal (could also lead to some commands hung). But the root cause is still untouched, for months..

I am quite concerned of possible impact to sosreport, which is our primary diagnostic and troubleshooting tool. If sosreport wont be able to collect podman related data due to podman commands hung, our ability to support podman will be limited.


Could you please at least assess this bug?

Hi Pavel,

thanks a lot for the reminder. We had plenty of fires to fight, apologies for the long silence on this bug. We will have a look right now.

@Daniel,

can you provide a reproducer with explicit steps? I have been chatting with Pavel and have a better understanding of the environment and potential sources of the bug. A reproducer would be hugely beneficial.

Valentin, the way I hit this bug is by running sosreports.

More info here:
https://bugzilla.redhat.com/show_bug.cgi?id=1767359

We workarounded it like:
https://github.com/sosreport/sos/pull/1875

We just hit this issue in the lab. OpenStack is now fully containerized which means all processes that are spawned by the OpenStack services are spawned in containers too.

What we saw was that when cleaning one container, "podman rm -f" got stuck and conmon for the given process was still running. Killing the conmon helped but it required manual intervention.

Without manually cleaning the compute node, OpenStack was not able to provide metadata for any new VMs on given node, which leads to authentication errors when connecting to the VMs. It makes the VMs practically unusable. This is a serious issue for OpenStack. Unfortunately, we don't have a clear reproducer outside of OpenStack but we can provide environment for troubleshooting if needed. Please prioritize this issue as it has a huge impact.

(In reply to Valentin Rothberg from comment #13)
> @Daniel,
> 
> can you provide a reproducer with explicit steps? I have been chatting with
> Pavel and have a better understanding of the environment and potential
> sources of the bug. A reproducer would be hugely beneficial.

See https://bugzilla.redhat.com/show_bug.cgi?id=1819662#c10 for expected reproducer. That is the way how sosreport calls commands and that *should* hang the same way.

Optionally, update the list ["timeout", "300s", "/usr/bin/podman", ..  according to your needs / cmd to try.

Jakub Libosvar  that not quite true
openstack is fully contianerised but we use pid=host when running nova_libvirt so that all vms spawned by libvirt in the are not spawned in the container but are instead spawned in the host pid namespace and parented to the host pid1
not to the libvirt container.

we do this so that you can restart nova_libvirt without killing all the vms.

but yes in generall all processes are spawned in the contianers now just wanted to point out that we intenionally disable this is at least one place where it would be unresonable to do it and there may be others but the nova_libvirt is the canonical example where we want child process not to run in the containers process namesapce.

Can confirm that provided reproducer does work.

I'm pretty sure Podman is working as expected here. A long explanation will follow, but the short answer to this is "do not run your exec sessions with -t if they are in subprocesses".

I'm not sure that adding a timeout to our locks will help at all. The Podman process is in a paused state, and from my understanding of the scheduler, that means we're never going to execute (and so the timer's "kill podman after X seconds" will also never run) - it might somewhat improve the experience for other processes that want to wait on the frozen lock, but none of them will actually get in.

The core issue here is the freeze when run as a child of Python in the given way. We're getting a SIGTTIN as part of this, which pauses execution of `podman exec`. The pausing seems to be standard, expected behaviour (we could add a signal handler to ignore it, potentially, but that might break other users who actually expect that signal to work as advertised).

From some looks at the documentation, it looks like SIGTTIN is generated by a background process trying to read from a TTY controlled by a foreground process. I can switch the error from SIGTTIN to SIGTTOU by setting `stdin=None` in the reproducer, which initially made me think that the stdout/stderr pipes Python gives us count as a controlling foreground terminal (which would be strange), but I then noticed that `-t` was set in the exec session. Creating a pseudoterminal for your exec session will cause Podman to attempt to set raw mode on its STDOUT/STDERR (otherwise we'll be dumping terminal nonprintables everywhere in the output); it seems somewhat reasonable that Python (or maybe `timeout`?) would misbehave if we tried messing with its terminal settings. `-t` also munges STDOUT and STDERR together, since it assumes we're writing to a user-facing terminal we have full control over. Removing it makes the reproducer no longer hang, and no error is printed.

I'd be curious as to why `-t` was added in the first place - was there a specific reason?

Thanks for analysis. I dont see a reason to stick to -t option in "podman exec" (we even removed it in sos upstream), so we can get rid of it as a long term solution. Just to ensure for backporting purposes: script:

---------------------8<-----------------
from subprocess import Popen, PIPE
  
p = Popen(["timeout", "300s", "/usr/bin/podman", "exec", "rabbitmq-bundle-podman-1", "uptime"],
          shell=False,
          stdout=PIPE,
          stderr=PIPE,
          bufsize=-1,
          close_fds=True)

out, err = p.communicate()
  
if err:
    print("Error: %s" % err)
---------------------8<-----------------


will work well / isnt expected to hung? and with line:

p = Popen(["timeout", "--foreground", "300s", "/usr/bin/podman", "exec", "rabbitmq-bundle-podman-1", "uptime"],

that emulates TTY via timeout command (and that helps in some use cases where the above cmd/script hangs)?

Both of those should work fine - Podman should be very forgiving about how it's run when not creating a terminal. Without a terminal, we're just writing to stdout/stderr, same as any other program - no attempt to modify terminal settings, set raw mode, etc.

Given the discussions above, I'm going to close this BZ as Podman is working as expected.

The needinfo request[s] on this closed bug have been removed as they have been unresolved for 500 days