[libvirt] Run libvirtd from git: virsh hangs

Thu Apr 5 15:11:44 UTC 2018

> You can enable debugging for virsh too:
>
> LIBVIRT_DEBUG=1 ./tools/virsh list --all
>
> Alternatively, you can run the libvirtd under strace to see if it
> accepts() the connection request. Seems like virsh is trying to connect
> to a different socket than libvirtd is listening to.

I can see the socket being created by libvirtd in /var/run/libvirt/libvirt-sock.

And as i start virsh (the system one) as root, it tries to open a
connection to 'qemu:///system'

Now, i tried to monitor what virsh was trying to do with strace, as
you suggested, using
sudo strace -v -y -yy -s 4096 virsh list --all

connect(5<UNIX:[16655541]>, {sa_family=AF_UNIX,
sun_path="/var/run/libvirt/libvirt-sock"}, 110) = 0
getsockname(5<UNIX:[16655541]>, {sa_family=AF_UNIX}, [128->2]) = 0
futex(0x7f73d0b16108, FUTEX_WAKE_PRIVATE, 2147483647) = 0
fcntl(5<UNIX:[16655541]>, F_GETFD)      = 0
fcntl(5<UNIX:[16655541]>, F_SETFD, FD_CLOEXEC) = 0
fcntl(5<UNIX:[16655541]>, F_GETFL)      = 0x2 (flags O_RDWR)
fcntl(5<UNIX:[16655541]>, F_SETFL, O_RDWR|O_NONBLOCK) = 0
futex(0x7f73d0b16008, FUTEX_WAKE_PRIVATE, 2147483647) = 0
pipe2([6<pipe:[16655542]>, 7<pipe:[16655542]>], O_CLOEXEC) = 0
write(4<pipe:[16655540]>, "\0", 1)      = 1
futex(0x7f73d0b15360, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x7f73d0b160d0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f73d0b16020, FUTEX_WAKE_PRIVATE, 2147483647) = 0
brk(0x562bbbb28000)                     = 0x562bbbb28000
write(4<pipe:[16655540]>, "\0", 1)      = 1
futex(0x7f73d0b15360, FUTEX_WAKE_PRIVATE, 1) = 1
rt_sigprocmask(SIG_BLOCK, [PIPE CHLD WINCH], [], 8) = 0
poll([{fd=5<UNIX:[16655541]>, events=POLLOUT}, {fd=6<pipe:[16655542]>,
events=POLLIN}], 2, -1) = 1 ([{fd=5, revents=POLLOUT}])
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
write(5<UNIX:[16655541]>, "\0\0\0\34
\0\200\206\0\0\0\1\0\0\0B\0\0\0\0\0\0\0\0\0\0\0\0", 28) = 28
brk(0x562bbbb18000)                     = 0x562bbbb18000
rt_sigprocmask(SIG_BLOCK, [PIPE CHLD WINCH], [], 8) = 0
poll([{fd=5<UNIX:[16655541]>, events=POLLIN}, {fd=6<pipe:[16655542]>,
events=POLLIN}], 2, -1

You can see that it successfully connects to the libvirt.sock, and
then it polls on the socket (5).

So i tried to strace libvirtd too:

bind(8<UNIX:[16652236]>, {sa_family=AF_UNIX,
sun_path="/var/run/libvirt/libvirt-sock"}, 110) = 0
umask(022)                              = 077
futex(0x7f537d1138e0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
fcntl(8<UNIX:[16652236,"/var/run/libvirt/libvirt-sock"]>, F_GETFD) = 0
fcntl(8<UNIX:[16652236,"/var/run/libvirt/libvirt-sock"]>, F_SETFD,
FD_CLOEXEC) = 0
fcntl(8<UNIX:[16652236,"/var/run/libvirt/libvirt-sock"]>, F_GETFL) =
0x2 (flags O_RDWR)
fcntl(8<UNIX:[16652236,"/var/run/libvirt/libvirt-sock"]>, F_SETFL,
O_RDWR|O_NONBLOCK) = 0
listen(8<UNIX:[16652236,"/var/run/libvirt/libvirt-sock"]>, 1000) = 0
socket(AF_UNIX, SOCK_STREAM, 0)         = 9<UNIX:[16652238]>
unlink("/var/run/libvirt/libvirt-sock-ro") = -1 ENOENT (No such file
or directory)
umask(0177000)                          = 022
bind(9<UNIX:[16652238]>, {sa_family=AF_UNIX,
sun_path="/var/run/libvirt/libvirt-sock-ro"}, 110) = 0
umask(022)                              = 000
fcntl(9<UNIX:[16652238,"/var/run/libvirt/libvirt-sock-ro"]>, F_GETFD) = 0
fcntl(9<UNIX:[16652238,"/var/run/libvirt/libvirt-sock-ro"]>, F_SETFD,
FD_CLOEXEC) = 0
fcntl(9<UNIX:[16652238,"/var/run/libvirt/libvirt-sock-ro"]>, F_GETFL)
= 0x2 (flags O_RDWR)
fcntl(9<UNIX:[16652238,"/var/run/libvirt/libvirt-sock-ro"]>, F_SETFL,
O_RDWR|O_NONBLOCK) = 0
listen(9<UNIX:[16652238,"/var/run/libvirt/libvirt-sock-ro"]>, 1000) = 0
socket(AF_UNIX, SOCK_STREAM, 0)         = 10<UNIX:[16652240]>
unlink("/var/run/libvirt/libvirt-admin-sock") = -1 ENOENT (No such
file or directory)
umask(0177077)                          = 022
bind(10<UNIX:[16652240]>, {sa_family=AF_UNIX,
sun_path="/var/run/libvirt/libvirt-admin-sock"}, 110) = 0
umask(022)                              = 077
fcntl(10<UNIX:[16652240,"/var/run/libvirt/libvirt-admin-sock"]>, F_GETFD) = 0
fcntl(10<UNIX:[16652240,"/var/run/libvirt/libvirt-admin-sock"]>,
F_SETFD, FD_CLOEXEC) = 0
fcntl(10<UNIX:[16652240,"/var/run/libvirt/libvirt-admin-sock"]>,
F_GETFL) = 0x2 (flags O_RDWR)
fcntl(10<UNIX:[16652240,"/var/run/libvirt/libvirt-admin-sock"]>,
F_SETFL, O_RDWR|O_NONBLOCK) = 0
listen(10<UNIX:[16652240,"/var/run/libvirt/libvirt-admin-sock"]>, 20) = 0
mmap(NULL, 8392704, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7f536bbbf000
mprotect(0x7f536bbbf000, 4096, PROT_NONE) = 0
clone(child_stack=0x7f536c3beeb0,
flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID,
parent_tidptr=0x7f536c3bf9d0, tls=0x7f536c3bf700,
child_tidptr=0x7f536c3bf9d0) = 349
socket(AF_NETLINK, SOCK_RAW|SOCK_CLOEXEC, NETLINK_ROUTE) =
11<NETLINK:[16652242]>
setsockopt(11<NETLINK:[16652242]>, SOL_SOCKET, SO_SNDBUF, [32768], 4) = 0
setsockopt(11<NETLINK:[16652242]>, SOL_SOCKET, SO_RCVBUF, [32768], 4) = 0
getpid()                                = 314
bind(11<NETLINK:[16652242]>, {sa_family=AF_NETLINK, nl_pid=931135802,
nl_groups=00000000}, 12) = 0
getsockname(11<NETLINK:[ROUTE:931135802]>, {sa_family=AF_NETLINK,
nl_pid=931135802, nl_groups=00000000}, [12]) = 0
setsockopt(11<NETLINK:[ROUTE:931135802]>, SOL_SOCKET, SO_SNDBUF, [32768], 4) = 0
setsockopt(11<NETLINK:[ROUTE:931135802]>, SOL_SOCKET, SO_RCVBUF,
[131702], 4) = 0
fcntl(11<NETLINK:[ROUTE:931135802]>, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
socket(AF_NETLINK, SOCK_RAW|SOCK_CLOEXEC, NETLINK_KOBJECT_UEVENT) =
12<NETLINK:[16652243]>
setsockopt(12<NETLINK:[16652243]>, SOL_SOCKET, SO_SNDBUF, [32768], 4) = 0
setsockopt(12<NETLINK:[16652243]>, SOL_SOCKET, SO_RCVBUF, [32768], 4) = 0
getpid()                                = 314
bind(12<NETLINK:[16652243]>, {sa_family=AF_NETLINK, nl_pid=1514144058,
nl_groups=00000000}, 12) = 0
getsockname(12<NETLINK:[KOBJECT_UEVENT:1514144058]>,
{sa_family=AF_NETLINK, nl_pid=1514144058, nl_groups=00000000}, [12]) =
0
setsockopt(12<NETLINK:[KOBJECT_UEVENT:1514144058]>, SOL_SOCKET,
SO_SNDBUF, [32768], 4) = 0
setsockopt(12<NETLINK:[KOBJECT_UEVENT:1514144058]>, SOL_SOCKET,
SO_RCVBUF, [131702], 4) = 0
setsockopt(12<NETLINK:[KOBJECT_UEVENT:1514144058]>, SOL_NETLINK, 1, [1], 4) = 0
fcntl(12<NETLINK:[KOBJECT_UEVENT:1514144058]>, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
poll([{fd=4<pipe:[16652234]>, events=POLLIN}, {fd=6<pipe:[16652235]>,
events=POLLIN}, {fd=11<NETLINK:[ROUTE:931135802]>, events=POLLIN},
{fd=12<NETLINK:[KOBJECT_UEVENT:1514144058]>, events=POLLIN}], 4, -1

And it is polling on a pipe ???
Any ideas how to debug this ?

I just want to run my custom libvirtd here, and test an app against
it, nothing special.

How do you guys do this ?

-- 
Mathieu Tarral