On Thu, May 02, 2019 at 11:22:39AM +0200, Lothar Schilling wrote: > Hi everybody, > > I've set up an new CentOS 7.6.1810 server. Then, via yum I installed > qemu-kvm libvirt libvirt-python libguestfs-tools virt-install. There > were no problems. But when I try to > > systemctl start libvirtd > > I get the following message: > > "libvirtd: process 472: arguments to dbus_message_iter_append_basic() > were incorrect, assertion "_dbus_check_is_valid_utf8 (*string_p)" failed > in file ../../dbus/dbus-message.c line 2754." > Firstly I would make sure that all the packages are up to date.  I'm not sure what the relevant versions are on CentOS 7.6.1810, so saying what versio you have installed might help later.

This message actually doesn't look like it comes from libvirt.  Are there few more lines in a log somewhere? > Starting libvirtd manually just by issuing the command "libvirtd" > without any further arguments is working, though. > As root?  This would also make sense if the communication that fails with the above error is happening between libvirtd and systemd (when the daemon is started by systemd). > I do not have the slightest idea what is going on, especially as I > didn't change anything about the config files. > I'm not really sure what the daemon is supposed to tell systemd apart sd_notify() when it is starting.  Maybe it is some value from the environment that we're sending and the error originates there, actually.  Like the hostname or something similar.  Again, having more logs would help as I too don't really know what is going on in there. > Any help would be appreciated, thank you > > Lothar Schilling > > _______________________________________________ > libvirt-users mailing list > libvirt-users(a)redhat.com > https://www.redhat.com/mailman/listinfo/libvirt-users

On 5/2/19 12:08 PM, Lothar Schilling wrote: > I turned logging up to maximum. That's all I get: > > May  2 11:02:06 hl308-3 systemd: Starting Virtualization daemon... > May  2 11:02:06 hl308-3 libvirtd: 472: info : libvirt version: 4.5.0, package: 10.el7_6.7 (CentOS BuildSystem <http://bugs.centos.org>;, 2019-04-24-14:04:12, x86-01.bsys.centos.org) > May  2 11:02:06 hl308-3 libvirtd: 472: info : hostname: my.server.net > May  2 11:02:06 hl308-3 libvirtd: 472: info : virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=1 fd=6 events=1 cb=0x7eff3bbde300 opaque=(nil) ff=(nil) > May  2 11:02:06 hl308-3 libvirtd: 472: info : virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=2 fd=8 events=1 cb=0x7eff3bd06760 opaque=0x558f9db485a0 ff=(nil) > May  2 11:02:06 hl308-3 systemd: Started Virtualization daemon. > May  2 11:02:06 hl308-3 libvirtd: 472: info : virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=3 fd=11 events=0 cb=0x7eff3bcfb420 opaque=0x558f9db69520 ff=0x7eff3bcfb3d0 > May  2 11:02:06 hl308-3 libvirtd: 472: info : virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=4 fd=12 events=0 cb=0x7eff3bcfb420 opaque=0x558f9db69700 ff=0x7eff3bcfb3d0 > May  2 11:02:06 hl308-3 libvirtd: process 472: arguments to dbus_message_iter_append_basic() were incorrect, assertion "_dbus_check_is_valid_utf8 (*string_p)" failed in file ../../dbus/dbus-message.c line 2754. > May  2 11:02:06 hl308-3 libvirtd: This is normally a bug in some application using the D-Bus library. > May  2 11:02:06 hl308-3 libvirtd: D-Bus not built with -rdynamic so unable to print a backtrace > May  2 11:02:06 hl308-3 systemd: libvirtd.service: main process exited, code=killed, status=6/ABRT This is not the maximum loggin. We'll need to see debug logs: https://wiki.libvirt.org/page/DebugLogs and perhaps running libvirtd under gdb and getting a stack trace (with all strings expanded) might help too.

On Thu, May 02, 2019 at 02:25:28PM +0200, Martin Kletzander wrote: > On Thu, May 02, 2019 at 01:07:32PM +0200, Michal Privoznik wrote: >> On 5/2/19 12:08 PM, Lothar Schilling wrote: >> >>> I turned logging up to maximum. That's all I get: >>> >>> May  2 11:02:06 hl308-3 systemd: Starting Virtualization daemon... >>> May  2 11:02:06 hl308-3 libvirtd: 472: info : libvirt version: >>> 4.5.0, package: 10.el7_6.7 (CentOS BuildSystem >>> <http://bugs.centos.org>;, 2019-04-24-14:04:12, x86-01.bsys.centos.org) >>> May  2 11:02:06 hl308-3 libvirtd: 472: info : hostname: my.server.net >>> May  2 11:02:06 hl308-3 libvirtd: 472: info : >>> virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=1 fd=6 >>> events=1 cb=0x7eff3bbde300 opaque=(nil) ff=(nil) >>> May  2 11:02:06 hl308-3 libvirtd: 472: info : >>> virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=2 fd=8 >>> events=1 cb=0x7eff3bd06760 opaque=0x558f9db485a0 ff=(nil) >>> May  2 11:02:06 hl308-3 systemd: Started Virtualization daemon. >>> May  2 11:02:06 hl308-3 libvirtd: 472: info : >>> virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=3 fd=11 >>> events=0 cb=0x7eff3bcfb420 opaque=0x558f9db69520 ff=0x7eff3bcfb3d0 >>> May  2 11:02:06 hl308-3 libvirtd: 472: info : >>> virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=4 fd=12 >>> events=0 cb=0x7eff3bcfb420 opaque=0x558f9db69700 ff=0x7eff3bcfb3d0 >>> May  2 11:02:06 hl308-3 libvirtd: process 472: arguments to >>> dbus_message_iter_append_basic() were incorrect, assertion >>> "_dbus_check_is_valid_utf8 (*string_p)" failed in file >>> ../../dbus/dbus-message.c line 2754. >>> May  2 11:02:06 hl308-3 libvirtd: This is normally a bug in some >>> application using the D-Bus library. >>> May  2 11:02:06 hl308-3 libvirtd: D-Bus not built with -rdynamic so >>> unable to print a backtrace >>> May  2 11:02:06 hl308-3 systemd: libvirtd.service: main process >>> exited, code=killed, status=6/ABRT >> >> This is not the maximum loggin. We'll need to see debug logs: >> >> https://wiki.libvirt.org/page/DebugLogs >> >> and perhaps running libvirtd under gdb and getting a stack trace (with >> all strings expanded) might help too. >> > > Actually gdb might be the only help here.  The reason is that that > dbus call > just reports the error and then calls abort(), so libvirtd will not > even get an > error message (which would help us track down what might've been the > case). > > If you can do something like: > Even better, there are some ways to get the core dump information which I completely forgot about: - coredumpctl -- IIRC you are running CentOS 7, so this will not be available                  for you yet.  If it was, coredumpctl show just shows all we                  need (by default it picks the last core dump and stacktrace is                  part of the output). - abrt-cli -- Similar to the above, it should be available for you, but you               need to have abrt installed and setup.  Which is not always the               default.  If you do, or you set it up yourself, however, you               should be able to get to the core dump as well, but it is not as               easy as with coredumpctl (i.e. I did not get to it in first 10               seconds). - Setup your own -- either set the ulimit for the service and look for the file                     that gets created or set kernel.core_pattern using sysctl                     to a command that gets ran with each core dump (this one                     does not need any ulimit setting, but you need to know what                     to specify there. Please let us know if you got anywhere, I'd like to see what the issue is and how we can fix it. >  $ dnf --enablerepo='*debug*' install libvirt-debuginfo dbus-debuginfo > >  $ cat >/var/lib/libvirt/gdbabortscript <<EOF >  start >  break abort >  commands >  t a a bt full >  end >  continue >  EOF > >  $ cat >/etc/systemd/system/libvirtd.service.d/override.conf <<EOF >  [Service] >  ExecStart= >  ExecStart=gdb --batch -x /var/lib/libvirt/gdbabortscript > /usr/sbin/libvirtd $LIBVIRTD_ARGS >  EOF > >  $ systemctl daemon-reload >  $ restorecon -F /var/lib/libvirt/gdbabortscript > /etc/systemd/system/libvirtd.service.d/override.conf >  $ systemctl restart libvirtd.service > > You should get the full stacktrace of the issue in the output of: > >  journalctl -u libvirtd.service > > and you can post it here so we can find out what's happening. > > HTH, > Martin

Am 03.05.2019 um 16:43 schrieb Martin Kletzander: > On Thu, May 02, 2019 at 02:25:28PM +0200, Martin Kletzander wrote: >> On Thu, May 02, 2019 at 01:07:32PM +0200, Michal Privoznik wrote: >>> On 5/2/19 12:08 PM, Lothar Schilling wrote: >>> >>>> I turned logging up to maximum. That's all I get: >>>> >>>> May  2 11:02:06 hl308-3 systemd: Starting Virtualization daemon... >>>> May  2 11:02:06 hl308-3 libvirtd: 472: info : libvirt version: >>>> 4.5.0, package: 10.el7_6.7 (CentOS BuildSystem >>>> <http://bugs.centos.org>;, 2019-04-24-14:04:12, x86-01.bsys.centos.org) >>>> May  2 11:02:06 hl308-3 libvirtd: 472: info : hostname: my.server.net >>>> May  2 11:02:06 hl308-3 libvirtd: 472: info : >>>> virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=1 fd=6 >>>> events=1 cb=0x7eff3bbde300 opaque=(nil) ff=(nil) >>>> May  2 11:02:06 hl308-3 libvirtd: 472: info : >>>> virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=2 fd=8 >>>> events=1 cb=0x7eff3bd06760 opaque=0x558f9db485a0 ff=(nil) >>>> May  2 11:02:06 hl308-3 systemd: Started Virtualization daemon. >>>> May  2 11:02:06 hl308-3 libvirtd: 472: info : >>>> virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=3 fd=11 >>>> events=0 cb=0x7eff3bcfb420 opaque=0x558f9db69520 ff=0x7eff3bcfb3d0 >>>> May  2 11:02:06 hl308-3 libvirtd: 472: info : >>>> virEventPollAddHandle:140 : EVENT_POLL_ADD_HANDLE: watch=4 fd=12 >>>> events=0 cb=0x7eff3bcfb420 opaque=0x558f9db69700 ff=0x7eff3bcfb3d0 >>>> May  2 11:02:06 hl308-3 libvirtd: process 472: arguments to >>>> dbus_message_iter_append_basic() were incorrect, assertion >>>> "_dbus_check_is_valid_utf8 (*string_p)" failed in file >>>> ../../dbus/dbus-message.c line 2754. >>>> May  2 11:02:06 hl308-3 libvirtd: This is normally a bug in some >>>> application using the D-Bus library. >>>> May  2 11:02:06 hl308-3 libvirtd: D-Bus not built with -rdynamic so >>>> unable to print a backtrace >>>> May  2 11:02:06 hl308-3 systemd: libvirtd.service: main process >>>> exited, code=killed, status=6/ABRT >>> This is not the maximum loggin. We'll need to see debug logs: >>> >>> https://wiki.libvirt.org/page/DebugLogs >>> >>> and perhaps running libvirtd under gdb and getting a stack trace (with >>> all strings expanded) might help too. >>> >> Actually gdb might be the only help here.  The reason is that that >> dbus call >> just reports the error and then calls abort(), so libvirtd will not >> even get an >> error message (which would help us track down what might've been the >> case). >> >> If you can do something like: >> > Even better, there are some ways to get the core dump information which I > completely forgot about: > > - coredumpctl -- IIRC you are running CentOS 7, so this will not be > available >                  for you yet.  If it was, coredumpctl show just shows > all we >                  need (by default it picks the last core dump and > stacktrace is >                  part of the output). > > - abrt-cli -- Similar to the above, it should be available for you, > but you >               need to have abrt installed and setup.  Which is not > always the >               default.  If you do, or you set it up yourself, however, > you >               should be able to get to the core dump as well, but it > is not as >               easy as with coredumpctl (i.e. I did not get to it in > first 10 >               seconds). > > - Setup your own -- either set the ulimit for the service and look for > the file >                     that gets created or set kernel.core_pattern using > sysctl >                     to a command that gets ran with each core dump > (this one >                     does not need any ulimit setting, but you need to > know what >                     to specify there. > > Please let us know if you got anywhere, I'd like to see what the issue > is and > how we can fix it. > >>  $ dnf --enablerepo='*debug*' install libvirt-debuginfo dbus-debuginfo >> >>  $ cat >/var/lib/libvirt/gdbabortscript <<EOF >>  start >>  break abort >>  commands >>  t a a bt full >>  end >>  continue >>  EOF >> >>  $ cat >/etc/systemd/system/libvirtd.service.d/override.conf <<EOF >>  [Service] >>  ExecStart= >>  ExecStart=gdb --batch -x /var/lib/libvirt/gdbabortscript >> /usr/sbin/libvirtd $LIBVIRTD_ARGS >>  EOF >> >>  $ systemctl daemon-reload >>  $ restorecon -F /var/lib/libvirt/gdbabortscript >> /etc/systemd/system/libvirtd.service.d/override.conf >>  $ systemctl restart libvirtd.service >> >> You should get the full stacktrace of the issue in the output of: >> >>  journalctl -u libvirtd.service >> >> and you can post it here so we can find out what's happening. >> >> HTH, >> Martin Hi Martin, I set up the machine from scratch and now I#m back to where I started from... Following your instructions I ran journalctl -u libvirtd.service. The output is attached. Thank you Lothar