Bug 1062340 - virsh dominfo fails with an error when transported from a remote machine through the libvirtd
Summary: virsh dominfo fails with an error when transported from a remote machine thro...
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Red Hat Enterprise Linux 5
Classification: Red Hat
Component: libvirt
Version: 5.6
Hardware: All
OS: Linux
medium
medium
Target Milestone: rc
: ---
Assignee: Libvirt Maintainers
QA Contact: Virtualization Bugs
URL:
Whiteboard:
Depends On: 506688 649438
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-02-06 17:07 UTC by R P Herrold
Modified: 2014-03-27 20:24 UTC (History)
17 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of: 649438
Environment:
Last Closed: 2014-03-27 20:24:18 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description R P Herrold 2014-02-06 17:07:47 UTC
+++ This bug was initially created as a clone of Bug #649438 +++

+++ This bug was initially created as a clone of Bug #506688 +++

Description of problem:

Regression -- The prior bug is back, this time as an error, rather than a warning

---------

we applied the 5.10 updates to a little used xen dom0 yesterday, and we no have a /var/log/messages full of:

Feb  6 11:50:15 xen-n002 libvirtd: 11:50:15.494: error : virLibConnError:462 : this function is not supported by the connection driver: virNodeGetSecurityModel
Feb  6 11:51:23 xen-n002 libvirtd: 11:51:23.852: error : xenUnifiedDomainLookupByName:767 : Domain not found: xenUnifiedDomainLookupByName
Feb  6 11:53:14 xen-n002 libvirtd: 11:53:14.518: error : xenUnifiedDomainLookupByName:767 : Domain not found: xenUnifiedDomainLookupByName
Feb  6 11:55:16 xen-n002 libvirtd: 11:55:16.409: error : virLibConnError:462 : this function is not supported by the connection driver: virNodeGetSecurityModel

local libvirt (the failing one) is: 
[root@xen-n002 ~]# rpm -q libvirt --qf '%{name}.%{arch} \
    %{name}-%{version}%{release} \n'
libvirt.x86_64 libvirt-0.8.2-29.el5_9.1
libvirt.i386 libvirt-0.8.2-29.el5_9.1

remote (provoking) libvirt / virsh is: 
[root@secure ~]# rpm -q libvirt --qf '%{name}.%{arch} \
   %{name}-%{version}-%{release} \n'
libvirt.x86_64 libvirt-0.8.2-29.el5_9.1

Comment 1 R P Herrold 2014-02-06 17:29:05 UTC
Follow-up

As before, if you need additional information, please ask and we will supplement as requested

Client machine details, as nefore:

[root@Follow-up

If you need additional information, please ask and we will supplement as requested

[root@elided ~]# rpm -q xen                                              
xen-3.0.3-142.el5_9.3                                                      
[root@elided ~]# rpm -q libvirt                                          
libvirt-0.8.2-29.el5_9.1
libvirt-0.8.2-29.el5_9.1
[root@xelided ~]# uname -a
Linux elided 2.6.18-371.4.1.el5xen #1 SMP Thu Jan 30 06:58:16 EST 2014 x86_64 x86_64 x86_64 GNU/Linux
[root@elided ~]# rpm -qa kernel\*
kernel-xen-2.6.18-194.17.1.el5
kernel-xen-2.6.18-274.3.1.el5
kernel-xen-2.6.18-308.1.1.el5
kernel-headers-2.6.18-371.4.1.el5
kernel-xen-2.6.18-371.4.1.el5
kernel-xen-2.6.18-194.26.1.el5
[root@elided ~]#

and remote provoking machine

[root@elided2 ~]#  service syslog restart                                   
Shutting down kernel logger:                               [  OK  ]        
Shutting down system logger:                               [  OK  ]        
Starting system logger:                                    [  OK  ]        
Starting kernel logger:                                    [  OK  ]        
[root@elided ~]#   virsh -c xen+ssh://elided.fqdn list              
 Id Name                 State                                             
----------------------------------                                         
  0 Domain-0             running                                           
  1 vm_98526             idle                                              
  2 vm_39052             running                                           
  3 vm_60056             running                                           

[root@elided2 ~]# virsh -c xen+ssh://elided.fqdn dominfo vm_39052   
Id:             2
Name:           vm_39052
UUID:           a33bd231-b9bb-07b7-439a-af69699a9206
OS Type:        linux
State:          running
CPU(s):         1
CPU time:       311.6s
Max memory:     786432 kB
Used memory:    786432 kB
Persistent:     no
Autostart:      disable

[root@elided2 ~]#

[root@elided2 ~]#  service syslog restart                                   
Shutting down kernel logger:                               [  OK  ]        
Shutting down system logger:                               [  OK  ]        
Starting system logger:                                    [  OK  ]        
Starting kernel logger:                                    [  OK  ]        
[root@elided2 ~]#   virsh -c xen+ssh://xen-n002.pmman.com list              
 Id Name                 State                                             
----------------------------------                                         
  0 Domain-0             running                                           
  1 vm_98526             idle                                              
  2 vm_39052             running                                           
  3 vm_60056             running                                           

[root@elided2 ~]# virsh -c xen+ssh://elided.fqdn dominfo vm_39052   
Id:             2
Name:           vm_39052
UUID:           a33bd231-b9bb-07b7-439a-af69699a9206
OS Type:        linux
State:          running
CPU(s):         1
CPU time:       311.6s
Max memory:     786432 kB
Used memory:    786432 kB
Persistent:     no
Autostart:      disable

root@elided2 ~]# ssh -l root elided.fqdn cat /var/log/messages | tail                                                                          
Feb  6 12:15:13 elided libvirtd: 12:15:13.028: error : virXenErrorFunc:840 : invalid argument in xenHypervisorDomainInterfaceStats: invalid path, vif<domid> should match this domain ID                                       
Feb  6 12:15:17 elided libvirtd: 12:15:17.814: error : virLibConnError:462 : this function is not supported by the connection driver: virNodeGetSecurityModel                                                                  
Feb  6 12:17:18 elided lvm[5040]: No longer monitoring snapshot MainGroup-xen_vm_39052_1391706677                                                   
Feb  6 12:17:31 elided kernel: EXT4-fs (dm-19): INFO: recovery required on readonly filesystem                                                      
Feb  6 12:17:31 elided kernel: EXT4-fs (dm-19): write access will be enabled during recovery                                                        
Feb  6 12:17:32 elided kernel: EXT4-fs (dm-19): recovery complete
Feb  6 12:17:32 elided kernel: EXT4-fs (dm-19): mounted filesystem with ordered data mode
Feb  6 12:20:18 elided libvirtd: 12:20:18.626: error : virLibConnError:462 : this function is not supported by the connection driver: virNodeGetSecurityModel
Feb  6 12:23:12 elided libvirtd: 12:23:12.470: error : virLibConnError:462 : this function is not supported by the connection driver: virNodeGetSecurityModel
Feb  6 12:24:35 elided libvirtd: 12:24:35.973: error : virLibConnError:462 : this function is not supported by the connection driver: virNodeGetSecurityModel
[root@elided2 ~]#

Comment 2 R P Herrold 2014-02-06 17:29:49 UTC
This seems to be a regression from:
  https://bugzilla.redhat.com/show_bug.cgi?id=649438#c12

Comment 3 RHEL Program Management 2014-03-07 12:41:49 UTC
This bug/component is not included in scope for RHEL-5.11.0 which is the last RHEL5 minor release. This Bugzilla will soon be CLOSED as WONTFIX (at the end of RHEL5.11 development phase (Apr 22, 2014)). Please contact your account manager or support representative in case you need to escalate this bug.

Comment 5 Jiri Denemark 2014-03-27 15:24:15 UTC
I don't believe this is a regression. Libvirt just logs most errors it reports at the time they occur. Only expected errors are not logged at all. The original error was that virsh actually reported the error back to the user. Which is not the case here, virsh dominfo command just works and doesn't report that error anymore.

Comment 6 RHEL Program Management 2014-03-27 15:49:01 UTC
This request was evaluated by Red Hat Product Management for inclusion
in a Red Hat Enterprise Linux release.  Product Management has
requested further review of this request by Red Hat Engineering, for
potential inclusion in a Red Hat Enterprise Linux release for currently
deployed products.  This request is not yet committed for inclusion in
a release.

Comment 7 R P Herrold 2014-03-27 17:12:06 UTC
as to comment #5, as run, the error (actually a warning -- a different matter, however, as it is not disabling) persists.  The message had stopped for a while after a libvirt update, and then returned after a second update.  I don't know how that is anything EXCEPT a loss of functionality

Comment #5 seems speculation rather than testing based

The error, after the recent Gnutls security update has simple moved and is expressed TODAY, on a fully updated setup this:


[root@centos5-64-herc ~]# tail /var/log/messages
Mar 27 13:09:56 centos5-64-herc libvirtd: 13:09:56.381: error : virLibConnError:462 : invalid connection pointer in virDrvSupportsFeature
Mar 27 13:09:56 centos5-64-herc libvirtd: 13:09:56.383: error : qemudClientReadBuf:1662 : gnutls_record_recv: A TLS packet with unexpected length was received.
Mar 27 13:10:06 centos5-64-herc libvirtd: 13:10:06.692: error : virLibConnError:462 : invalid connection pointer in virDrvSupportsFeature
Mar 27 13:10:06 centos5-64-herc libvirtd: 13:10:06.695: error : qemudClientReadBuf:1662 : gnutls_record_recv: A TLS packet with unexpected length was received.
Mar 27 13:10:17 centos5-64-herc libvirtd: 13:10:17.045: error : virLibConnError:462 : invalid connection pointer in virDrvSupportsFeature
Mar 27 13:10:17 centos5-64-herc libvirtd: 13:10:17.048: error : qemudClientReadBuf:1662 : gnutls_record_recv: A TLS packet with unexpected length was received.
Mar 27 13:10:27 centos5-64-herc libvirtd: 13:10:27.344: error : virLibConnError:462 : invalid connection pointer in virDrvSupportsFeature
Mar 27 13:10:27 centos5-64-herc libvirtd: 13:10:27.347: error : qemudClientReadBuf:1662 : gnutls_record_recv: A TLS packet with unexpected length was received.
Mar 27 13:10:37 centos5-64-herc libvirtd: 13:10:37.642: error : virLibConnError:462 : invalid connection pointer in virDrvSupportsFeature
Mar 27 13:10:37 centos5-64-herc libvirtd: 13:10:37.647: error : qemudClientReadBuf:1662 : gnutls_record_recv: A TLS packet with unexpected length was received.
[root@centos5-64-herc ~]#

Comment 8 Jiri Denemark 2014-03-27 20:24:18 UTC
A lot of different things seem to be mixed in this bug report.

1. virsh dominfo reporting "this function is not supported by the connection driver: virNodeGetSecurityModel" error (not its presence in the logs):

This is the original error reported as bug 649438 and it is apparently fixed since virsh does not report any error in comment #1.


2. The presence of the error from case 1 in the logs:

This is supposed to always be logged by libvirtd whenever a libvirt client calls virNodeGetSecurityModel on a connection to xen driver. In fact  the patch for bug 649438 fixed this API to properly log any errors in its execution in addition to fixing virsh not to report an error about unsupported API. At this point, you could have started seeing errors rather than warnings about this in the logs. This was done on purpose, libvirtd logs errors just like any other daemon and their purpose is to give users or admins something to look at when clients stop working as expected. This particular error is considered harmless by the client (virsh) because it knows it calls an API which might not be supported by the connection driver the client is connected to and in such case it just does not provide the information that the API would provide. However, from libvirtd's point of view, calling an unsupported API is not harmless and needs to be logged in case a client does expect it to work. Several specific error types are now (not in RHEL-5 I believe, though) logged in debug level by libvirt because they are not real errors from libvirtd's point of view, but this is not the case.


3. Regression in some errors being logged or not:

The errors are logged when they happen so just because they did not happen in the past (and thus were not logged) seeing them in the logs now does not imply there is a regression anywhere. It does not imply the opposite either, though. For investigating a possible regression we need a set of steps which work as expected with older version of libvirt while they don't work with newer version of libvirt in the same environment, configuration, etc. And we need to know the libvirt version in both cases.


4. Loss of functionality:

One log message more or less has no effect on any functionality. Unless there's a ton of them so that the logs get filled up so fast they consume all disk space. In your case, virsh dominfo command reports everything it should and correctly (at least you didn't complain about it not doing so) there's definitely no loss of functionality here.


5. Various other errors logged by libvirtd:

Each of the errors has its own triggers and libvirtd logs them because it does not consider them harmless. And logging them is a feature rather than a bug. For example the errors from comment #7 show that the communication between libvirtd and the client is seriously broken and that is something to be fixed rather than libvirtd being so brave and telling the admin about the errors instead of silently ignoring them.


All that said, it seems the main thing you are complaining about is any error messages being logged by libvirt through syslog, is that right? If so, nothing is easier than telling libvirt not to do that. You can set log_outputs in /etc/libvirt/libvirtd.conf according to your needs. For example, 

log_outputs="3:file:/var/log/libvirt/libvirtd.log"

tells libvirtd to log warnings and errors to libvirtd.log rather than through syslog. In case you totally hate libvirtd's log messages, just use

log_outputs="1:file:/dev/null"

and you won't ever see them again.


Anyway, RHEL-5 is in a Production Phase 3, which means only severe bugs are fixed and errors logged to /var/log/messages don't seem to fall into that category. Especially when they are supposed to be logged. However, if you disagree, please follow the advice in comment #3 to escalate this bug.


Note You need to log in before you can comment on or make changes to this bug.