5:01 a.m.
Hi all,
I'm using podman-remote and I'm trying to exec commands in containers.
It seems it fails, but I don't really understand why.
I'm on fedora 30 (with last updates), I tried podman 1.6.1 (from RPMs)
but also 1.6.2 compiled from scratch:
$ podman version
Version: 1.6.2
RemoteAPI Version: 1
Go Version: go1.12.10
OS/Arch: linux/amd64
Ultimately, I'd need to exec commands from a golang program, but for now
experimenting with command line is fine, but can't make even this work :)
here's what I tried:
$ varlink call -m unix:/run/podman/io.podman/io.podman.CreateContainer
'{"create":{"args":["fedora:30", "/bin/sleep",
"10h"]}}'
{
"container":
"c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853"
}
$ varlink call -m unix:/run/podman/io.podman/io.podman.StartContainer
'{"name":"c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853"}'
{
"container":
"c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853"
}
The container IS running now:
root 7836 0.0 0.0 77876 1756 ? Ssl 09:11 0:00
/usr/bin/conmon --api-version 1 -s -c
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853 -u
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853 -r
/usr/bin/runc -b
/var/lib/containers/storage/overlay-containers/c24e28054f89c0a
root 7848 0.0 0.0 2320 684 ? Ss 09:11 0:00 \_
/bin/sleep 10h
So I do:
$ varlink call -m unix:/run/podman/io.podman/io.podman.ExecContainer '{
"opts": { "name":
"c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853",
"tty": true, "privileged": true, "cmd":
["/bin/date"] } }'
Call failed with error: io.podman.ErrorOccurred
{
"reason": "client must use upgraded connection to exec"
}
So I downloaded go-varlink-cmd
(https://github.com/varlink/go-varlink-cmd) and patched to supporte the
upgraded connection (on client side)[1], but doesn't look much better:
$ ~/bin/go-varlink-cmd call -upgrade
unix:/run/podman/io.podman/io.podman.ExecContainer '{ "opts": {
"name":
"c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853",
"tty": true, "privileged": true, "cmd":
["/bin/date"] } }'
recv -> 0 # return value
retval -> map[string]interface {}(nil) # what got as answer
{} # answer translated to JSON
No luck with minimal command line either:
$ ~/bin/go-varlink-cmd call -upgrade
unix:/run/podman/io.podman/io.podman.ExecContainer '{ "opts": {
"name":
"c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853",
"cmd": ["/bin/date"] } }'
recv -> 0
retval -> map[string]interface {}(nil)
{}
Maybe, just wondering: do I need to set something when I create the
container? If so the docs aren't crystal clear :\
I tried to look at logs but can't make much sense. Here's the logs for
podman-remote on my system, with log level increased to debug:
Oct 28 09:21:09 myhost.lan systemd[1]: Started Podman Remote API Service.
Oct 28 09:21:09 myhost.lan audit[1]: SERVICE_START pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=io.podman comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Using varlink socket:
unix:/run/podman/io.podman"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="using conmon:
\"/usr/bin/conmon\""
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Initializing boltdb
state at /var/lib/containers/storage/libpod/bolt_state.db"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Using graph driver
overlay"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Using graph root
/var/lib/containers/storage"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Using run root
/var/run/containers/storage"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Using static dir
/var/lib/containers/storage/libpod"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Using tmp dir
/var/run/libpod"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Using volume path
/var/lib/containers/storage/volumes"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Set libpod namespace
to \"\""
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="[graphdriver] trying
provided driver \"overlay\""
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="cached value indicated
that overlay is supported"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="cached value indicated
that metacopy is being used"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="cached value indicated
that native-diff is not being used"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=warning msg="Not using native
diff for overlay, this may cause degraded performance for building
images: kernel has CONFIG_OVERLAY_FS_REDIRECT_DIR enabled"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="backingFs=extfs,
projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=true"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Initializing event
backend journald"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="using runtime
\"/usr/bin/runc\""
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=warning msg="Error initializing
configured OCI runtime crun: no valid executable found for OCI runtime
crun: invalid argument"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=info msg="Found CNI network
podman (type=bridge) at /etc/cni/net.d/87-podman-bridge.conflist"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Creating new exec
session in container
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853 with
session id 6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c014c15054f67c"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=error msg="ExecContainer failed
to HANG-UP on
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853: write
unix /run/podman/io.podman->@: write: broken pipe"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=error msg="Exec Container err:
write unix /run/podman/io.podman->@: write: broken pipe"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="/usr/bin/conmon
messages will be logged to syslog"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="running conmon:
/usr/bin/conmon" args="[--api-version 1 -s -c
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853 -u
6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c014c15054f67c -r
/usr/bin/runc -b />
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="disabling SD
notify"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=info msg="Running conmon under
slice machine.slice and unitName
libpod-conmon-c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853.scope"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=warning msg="Failed to add conmon
to systemd sandbox cgroup: Unit
libpod-conmon-c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853.scope
already exists."
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Attaching to container
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853 exec
session 6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c014c15054f67c"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="connecting to socket
/var/run/libpod/socket/6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c014c15054f67c/attach"
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: addr{sun_family=AF_UNIX, sun_path=/tmp/conmon-term.B2039Z}
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: attach sock path:
/var/run/libpod/socket/6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c014c15054f67c/attach
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: addr{sun_family=AF_UNIX,
sun_path=/var/run/libpod/socket/6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c014c15054f67c/attach}
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: ctl fifo path:
/var/lib/containers/storage/overlay-containers/c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853/userdata/6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c014c15054f67c/ctl
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: terminal_ctrl_fd: 18
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ndebug>: sending attach message to parent
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ndebug>: sent attach message to parent
Oct 28 09:21:09 myhost.lan conmon[8108]: conmon c24e28054f89c0a0ac9c
<ndebug>: exec with attach is waiting for start message from parent
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Received: 0"
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: Accepted connection 20
Oct 28 09:21:09 myhost.lan conmon[8108]: conmon c24e28054f89c0a0ac9c
<ndebug>: exec with attach got start message from parent
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: about to accept from console_socket_fd: 14
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: about to recvfd from connfd: 21
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: console = {.name = '/dev/ptmx8 09:21:09 conmon: conmon
c24e28054f89c0a0ac9c <ninfo>: about to recvfd from connfd: 21
'; .fd = 14}
Oct 28 09:21:09 myhost.lan systemd[2088]:
run-runc-c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853-runc.xJTNZd.mount:
Succeeded.
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ndebug>: couldn't find cb for pid 8121
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ndebug>: container status and pid were found prior to callback being
registered. calling manually
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ndebug>: container PID: 8121
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<nwarn>: Failed to open cgroups file: /proc/8121/cgroup
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<nwarn>: Failed to get memory cgroup path. Container may have exited
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Received: 8121"
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<nwarn>: stdio_input read failed Input/output error
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<nwarn>: Failed to write to socket
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<error>: Unable to send container stderr message to parent Bad file
descriptor
Oct 28 09:21:09 myhost.lan podman[8087]: 2019-10-28 09:21:09.632987596
+0100 CET m=+0.247438867 container exec
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853
(image=docker.io/library/fedora:30, name=sad_thompson)
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Successfully started
exec session
6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c014c15054f67c in
container c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=error msg="write unix
/run/podman/io.podman->@: write: broken pipe"
I'm out of ideas and can't find anything in the docs - apologies if I
missed anything, please feel free to send me there
Any help or comment would be appreciated.
Thanks and bests!
--
Francesco Romani
Senior SW Eng., Virtualization R&D
Red Hat
IRC: fromani github: @fromanirh
10:09 a.m.
I'm glad to see that you are going to implement this in a golang
program. That is how you are going to have to do it. I know of no
other way.
On Mon, 2019-10-28 at 10:01 +0100, Francesco Romani wrote:
Hi all,
I'm using podman-remote and I'm trying to exec commands in
containers.
It seems it fails, but I don't really understand why.
I'm on fedora 30 (with last updates), I tried podman 1.6.1 (from
RPMs)
but also 1.6.2 compiled from scratch:
$ podman version
Version: 1.6.2
RemoteAPI Version: 1
Go Version: go1.12.10
OS/Arch: linux/amd64
Ultimately, I'd need to exec commands from a golang program, but for
now
experimenting with command line is fine, but can't make even this
work :)
here's what I tried:
$ varlink call -m
unix:/run/podman/io.podman/io.podman.CreateContainer
'{"create":{"args":["fedora:30",
"/bin/sleep", "10h"]}}'
{
"container":
"c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853"
}
$ varlink call -m
unix:/run/podman/io.podman/io.podman.StartContainer
'{"name":"c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a1
64853"}'
{
"container":
"c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853"
}
The container IS running now:
root 7836 0.0 0.0 77876 1756 ? Ssl 09:11 0:00
/usr/bin/conmon --api-version 1 -s -c
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853 -u
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853 -r
/usr/bin/runc -b
/var/lib/containers/storage/overlay-containers/c24e28054f89c0a
root 7848 0.0 0.0 2320 684 ? Ss 09:11 0:00 \_
/bin/sleep 10h
So I do:
$ varlink call -m unix:/run/podman/io.podman/io.podman.ExecContainer
'{
"opts": { "name":
"c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853",
"tty": true, "privileged": true, "cmd":
["/bin/date"] } }'
Call failed with error: io.podman.ErrorOccurred
{
"reason": "client must use upgraded connection to exec"
}
So I downloaded go-varlink-cmd
(https://github.com/varlink/go-varlink-cmd) and patched to supporte
the
upgraded connection (on client side)[1], but doesn't look much
better:
$ ~/bin/go-varlink-cmd call -upgrade
unix:/run/podman/io.podman/io.podman.ExecContainer '{ "opts": {
"name":
"c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853",
"tty": true, "privileged": true, "cmd":
["/bin/date"] } }'
recv -> 0 # return value
retval -> map[string]interface {}(nil) # what got as answer
{} # answer translated to JSON
No luck with minimal command line either:
$ ~/bin/go-varlink-cmd call -upgrade
unix:/run/podman/io.podman/io.podman.ExecContainer '{ "opts": {
"name":
"c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853",
"cmd": ["/bin/date"] } }'
recv -> 0
retval -> map[string]interface {}(nil)
{}
Maybe, just wondering: do I need to set something when I create the
container? If so the docs aren't crystal clear :\
I tried to look at logs but can't make much sense. Here's the logs
for
podman-remote on my system, with log level increased to debug:
Oct 28 09:21:09 myhost.lan systemd[1]: Started Podman Remote API
Service.
Oct 28 09:21:09 myhost.lan audit[1]: SERVICE_START pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=io.podman comm="systemd" exe="/usr/lib/systemd/systemd"
hostname=? addr=? terminal=? res=success'
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Using varlink
socket:
unix:/run/podman/io.podman"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="using conmon:
\"/usr/bin/conmon\""
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Initializing
boltdb
state at /var/lib/containers/storage/libpod/bolt_state.db"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Using graph driver
overlay"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Using graph root
/var/lib/containers/storage"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Using run root
/var/run/containers/storage"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Using static dir
/var/lib/containers/storage/libpod"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Using tmp dir
/var/run/libpod"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Using volume path
/var/lib/containers/storage/volumes"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Set libpod
namespace
to \"\""
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="[graphdriver]
trying
provided driver \"overlay\""
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="cached value
indicated
that overlay is supported"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="cached value
indicated
that metacopy is being used"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="cached value
indicated
that native-diff is not being used"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=warning msg="Not using native
diff for overlay, this may cause degraded performance for building
images: kernel has CONFIG_OVERLAY_FS_REDIRECT_DIR enabled"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="backingFs=extfs,
projectQuotaSupported=false, useNativeDiff=false, usingMetacopy=true"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Initializing event
backend journald"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="using runtime
\"/usr/bin/runc\""
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=warning msg="Error
initializing
configured OCI runtime crun: no valid executable found for OCI
runtime
crun: invalid argument"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=info msg="Found CNI network
podman (type=bridge) at /etc/cni/net.d/87-podman-bridge.conflist"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Creating new exec
session in container
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853
with
session id
6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c014c15054f67c"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=error msg="ExecContainer
failed
to HANG-UP on
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853:
write
unix /run/podman/io.podman->@: write: broken pipe"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=error msg="Exec Container
err:
write unix /run/podman/io.podman->@: write: broken pipe"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="/usr/bin/conmon
messages will be logged to syslog"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="running conmon:
/usr/bin/conmon" args="[--api-version 1 -s -c
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853 -u
6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c014c15054f67c -r
/usr/bin/runc -b />
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="disabling SD
notify"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=info msg="Running conmon
under
slice machine.slice and unitName
libpod-conmon-
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853.scop
e"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=warning msg="Failed to add
conmon
to systemd sandbox cgroup: Unit
libpod-conmon-
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853.scop
e
already exists."
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Attaching to
container
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853
exec
session
6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c014c15054f67c"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="connecting to
socket
/var/run/libpod/socket/6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba
1534c014c15054f67c/attach"
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: addr{sun_family=AF_UNIX, sun_path=/tmp/conmon-term.B2039Z}
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: attach sock path:
/var/run/libpod/socket/6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba
1534c014c15054f67c/attach
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: addr{sun_family=AF_UNIX,
sun_path=/var/run/libpod/socket/6a1ccdea916ee245420320fa3ce02ff68ea06
6b8b6b7ba1534c014c15054f67c/attach}
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: ctl fifo path:
/var/lib/containers/storage/overlay-
containers/c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a
164853/userdata/6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c01
4c15054f67c/ctl
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: terminal_ctrl_fd: 18
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ndebug>: sending attach message to parent
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ndebug>: sent attach message to parent
Oct 28 09:21:09 myhost.lan conmon[8108]: conmon c24e28054f89c0a0ac9c
<ndebug>: exec with attach is waiting for start message from parent
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Received: 0"
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: Accepted connection 20
Oct 28 09:21:09 myhost.lan conmon[8108]: conmon c24e28054f89c0a0ac9c
<ndebug>: exec with attach got start message from parent
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: about to accept from console_socket_fd: 14
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: about to recvfd from connfd: 21
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ninfo>: console = {.name = '/dev/ptmx8 09:21:09 conmon: conmon
c24e28054f89c0a0ac9c <ninfo>: about to recvfd from connfd: 21
'; .fd = 14}
Oct 28 09:21:09 myhost.lan systemd[2088]:
run-runc-
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853-
runc.xJTNZd.mount:
Succeeded.
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ndebug>: couldn't find cb for pid 8121
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ndebug>: container status and pid were found prior to callback
being
registered. calling manually
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<ndebug>: container PID: 8121
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<nwarn>: Failed to open cgroups file: /proc/8121/cgroup
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<nwarn>: Failed to get memory cgroup path. Container may have exited
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Received: 8121"
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<nwarn>: stdio_input read failed Input/output error
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<nwarn>: Failed to write to socket
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<error>: Unable to send container stderr message to parent Bad file
descriptor
Oct 28 09:21:09 myhost.lan podman[8087]: 2019-10-28
09:21:09.632987596
+0100 CET m=+0.247438867 container exec
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853
(image=docker.io/library/fedora:30, name=sad_thompson)
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Successfully
started
exec session
6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c014c15054f67c in
container
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=error msg="write unix
/run/podman/io.podman->@: write: broken pipe"
I'm out of ideas and can't find anything in the docs - apologies if
I
missed anything, please feel free to send me there
Any help or comment would be appreciated.
Thanks and bests!
--
Francesco Romani
Senior SW Eng., Virtualization R&D
Red Hat
IRC: fromani github: @fromanirh
_______________________________________________
Podman mailing list -- podman(a)lists.podman.io
To unsubscribe send an email to podman-leave(a)lists.podman.io
10:19 a.m.
On 10/28/19 3:09 PM, Brent Baude wrote:
I'm glad to see that you are going to implement this in a golang
program. That is how you are going to have to do it. I know of no
other way.
Hey,
thanks for your reply. Does this means it could be a podman bug?
bests,
--
Francesco Romani
Senior SW Eng., Virtualization R&D
Red Hat
IRC: fromani github: @fromanirh
10:23 a.m.
On Mon, 2019-10-28 at 15:19 +0100, Francesco Romani wrote:
On 10/28/19 3:09 PM, Brent Baude wrote:
> I'm glad to see that you are going to implement this in a golang
> program. That is how you are going to have to do it. I know of no
> other way.
Hey,
thanks for your reply. Does this means it could be a podman bug?
bests,
I don't believe so. I am unaware of how to use the generic varlink
tools to emulate and upgraded connection.
10:27 a.m.
On 10/28/19 3:23 PM, Brent Baude wrote:
On Mon, 2019-10-28 at 15:19 +0100, Francesco Romani wrote:
> On 10/28/19 3:09 PM, Brent Baude wrote:
>> I'm glad to see that you are going to implement this in a golang
>> program. That is how you are going to have to do it. I know of no
>> other way.
> Hey,
>
>
> thanks for your reply. Does this means it could be a podman bug?
>
>
> bests,
>
I don't believe so. I am unaware of how to use the generic varlink
tools to emulate and upgraded connection.
OK, thanks. Any other tips about how I can debug this further?
These entries in the podman syslog (actually journal, but still) look
suspicious:
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<nwarn>: stdio_input read failed Input/output error
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<nwarn>: Failed to write to socket
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<error>: Unable to send container stderr message to parent Bad file
descriptor
Oct 28 09:21:09 myhost.lan podman[8087]: 2019-10-28 09:21:09.632987596
+0100 CET m=+0.247438867 container exec
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853
(image=docker.io/library/fedora:30, name=sad_thompson)
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Successfully started
exec session
6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c014c15054f67c in
container c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=error msg="write unix
/run/podman/io.podman->@: write: broken pipe"
My wild guess is that the client somehow exits before the podman on the
other side of the varlink could reply.
Thanks,
--
Francesco Romani
Senior SW Eng., Virtualization R&D
Red Hat
IRC: fromani github: @fromanirh
10:30 a.m.
On Mon, 2019-10-28 at 15:27 +0100, Francesco Romani wrote:
On 10/28/19 3:23 PM, Brent Baude wrote:
> On Mon, 2019-10-28 at 15:19 +0100, Francesco Romani wrote:
> > On 10/28/19 3:09 PM, Brent Baude wrote:
> > > I'm glad to see that you are going to implement this in a
> > > golang
> > > program. That is how you are going to have to do it. I know
> > > of no
> > > other way.
> > Hey,
> >
> >
> > thanks for your reply. Does this means it could be a podman bug?
> >
> >
> > bests,
> >
> I don't believe so. I am unaware of how to use the generic varlink
> tools to emulate and upgraded connection.
OK, thanks. Any other tips about how I can debug this further?
What I am saying here is that this won't work. You are going to have
to implement this using golang (or python?). Exec requires a special
connection referred to as "upgraded" which I don't believe can be done
with the varlink clients.
These entries in the podman syslog (actually journal, but still)
look
suspicious:
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<nwarn>: stdio_input read failed Input/output error
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<nwarn>: Failed to write to socket
Oct 28 09:21:09 myhost.lan conmon[8106]: conmon c24e28054f89c0a0ac9c
<error>: Unable to send container stderr message to parent Bad file
descriptor
Oct 28 09:21:09 myhost.lan podman[8087]: 2019-10-28
09:21:09.632987596
+0100 CET m=+0.247438867 container exec
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853
(image=docker.io/library/fedora:30, name=sad_thompson)
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=debug msg="Successfully
started
exec session
6a1ccdea916ee245420320fa3ce02ff68ea066b8b6b7ba1534c014c15054f67c in
container
c24e28054f89c0a0ac9c5e3690ab0c5ef5a8b859ed51d032ae38cc618a164853"
Oct 28 09:21:09 myhost.lan podman[8087]:
time="2019-10-28T09:21:09+01:00" level=error msg="write unix
/run/podman/io.podman->@: write: broken pipe"
My wild guess is that the client somehow exits before the podman on
the
other side of the varlink could reply.
Thanks,
1494
days inactive
1494
days old
5 comments
2 participants
participants (2)
-
Brent Baude -
Francesco Romani