Thank you, Rich, This was the issue indeed. export LIBGUESTFS_BACKEND=direct fixed it. The next step I tried was to integrate libguestfs in collectd virt plugin to collect this data automatically. In this case I'm having an unknown error in add_libvirt_dom() (same with add_domain) when it's invoking qemu-img to create overlay image. There is no difference between manual and service execution. I tried setting LIBGUESTFS_BACKEND to direct, libvirt, libvirt:qemu:///session with no success. Also tried using a different tmp dir just in case - nothing. Maybe something is wrong with how collectd runs its plugins (dynamic linking)? Invoking virt-df from collectd's plugin gives the same error message. I tried running the same qemu-img command from collectd and it passes though! Confusing... Do you have any hints what to try? Here is the complete output from collectd: [2018-11-07 12:21:54] plugin_load: plugin "logfile" successfully loaded. [2018-11-07 12:21:54] plugin_load: plugin "syslog" successfully loaded. Before guestfs_create() UID: 0 Effective UID: 0 Before guestfs_set_verbose() Before guestfs_set_trace() Before guestfs_add_domain() libguestfs: trace: add_domain "wer" "readonly:true" libguestfs: opening libvirt handle: URI = NULL, auth = default+wrapper, flags = 0 libguestfs: successfully opened libvirt handle: conn = 0x7f7e70005210 libguestfs: trace: add_libvirt_dom (virDomainPtr)0x7f7e70005fa0 "readonly:true" libguestfs: original domain XML:\n<domain type='kvm' id='9'>\n <name>wer</name>\n <uuid>03fde334-92a5-4e5e-9247-924c9d40230f</uuid>\n <memory unit='KiB'>2097152</memory>\n <currentMemory unit='KiB'>2097152</currentMemory>\n <vcpu placement='static'>1</vcpu>\n <resource>\n <partition>/machine</partition>\n </resource>\n <os>\n <type arch='x86_64' machine='pc-i440fx-2.7'>hvm</type>\n <bootmenu enable='yes'/>\n </os>\n <features>\n <acpi/>\n <apic/>\n <vmport state='off'/>\n </features>\n <cpu mode='custom' match='exact'>\n <model fallback='allow'>Westmere</model>\n </cpu>\n <clock offset='utc'>\n <timer name='rtc' tickpolicy='catchup'/>\n <timer name='pit' tickpolicy='delay'/>\n <timer name='hpet' present='no'/>\n </clock>\n <on_poweroff>destroy</on_poweroff>\n <on_reboot>restart</on_reboot>\n <on_crash>destroy</on_crash>\n <pm>\n <suspend-to-mem enabled='no'/>\n <suspend-to-disk enabled='no'/>\n </pm>\n <devices>\n <emulator>/usr/bin/qemu-kvm</emulator>\n <disk type='file' device='disk'>\n <driver name='qemu' type='qcow2'/>\n <source file='/home/peterd/TVE/wer.qcow2'/>\n <backingStore/>\n <target dev='sda' bus='sata'/>\n <boot order='1'/>\n <alias name='sata0-0-0'/>\n <address type='drive' controller='0' bus='0' target='0' unit='0'/>\n </disk>\n <disk type='file' device='disk'>\n <driver name='qemu' type='qcow2'/>\n <source file='/var/lib/libvirt/images/wer.qcow2'/>\n <backingStore/>\n <target dev='sdb' bus='sata'/>\n <alias name='sata0-0-1'/>\n <address type='drive' controller='0' bus='0' target='0' unit='1'/>\n </disk>\n <disk type='file' device='cdrom'>\n <driver name='qemu' type='raw'/>\n <source file='/home/peterd/boot_new.iso'/>\n <backingStore/>\n <target dev='hda' bus='ide'/>\n <readonly/>\n <boot order='2'/>\n <alias name='ide0-0-0'/>\n <address type='drive' controller='0' bus='0' target='0' unit='0'/>\n </disk>\n <controller type='usb' index='0' model='ich9-ehci1'>\n <alias name='usb'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x7'/>\n </controller>\n <controller type='usb' index='0' model='ich9-uhci1'>\n <alias name='usb'/>\n <master startport='0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x0' multifunction='on'/>\n </controller>\n <controller type='usb' index='0' model='ich9-uhci2'>\n <alias name='usb'/>\n <master startport='2'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x1'/>\n </controller>\n <controller type='usb' index='0' model='ich9-uhci3'>\n <alias name='usb'/>\n <master startport='4'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x2'/>\n </controller>\n <controller type='ide' index='0'>\n <alias name='ide'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x1'/>\n </controller>\n <controller type='sata' index='0'>\n <alias name='sata0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>\n </controller>\n <controller type='virtio-serial' index='0'>\n <alias name='virtio-serial0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x07' function='0x0'/>\n </controller>\n <controller type='scsi' index='0' model='virtio-scsi'>\n <alias name='scsi0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x09' function='0x0'/>\n </controller>\n <controller type='pci' index='0' model='pci-root'>\n <alias name='pci.0'/>\n </controller>\n <interface type='direct'>\n <mac address='52:54:00:2c:7a:bf'/>\n <source dev='macvlan0' mode='bridge'/>\n <target dev='macvtap0'/>\n <model type='e1000'/>\n <alias name='net0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>\n </interface>\n <serial type='pty'>\n <source path='/dev/pts/8'/>\n <target port='0'/>\n <alias name='serial0'/>\n </serial>\n <console type='pty' tty='/dev/pts/8'>\n <source path='/dev/pts/8'/>\n <target type='serial' port='0'/>\n <alias name='serial0'/>\n </console>\n <channel type='spicevmc'>\n <target type='virtio' name='com.redhat.spice.0' state='disconnected'/>\n <alias name='channel0'/>\n <address type='virtio-serial' controller='0' bus='0' port='1'/>\n </channel>\n <input type='mouse' bus='ps2'>\n <alias name='input0'/>\n </input>\n <input type='keyboard' bus='ps2'>\n <alias name='input1'/>\n </input>\n <graphics type='spice' port='5900' autoport='yes' listen='127.0.0.1'>\n <listen type='address' address='127.0.0.1'/>\n <image compression='off'/>\n </graphics>\n <sound model='ich6'>\n <alias name='sound0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>\n </sound>\n <video>\n <model type='qxl' ram='65536' vram='65536' vgamem='16384' heads='1' primary='yes'/>\n <alias name='video0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>\n </video>\n <redirdev bus='usb' type='spicevmc'>\n <alias name='redir0'/>\n <address type='usb' bus='0' port='1'/>\n </redirdev>\n <redirdev bus='usb' type='spicevmc'>\n <alias name='redir1'/>\n <address type='usb' bus='0' port='2'/>\n </redirdev>\n <memballoon model='virtio'>\n <alias name='balloon0'/>\n <address type='pci' domain='0x0000' bus='0x00' slot='0x08' function='0x0'/>\n </memballoon>\n </devices>\n <seclabel type='none' model='none'/>\n <seclabel type='dynamic' model='dac' relabel='yes'>\n <label>+0:+0</label>\n <imagelabel>+0:+0</imagelabel>\n </seclabel>\n</domain>\n libguestfs: trace: clear_backend_setting "internal_libvirt_norelabel_disks" libguestfs: trace: clear_backend_setting = 0 libguestfs: disk[0]: filename: /home/peterd/TVE/wer.qcow2 libguestfs: trace: add_drive "/home/peterd/TVE/wer.qcow2" "readonly:true" "format:qcow2" libguestfs: creating COW overlay to protect original drive content libguestfs: trace: get_tmpdir libguestfs: trace: get_tmpdir = "/tmp" libguestfs: trace: disk_create "/tmp/libguestfsUIZbDK/overlay1.qcow2" "qcow2" -1 "backingfile:/home/peterd/TVE/wer.qcow2" "backingformat:qcow2" libguestfs: command: run: qemu-img libguestfs: command: run: \ create libguestfs: command: run: \ -f qcow2 libguestfs: command: run: \ -o backing_file=/home/peterd/TVE/wer.qcow2,backing_fmt=qcow2 libguestfs: command: run: \ /tmp/libguestfsUIZbDK/overlay1.qcow2 Formatting '/tmp/libguestfsUIZbDK/overlay1.qcow2', fmt=qcow2 size=107374182400 backing_file=/home/peterd/TVE/wer.qcow2 backing_fmt=qcow2 encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16 libguestfs: error: command: waitpid: No child processes libguestfs: error: qemu-img: /tmp/libguestfsUIZbDK/overlay1.qcow2: qemu-img exited for an unknown reason (status -1), see debug messages above libguestfs: trace: disk_create = -1 (error) libguestfs: trace: add_drive = -1 (error) libguestfs: trace: add_libvirt_dom = -1 (error) libguestfs: trace: add_domain = -1 (error) libguestfs: trace: close libguestfs: closing guestfs handle 0x7f7e700049f0 (state 0) libguestfs: command: run: rm libguestfs: command: run: \ -rf /tmp/libguestfsUIZbDK libguestfs: error: command: waitpid: No child processes Best Regards, Peter On Fri, Nov 2, 2018 at 9:48 PM Richard W.M. Jones <rjones@redhat.com> wrote:

...

Hello,

I have a simple C program that uses libguestfs to extract info about disk usage from a libvirt domain. It works when ran manually as root, but fails when started as a systemd service.

I'm attaching the service file, source code and verbose logs from both

On Fri, Nov 02, 2018 at 06:04:08PM +0200, Peter Dimitrov wrote: the

...

successful manual run and from the service journal.

SELinix is disabled.

Error messages: libguestfs: set_socket_create_context: getcon failed: (none): Invalid argument [you can ignore this message if you are not using SELinux + sVirt] libguestfs: clear_socket_create_context: setsockcreatecon failed: NULL: Invalid argument [you can ignore this message if you are not using SELinux + sVirt] libguestfs: error: chown: /tmp/libguestfsvMMaec/guestfsd.sock: Operation not permitted libguestfs: clear_socket_create_context: setsockcreatecon failed: NULL: Invalid argument [you can ignore this message if you are not using SELinux + sVirt] libguestfs: trace: launch = -1 (error) failed to launch domain: Invalid argument

I cannot see what the problem is immediately, but I guess that systemd is confining the service in such a way that libvirt has problems.

Firstly I would try using the direct backend:

export LIBGUESTFS_BACKEND=direct

If it's still not fixed, then it's something to do with systemd confining affecting qemu.

If that fixes it, then it's a problem with libvirt, and you will need to find the libvirt log file. Usually that's in /var/log/libvirt/qemu/guestfs-*.log or in $HOME/.cache/libvirt/qemu/log/guestfs-*.log But I've no idea where it will end up when you're running everything under systemd.

Rich.

-- Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones Read my programming and virtualization blog: http://rwmj.wordpress.com virt-p2v converts physical machines to virtual machines. Boot with a live CD or over the network (PXE) and turn machines into KVM guests. http://libguestfs.org/virt-v2v

That makes no sense because we are supposed to have just forked successfully

I just realized libguestfs uses fork. Now we know why qemu-img worked - I launched it with popen.

So it must be something to do with collectd and how it runs programs. Is it using LD_PRELOAD trickery, or replacing libc, or using seccomp?

If I understand the question correctly - it's about how collectd loads its plugins? If so it uses: static int plugin_load_file(const char *file, _Bool global) { void (*reg_handle)(void); int flags = RTLD_NOW; if (global) flags |= RTLD_GLOBAL; void *dlh = *dlopen*(file, flags); //... reg_handle = (void (*)(void))*dlsym*(dlh, "module_register"); //... *(*reg_handle)();* } Does this give any clues? Best Regards, Peter On Wed, Nov 7, 2018 at 12:56 PM Richard W.M. Jones <rjones@redhat.com> wrote:

On Wed, Nov 07, 2018 at 12:32:48PM +0200, Peter Dimitrov wrote:

...

Thank you, Rich, This was the issue indeed. export LIBGUESTFS_BACKEND=direct fixed it.

The next step I tried was to integrate libguestfs in collectd virt plugin to collect this data automatically. In this case I'm having an unknown error in add_libvirt_dom() (same with add_domain) when it's invoking qemu-img to create overlay image.

There is no difference between manual and service execution. I tried setting LIBGUESTFS_BACKEND to direct, libvirt, libvirt:qemu:///session with no success. Also tried using a different tmp dir just in case - nothing.

Maybe something is wrong with how collectd runs its plugins (dynamic linking)? Invoking virt-df from collectd's plugin gives the same error message. I tried running the same qemu-img command from collectd and it passes though! Confusing...

The log indicates something a bit strange is going on:

...

libguestfs: command: run: qemu-img libguestfs: command: run: \ create libguestfs: command: run: \ -f qcow2 libguestfs: command: run: \ -o backing_file=/home/peterd/TVE/wer.qcow2,backing_fmt=qcow2 libguestfs: command: run: \ /tmp/libguestfsUIZbDK/overlay1.qcow2 Formatting '/tmp/libguestfsUIZbDK/overlay1.qcow2', fmt=qcow2 size=107374182400 backing_file=/home/peterd/TVE/wer.qcow2 backing_fmt=qcow2 encryption=off cluster_size=65536 lazy_refcounts=off refcount_bits=16 libguestfs: error: command: waitpid: No child processes libguestfs: error: qemu-img: /tmp/libguestfsUIZbDK/overlay1.qcow2: qemu-img exited for an unknown reason (status -1), see debug messages above

Obviously waitpid(2) is failing with ECHILD here:

https://github.com/libguestfs/libguestfs/blob/3430c2dd654b19a55d213a9302ac5e...

That makes no sense because we are supposed to have just forked successfully:

https://github.com/libguestfs/libguestfs/blob/3430c2dd654b19a55d213a9302ac5e...

called from:

https://github.com/libguestfs/libguestfs/blob/3430c2dd654b19a55d213a9302ac5e...

Notice also that qemu-img *does* run (you can see the output from the command).

So it must be something to do with collectd and how it runs programs. Is it using LD_PRELOAD trickery, or replacing libc, or using seccomp? My guess is that any program which launched a subprocess and then waited for it would fail in the same way.

Rich.

-- Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones Read my programming and virtualization blog: http://rwmj.wordpress.com virt-df lists disk usage of guests without needing to install any software inside the virtual machine. Supports Linux and Windows. http://people.redhat.com/~rjones/virt-df/

Here are strace outputs per process. strace_output.22076 is the plugin's pid. (A little before forking) strace_output.22077 runs qemu-img strace_output.22078 is a mystery to me strace_output.22079 is rm -rf to the overlay image and its temporary dir. Best Regards, Peter On Wed, Nov 7, 2018 at 4:38 PM Richard W.M. Jones <rjones@redhat.com> wrote:

On Wed, Nov 07, 2018 at 01:37:03PM +0200, Peter Dimitrov wrote:

...

...

That makes no sense because we are supposed to have just forked successfully

I just realized libguestfs uses fork. Now we know why qemu-img worked - I launched it with popen.

...

So it must be something to do with collectd and how it runs programs. Is it using LD_PRELOAD trickery, or replacing libc, or using seccomp?

If I understand the question correctly - it's about how collectd loads its plugins? If so it uses:

static int plugin_load_file(const char *file, _Bool global) { void (*reg_handle)(void); int flags = RTLD_NOW; if (global) flags |= RTLD_GLOBAL; void *dlh = *dlopen*(file, flags); //... reg_handle = (void (*)(void))*dlsym*(dlh, "module_register"); //... *(*reg_handle)();* }

Does this give any clues?

Can you strace the collectd process around the point where qemu-img is run? It may gives some clues.

Rich.

-- Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones Read my programming and virtualization blog: http://rwmj.wordpress.com libguestfs lets you edit virtual machines. Supports shell scripting, bindings from many languages. http://libguestfs.org

Confirming that: signal (SIGCHLD, SIG_DFL); works. Thank you, Rich! Best Regards, Peter On Thu, Nov 8, 2018 at 5:07 PM Richard W.M. Jones <rjones@redhat.com> wrote:

On Thu, Nov 08, 2018 at 04:51:31PM +0200, Peter Dimitrov wrote:

...

Here are strace outputs per process.

strace_output.22076 is the plugin's pid. (A little before forking)

Ah ha.

Close reading of the waitpid(2) man page says:

ECHILD (for waitpid() or waitid()) The process specified by pid (wait‐ pid()) or idtype and id (waitid()) does not exist or is not a child of the calling process. (This can happen for one's own child if the action for SIGCHLD is set to SIG_IGN. See also the Linux Notes section about threads.)

I'm going to guess that collectd is leaking the signal handler setting into the child process instead of resetting it. This is a bug in collectd.

It's surprisingly hard to correctly fork a process in Unix. Here's what libvirt does, which is the most comprehensive code that I know of. It involves resetting multiple things before running the child:

https://libvirt.org/git/?p=libvirt.git;a=blob;f=src/util/vircommand.c;h=de93...

While you're getting the collectd bug fixed, the easiest workaround is probably to add:

signal (SIGCHLD, SIG_DFL);

in your code.

Rich.

-- Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones Read my programming and virtualization blog: http://rwmj.wordpress.com virt-top is 'top' for virtual machines. Tiny program with many powerful monitoring features, net stats, disk stats, logging, etc. http://people.redhat.com/~rjones/virt-top