[SOLVED] libvirt: libvirtd often takes ~45 seconds to start

atelszewski · 02-02-2017, 07:50 PM

Hi,

libvirt version: 3.0.0.

libvirtd often takes ~45 seconds to start, where normally it should be around 2 seconds (on my machine). It happens very often, but sometimes it starts quickly as it should.

I actually debugged /etc/rc.d/rc.libvirt and know that it hangs here:

Code:

/usr/sbin/libvirtd -d -l $LIBVIRTD_OPTS

I tried disabling network auto-start with no change.
Also, the log does not say much:

Code:

2017-02-03 01:31:09.668+0000: 1277: info : libvirt version: 3.0.0
2017-02-03 01:31:09.668+0000: 1277: info : hostname: andtel.ddns.net
2017-02-03 01:31:09.668+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:09.670+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-alpha: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:09.767+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:09.768+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-cris: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:09.866+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:09.867+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-lm32: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:09.983+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:09.983+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-m68k: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.078+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.078+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-microblaze: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.167+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.167+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-microblazeel: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.281+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.281+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-mips: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.394+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.394+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-mipsel: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.509+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.509+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-mips64: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.625+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.625+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-mips64el: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.714+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.714+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-or32: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.834+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.834+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-sh4: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.942+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:10.942+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-sh4eb: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:11.033+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:11.033+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-sparc: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:11.140+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:11.140+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-sparc64: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:11.229+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:11.229+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-unicore32: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:11.320+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:11.321+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-xtensa: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:11.410+0000: 1277: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:31:11.410+0000: 1277: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-xtensaeb: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:12.885+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:12.885+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-alpha: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:12.964+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:12.964+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-cris: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.044+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.044+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-lm32: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.132+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.132+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-m68k: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.212+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.212+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-microblaze: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.293+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.293+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-microblazeel: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.381+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.381+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-mips: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.467+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.467+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-mipsel: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.557+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.558+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-mips64: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.645+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.646+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-mips64el: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.722+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.722+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-or32: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.816+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.816+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-sh4: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.903+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.903+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-sh4eb: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.980+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:13.980+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-sparc: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:14.066+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:14.067+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-sparc64: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:14.145+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:14.145+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-unicore32: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:14.225+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:14.225+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-xtensa: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:14.302+0000: 1249: error : qemuMonitorJSONCheckError:387 : internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found
2017-02-03 01:32:14.302+0000: 1249: warning : virQEMUCapsLogProbeFailure:4624 : Failed to probe capabilities for /usr/bin/qemu-system-xtensaeb: internal error: unable to execute QEMU command 'query-cpu-definitions': The command query-cpu-definitions has not been found

Running /etc/rc.d/rc.libvirt restart once the system is booted, is fast.
Also, /usr/sbin/libvirtd when run by regular user (i.e. in qemu:///session) starts quickly.

Do you have any ideas?
Thanks in advance!

--
Best regards,
Andrzej Telszewski

atelszewski · 02-02-2017, 08:48 PM

Hi,

I enabled logging with debug level set and something can be observed, but I'm far from knowing what it means ;-)
The logs are ~20M in size, so I post only the part where the problem occurs. Please note the bold font.

When libvirtd hangs:

Code:

(...)
2017-02-03 02:25:44.152+0000: 1253: info : virNetSocketNew:291 : RPC_SOCKET_NEW: sock=0x55ab5b9acdd0 fd=12 errfd=-1 pid=0 localAddr=127.0.0.1;0, remoteAddr=<null>
2017-02-03 02:25:44.152+0000: 1253: info : virObjectRef:296 : OBJECT_REF: obj=0x55ab5b9acad0
2017-02-03 02:25:44.152+0000: 1253: info : virObjectRef:296 : OBJECT_REF: obj=0x55ab5b9acdd0
2017-02-03 02:25:44.152+0000: 1253: debug : virEventPollInterruptLocked:722 : Skip interrupt, 0 0
2017-02-03 02:25:44.152+0000: 1253: info : virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=5 fd=12 events=0 cb=0x7febf52c2a00 opaque=0x55ab5b9acdd0 ff=0x7febf52c29b0
2017-02-03 02:25:44.152+0000: 1253: info : virObjectRef:296 : OBJECT_REF: obj=0x55ab5b9acad0
2017-02-03 02:26:35.083+0000: 1253: info : virObjectNew:202 : OBJECT_NEW: obj=0x55ab5b9aff70 classname=virNetSASLContext
2017-02-03 02:26:35.083+0000: 1253: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x55ab5b9ac340
2017-02-03 02:26:35.083+0000: 1253: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x55ab5b9acad0
2017-02-03 02:26:35.083+0000: 1253: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x55ab5b9aa230
2017-02-03 02:26:35.083+0000: 1253: debug : virFileClose:108 : Closed fd 5
2017-02-03 02:26:35.083+0000: 1253: info : virObjectRef:296 : OBJECT_REF: obj=0x55ab5b9a2200
(...)

You can see there is a gap of ~50 seconds between the logged messages.
And that is more less what I measured with stopwatch.

Now for quickly starting libvirtd:

Code:

2017-02-03 02:23:45.262+0000: 1252: info : virNetSocketNew:291 : RPC_SOCKET_NEW: sock=0x55a4475dfdd0 fd=12 errfd=-1 pid=0 localAddr=127.0.0.1;0, remoteAddr=<null>
2017-02-03 02:23:45.262+0000: 1252: info : virObjectRef:296 : OBJECT_REF: obj=0x55a4475dfad0
2017-02-03 02:23:45.262+0000: 1252: info : virObjectRef:296 : OBJECT_REF: obj=0x55a4475dfdd0
2017-02-03 02:23:45.262+0000: 1252: debug : virEventPollInterruptLocked:722 : Skip interrupt, 0 0
2017-02-03 02:23:45.262+0000: 1252: info : virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=5 fd=12 events=0 cb=0x7f1858a27a00 opaque=0x55a4475dfdd0 ff=0x7f1858a279b0
2017-02-03 02:23:45.262+0000: 1252: info : virObjectRef:296 : OBJECT_REF: obj=0x55a4475dfad0
2017-02-03 02:23:48.444+0000: 1252: info : virObjectNew:202 : OBJECT_NEW: obj=0x55a4475e2f70 classname=virNetSASLContext
2017-02-03 02:23:48.444+0000: 1252: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x55a4475df340
2017-02-03 02:23:48.444+0000: 1252: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x55a4475dfad0
2017-02-03 02:23:48.444+0000: 1252: info : virObjectUnref:259 : OBJECT_UNREF: obj=0x55a4475dcbe0
2017-02-03 02:23:48.444+0000: 1252: debug : virFileClose:108 : Closed fd 5
2017-02-03 02:23:48.444+0000: 1252: info : virObjectRef:296 : OBJECT_REF: obj=0x55a4475d51d0

Here, the gap is much smaller, ~3 seconds only.

--
Best regards,
Andrzej Telszewski

ChuangTzu · 02-02-2017, 08:48 PM

Configuration
Automatic startup

If you want to have the libvirt daemon started automatically, add the following section to /etc/rc.d/rc.local:

# start libvirt
if [ -x /etc/rc.d/rc.libvirt ]; then
/etc/rc.d/rc.libvirt start
fi

Make sure /etc/rc.d/rc.libvirt is executable.

Ref: http://docs.slackware.com/howtos:gen...in:kvm_libvirt

atelszewski · 02-02-2017, 08:53 PM

Hi,

Quote:

Originally Posted by ChuangTzu

Configuration
Automatic startup

If you want to have the libvirt daemon started automatically, add the following section to /etc/rc.d/rc.local:

# start libvirt
if [ -x /etc/rc.d/rc.libvirt ]; then
/etc/rc.d/rc.libvirt start
fi

Make sure /etc/rc.d/rc.libvirt is executable.

Ref: http://docs.slackware.com/howtos:gen...in:kvm_libvirt

I'd say you misunderstood my question (alternatively my wording wasn't precise enough ;-)).
It's about different matter.

--
Best regards,
Andrzej Telszewski

PhilipH · 02-03-2017, 03:59 AM

I had the same, and put this in my rc.local:

Code:

rm /dev/random
ln -s /dev/urandom /dev/random
/etc/rc.d/rc.libvirt start

Although now I realize it's perhaps possible to use the hardware random generator instead...

atelszewski · 02-03-2017, 07:23 AM

Hi,

Would than mean there is not enough entropy?
If so, then I will first try to solve that, maybe I have RNG that I don't know of.

I would prefer not to go with the solution you did.
Although, If my problem is the same as yours, this is really important piece of information.

I'll try it, thanks!

--
Best regards,
Andrzej Telszewski

PhilipH · 02-03-2017, 07:31 AM

Yes, it was a lack of entropy problem. Using strace I found it was waiting on reading /dev/random.
It's worth a try to test if you also have the lack of entropy problem.

I would also prefer not to use this solution, but I haven't found a better one.

Some cpu's have a hardware random generator, however there are some issue with it

BratPit · 02-03-2017, 09:20 AM

If entropy is a problem go to kernel 4.8.

It may be compiled with GCC plagins ported from Grsecurity.

https://lwn.net/Articles/691102/

In

Quote:

/proc/sys/kernel/random/entropy_avail

For my desktop was about 900 bits now with kernel 4.8 is about 4000 bits of entropy.

szboardstretcher · 02-03-2017, 09:23 AM

Look into 'haveged' if you need additional entropy.

Tutorial:
https://www.digitalocean.com/communi...-using-haveged

Homepage:
http://www.issihosts.com/haveged/

atelszewski · 02-04-2017, 11:29 AM

Hi,

@PhilipH Funny, because when I display the available entropy just before libvirtd, it's around ~40 for both situations, i.e. when libvirtd starts quickly or slowly. Still, I think that entropy is the problem and increasing that is the first thing I want to do, not just because of libvirtd's slow startup.

Quote:

Originally Posted by BratPit

If entropy is a problem go to kernel 4.8.

It may be compiled with GCC plagins ported from Grsecurity.

Are GCC plugins and Grsecurity of any relevance here or just 4.8+ kernel?
I'm not entirely sure, but GCC plugins require greater GCC version than I have (gcc-5.3.0) and I don't intend to upgrade GCC now.
I'm now building kernel 4.9, since 4.8 is EOL.

Quote:

Originally Posted by szboardstretcher

Look into 'haveged' if you need additional entropy.

Tutorial:
https://www.digitalocean.com/communi...-using-haveged

Homepage:
http://www.issihosts.com/haveged/

That's an option too.

Anyways, I had an initial look at TPM and rng-tools, it looks like it might work on my system.

--
Best regards,
Andrzej Telszewski

PhilipH · 02-04-2017, 01:29 PM

Well, it's easy enough to test if entropy is the problem.
Put the lines I posted earlier in rc.local and reboot.
If it's fast, it's an lack of entropy problem, if still slow it's something else.
After testing just remove the lines from rc.local and reboot, /dev is a sort of tmpfs and will be rebuild at boot so /dev/urandom will be restored.

If it's not an entropy problem, perhaps it will help to change this line in /etc/rc.d/rc.libvirt:
/usr/sbin/libvirtd -d -l $LIBVIRTD_OPTS
into
strace -f -o /tmp/libvirttrace.log /usr/sbin/libvirtd -d -l $LIBVIRTD_OPTS

BratPit · 02-04-2017, 01:57 PM

Quote:

Originally Posted by atelszewski

Hi,

Are GCC plugins and Grsecurity of any relevance here or just 4.8+ kernel?
I'm not entirely sure, but GCC plugins require greater GCC version than I have (gcc-5.3.0) and I don't intend to upgrade GCC now.
I'm now building kernel 4.9, since 4.8 is EOL.

CONFIG_GCC_PLUGINS option in kernel config. Gcc-5.3.0 is enough.
4.8 has better entropy seen in

Quote:

/proc/sys/kernel/random/entropy_avail

but in 4.9 is better during boot - Latent entropy patch.

I think all is done by ported gcc plugins from Grsecurity team.

atelszewski · 02-04-2017, 03:38 PM

Hi,

In the end, I managed to increase the entropy availability with 4.4.x kernel, rng-tools and TPM.
I had to disable IOMMU, otherwise TPM is not accessible due to some errors.
That's not a big deal, since I don't have any device to pass to virtual machines.
In this setup my entropy is at around 3k bits.

I decided not to go with haveged and RDRAND/RDSEED due to some concerns mentioned elsewhere on the Internet.
I haven't dug deep enough, so I'm not really sure.

One thing I can say about RDRAND/RDSEED is that it looks to be really fast.
It is surely faster than TPM (but TPM seems to be fast enough).

Code:

$ /usr/sbin/rngd -f --no-drng=1
$ dd if=/dev/random of=/dev/null bs=1024 count=4 iflag=fullblock
4+0 records in
4+0 records out
4096 bytes (4.1 kB, 4.0 KiB) copied, 3.28853 s, 1.2 kB/s

Code:

$ /usr/sbin/rngd -f
$ dd if=/dev/random of=/dev/null bs=1024 count=4 iflag=fullblock
4+0 records in
4+0 records out
4096 bytes (4.1 kB, 4.0 KiB) copied, 0.00631868 s, 648 kB/s

--
Best regards,
Andrzej Telszewski

atelszewski · 02-07-2017, 05:02 AM

Hi,

It looks like low entropy availability was the problem of libvirtd slow startup.
Now it starts faster than it ever used to ;-)

@PhilipH Thank you for pointing out this problem.
And, I encourage you to find better entropy source too ;-)

Thanks.

--
Best regards,
Andrzej Telszewski

PhilipH · 02-07-2017, 06:35 AM

Good to hear you have it working !
My work computer seems to have a tpm module also, now I just have to persuade the people who know the bios password to enable it ;-)
Maybe I will just start libvirt in the background, by the time I have logged in and started the virtual machine manager it probably has enough entropy.

btw, today some more fun with libvirt after upgrading it to 3.0.0.
It won't start the vm if the configured disk is a link, for example /dev/vg01/lvname when using lvm or /dev/disk/by-uuid/<uuid>
It just says: error: An error occurred, but the cause is unknown
More info is in the Arch Linux bugreport in case somebody runs into this...