LinuxQuestions.org

LinuxQuestions.org (/questions/)
-   Linux - Virtualization and Cloud (https://www.linuxquestions.org/questions/linux-virtualization-and-cloud-90/)
-   -   Fedora 31 Upgrade "broke" libvirtd (https://www.linuxquestions.org/questions/linux-virtualization-and-cloud-90/fedora-31-upgrade-broke-libvirtd-4175664426/)

rainman715 11-17-2019 10:19 AM
Fedora 31 Upgrade "broke" libvirtd
 
Hello,

I just upgraded from Fedora 30 to 31, and now the libvirtd service will not stay active; it dies exactly two minutes after starting. The service does not have an error message. I enabled debug for libvirtd, but I do not understand the information coming back. Unfortunately, the file is too big to upload. Happy to break it up if it helps me resolve this.

Below is the status from libvirtd after it dies.

Code:
systemctl status libvirtd
● libvirtd.service - Virtualization daemon
  Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled)
  Active: inactive (dead) since Sun 2019-11-17 10:37:00 EST; 4min 3s ago
    Docs: man:libvirtd(8)
          https://libvirt.org
  Process: 1984 ExecStart=/usr/sbin/libvirtd $LIBVIRTD_ARGS (code=exited, status=0/SUCCESS)
 Main PID: 1984 (code=exited, status=0/SUCCESS)
      CPU: 195ms

Nov 17 10:35:00 ########## systemd[1]: Starting Virtualization daemon...
Nov 17 10:35:00 ########## libvirtd[1984]: 2019-11-17 15:35:00.695+0000: 1984: info : libvirt version: 5.6.0, package: 5.fc31 (Fedora Project, 2019-11-11-2>
Nov 17 10:35:00 ########## libvirtd[1984]: 2019-11-17 15:35:00.695+0000: 1984: info : hostname: ##########
Nov 17 10:35:00 ########## libvirtd[1984]: 2019-11-17 15:35:00.695+0000: 1984: debug : virLogParseOutputs:1765 : outputs=1:file:/var/log/libvirt/libvirtd.l>
Nov 17 10:35:00 ########## libvirtd[1984]: 2019-11-17 15:35:00.695+0000: 1984: debug : virLogParseOutput:1593 : output=1:file:/var/log/libvirt/libvirtd.log
Nov 17 10:35:00 ########## systemd[1]: Started Virtualization daemon.
Nov 17 10:35:00 ########## dnsmasq[1311]: read /etc/hosts - 2 addresses
Nov 17 10:35:00 ########## dnsmasq[1311]: read /var/lib/libvirt/dnsmasq/default.addnhosts - 0 addresses
Nov 17 10:35:00 ########## dnsmasq-dhcp[1311]: read /var/lib/libvirt/dnsmasq/default.hostsfile
Nov 17 10:37:00 ########## systemd[1]: libvirtd.service: Succeeded.
I'm not sure what else to check, please help.

Thanks
Ray

Ser Olmy 11-17-2019 11:08 AM
You could try running libvirtd manually in a terminal (sudo libvirtd) and see what messages appear at the console.

rainman715 11-17-2019 11:15 AM
Quote:
Originally Posted by Ser Olmy (Post 6058906)
You could try running libvirtd manually in a terminal (sudo libvirtd) and see what messages appear at the console.
Thanks Ser Olmy, however this doesn't seem to work either. All I get is the following:

Code:
2019-11-17 17:13:46.224+0000: 2935: info : libvirt version: 5.6.0, package: 5.fc31 (Fedora Project, 2019-11-11-20:24:00, )
2019-11-17 17:13:46.224+0000: 2935: info : hostname: shenron.DBZ
2019-11-17 17:13:46.224+0000: 2935: debug : virLogParseOutputs:1765 : outputs=1:file:/var/log/libvirt/libvirtd.log
2019-11-17 17:13:46.224+0000: 2935: debug : virLogParseOutput:1593 : output=1:file:/var/log/libvirt/libvirtd.log
It stays past the two minutes, but I cannot connect to the hypervisor. Are there any other logs etc. I can check?

Ser Olmy 11-17-2019 11:25 AM
Quote:
Originally Posted by rainman715 (Post 6058910)
It stays past the two minutes, but I cannot connect to the hypervisor.
What do you mean by that? Does virsh list fail, and if so, what's the exact error message?
Quote:
Originally Posted by rainman715 (Post 6058910)
Are there any other logs etc. I can check?
Well, there's:
Quote:
Originally Posted by rainman715 (Post 6058910)
Code:
2019-11-17 17:13:46.224+0000: 2935: info : libvirt version: 5.6.0, package: 5.fc31 (Fedora Project, 2019-11-11-20:24:00, )
2019-11-17 17:13:46.224+0000: 2935: info : hostname: shenron.DBZ
2019-11-17 17:13:46.224+0000: 2935: debug : virLogParseOutputs:1765 : outputs=1:file:/var/log/libvirt/libvirtd.log
2019-11-17 17:13:46.224+0000: 2935: debug : virLogParseOutput:1593 : output=1:file:/var/log/libvirt/libvirtd.log
Delete/empty the log before running libvirtd and post the results. If the log is too big to post, use pastebin or something similar and post a link.

rainman715 11-17-2019 12:17 PM
Quote:
Originally Posted by Ser Olmy (Post 6058918)
What do you mean by that? Does virsh list fail, and if so, what's the exact error message?
virsh list returns an empty list. I also tried to create a new domain to see if I just lost configs, but receive the following:

Code:
sudo virt-install --name guest1-rhel7 --memory 2048 --vcpus 2 --disk path=/vms/os//myRHELVM1.img,bus=virtio,size=8 --network=bridge:br0 --pxe --os-variant rhel7.0
WARNING  Unable to connect to graphical console: virt-viewer not installed. Please install the 'virt-viewer' package.
WARNING  No console to launch for the guest, defaulting to --wait -1

Starting install...
Allocating 'myRHELVM1.img'                                                                                                                    | 8.0 GB  00:00:00   
ERROR    can't connect to virtlogd: Cannot recv data: Connection reset by peer
Removing disk 'myRHELVM1.img'                                                                                                                  |    0 B  00:00:00   
Domain installation does not appear to have been successful.
If it was, you can restart your domain by running:
  virsh --connect qemu:///system start guest1-rhel7
otherwise, please restart your installation.
virtlogd was not running, but even after starting it I received the same message as above. Also, the console generated the following:
Code:
libvirtd -v
2019-11-17 17:49:10.331+0000: 3283: info : libvirt version: 5.6.0, package: 5.fc31 (Fedora Project, 2019-11-11-20:24:00, )
2019-11-17 17:49:10.331+0000: 3283: info : hostname: #########
2019-11-17 17:49:10.331+0000: 3283: debug : virLogParseOutputs:1765 : outputs=1:file:/var/log/libvirt/libvirtd.log
2019-11-17 17:49:10.331+0000: 3283: debug : virLogParseOutput:1593 : output=1:file:/var/log/libvirt/libvirtd.log
2019-11-17 17:49:17.445+0000: 3370: info : virSecuritySELinuxSetFileconImpl:1280 : Setting SELinux context on '/var/lib/libvirt/qemu/domain-1-guest1-rhel7' to 'unconfined_u:object_r:svirt_image_t:s0:c654,c834'
2019-11-17 17:49:17.446+0000: 3371: info : virSecurityDACSetOwnership:799 : Setting DAC user and group on '/var/lib/libvirt/qemu/domain-1-guest1-rhel7' to '107:107'
2019-11-17 17:49:17.447+0000: 3372: info : virSecuritySELinuxSetFileconImpl:1280 : Setting SELinux context on '/var/lib/libvirt/qemu/channel/target/domain-1-guest1-rhel7' to 'unconfined_u:object_r:svirt_image_t:s0:c654,c834'
2019-11-17 17:49:17.448+0000: 3373: info : virSecurityDACSetOwnership:799 : Setting DAC user and group on '/var/lib/libvirt/qemu/channel/target/domain-1-guest1-rhel7' to '107:107'
2019-11-17 17:49:17.449+0000: 3374: info : virSecuritySELinuxSetFileconImpl:1280 : Setting SELinux context on '/var/lib/libvirt/qemu/domain-1-guest1-rhel7/master-key.aes' to 'unconfined_u:object_r:svirt_image_t:s0:c654,c834'
2019-11-17 17:49:17.450+0000: 3375: info : virSecurityDACSetOwnership:799 : Setting DAC user and group on '/var/lib/libvirt/qemu/domain-1-guest1-rhel7/master-key.aes' to '107:107'

Quote:
Originally Posted by Ser Olmy (Post 6058918)
Well, there's:
Delete/empty the log before running libvirtd and post the results. If the log is too big to post, use pastebin or something similar and post a link.
I wasn't sure if you wanted the log from trying to start the service or from running it manually, so I included both. Both are broken into two postings because they exceeded the limit on pastebin.

Attempting to start the service:
https://pastebin.com/SG3sGVLA
https://pastebin.com/72KXFVe1

Running libvirtd manuall and trying to create a new domain:
https://pastebin.com/iedPhWa4
https://pastebin.com/kqsyPRDr

Really appreciate your help with this.

Thanks
Ray

Ser Olmy 11-17-2019 12:59 PM
This certainly doesn't look right:
Code:
2019-11-17 18:03:29.291+0000: 3608: info : virNetSocketNew:290 : RPC_SOCKET_NEW: sock=0x7f3cdc026670 fd=34 errfd=-1 pid=0 localAddr=127.0.0.1;0, remoteAddr=127.0.0.1;0
2019-11-17 18:03:29.291+0000: 3608: info : virNetClientNew:322 : RPC_CLIENT_NEW: client=0x7f3cdc027bf0 sock=0x7f3cdc026670
2019-11-17 18:03:29.291+0000: 3608: info : virNetClientSendInternal:2124 : RPC_CLIENT_MSG_TX_QUEUE: client=0x7f3cdc027bf0 len=116 prog=2270401305 vers=1 proc=1 type=0 status=0 serial=0
2019-11-17 18:03:29.291+0000: 3608: error : virNetSocketReadWire:1835 : Cannot recv data: Connection reset by peer
2019-11-17 18:03:29.291+0000: 3608: info : virNetSocketDispose:1357 : RPC_SOCKET_DISPOSE: sock=0x7f3cdc026670
A shot in the dark: Do you have libvirtd-tcp.socket on your system? I'm not too familiar with systemd, but I believe it should reside in /usr/lib/systemd/system.

rainman715 11-17-2019 01:05 PM
Quote:
Originally Posted by Ser Olmy (Post 6058951)
A shot in the dark: Do you have libvirtd-tcp.socket on your system? I'm not too familiar with systemd, but I believe it should reside in /usr/lib/systemd/system.
I do, and it indeed is located in /usr/lib/systemd/system/libvirtd-tcp.socket

If it helps......

Code:
[Unit]
Description=Libvirt non-TLS IP socket
Before=libvirtd.service
BindsTo=libvirtd.socket
After=libvirtd.socket

[Socket]
# This must match the /etc/libvirt/libvirtd.conf tcp_port setting
# when using systemd version < 227
ListenStream=16509
Service=libvirtd.service

[Install]
WantedBy=sockets.target

Ser Olmy 11-17-2019 01:52 PM
That looks about right.

However, there seems be a version conflict between libvirt and its dependencies. From the service startup log:
Code:
2019-11-17 15:44:34.218+0000: 2089: debug : virCommandRun:2506 : Result status 0, stdout: 'Usage: dnsmasq [options]

Valid options are:
<snip>
As you can see, dnsmasq is being called with parameters it doesn't recognize, so it spews out the "usage" help text.

It seems the upgrade process has bungled some packages. I'd try uninstalling and then reinstalling libvirt, dnsmasq and any other dependencies, perhaps even qemu.

rainman715 11-18-2019 07:58 PM
I ended up rebuilding the hypervisor and now all is working as expected.


All times are GMT -5. The time now is 02:56 AM.