Bug 713286

Summary: virt-manager 0.8.7-2 fills message log VERY fast
Product: Red Hat Enterprise Linux 6 Reporter: Dave Allan <dallan>
Component: netcfAssignee: Laine Stump <laine>
Status: CLOSED ERRATA QA Contact: qe-baseos-daemons
Severity: medium Docs Contact:
Priority: medium    
Version: 6.2CC: berrange, crobinso, dyuan, gren, hbrock, jforbes, jlmagee, john.ellson, laine, lutter, mzhan, niharvey, pierre-bugzilla, rwu, troels, vbian, vinschen, virt-maint, yhuang
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: netcf-0.1.9-1.el6 Doc Type: Bug Fix
Doc Text:
Users had reported many repeated error logs related to certain interfaces. The cause was determined to be that those interfaces had associated config files in /etc/sysconfig/network-scripts, but no corresponding device in the kernel. There are many situations that will result in this situation. For example, if a bridge interface has been ifdowned, it will not exist at all in the kernel, but its config files will stil exist. Another case is an "alias interface" (eg "eth0:1", which is not really an interface on its own, but just an obsolete method of specifying a 2nd (or more) IP address for a single interface. (In the example given, the config files willtalk about the interface "eth0:1", but the kernel only knows about "eth0".) netcf was returning an error status any time it was asked for the current status of an interface it couldn't find in the kernel, so management applications that periodically poll netcf for the status of all system interfaces (e.g. virt-manager) would quickly collect scads of error log messages. The solution is to ignore failure to find an interface in the kernel (which in this situation is really just one more piece of information about the interface's status - the fact that it has a config but doesn't exist in the kernel).
Story Points: ---
Clone Of: 698108 Environment:
Last Closed: 2011-12-06 15:19:12 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 698108    
Bug Blocks:    

Description Dave Allan 2011-06-14 21:11:36 UTC
+++ This bug was initially created as a clone of Bug #698108 +++

Description of problem:

  The latest update to virt-manager, release 0.8.7-2.fc14, introduced some
  problem I didn't have before.  For some reason my message logs are
  filled up with messages like this:

    libvirtd: 13:13:38.083: error : interfaceGetXMLDesc:355 : internal error
    could not get interface XML description (netcf: NETLINK socket operation
    failed - couldn't find ifindex for interface `br0:1`)

  As soon as virt-manager runs, this message fills up the message log
  pretty fast, one message per second.  It does not matter if a virtual
  machine is running at the time.

  Yes, I have an interface br0:1, but it's not used by any of the virtual
  machines and it's not mentioned in any configuration so I have no idea
  why virt-manager is suddenly keen to get hold of the interface.  None of
  the older virt-manager versions I used so far has shown any interest in
  this interface, nor did any of them log such a message.

  I even tried to add this interface to the libvirt configuration, but
  the GUI doesn't accept an interface with a colon in its name.

  So, what I did for now is to downgrade virt-mananger to version
  0.8.5-1.fc14.  This fixes the problem for me.

  However, I would be more confident if I

  1) knew why this message is generated now and
  2) how to avoid it.


Version-Release number of selected component (if applicable):

  0.8.7-2

How reproducible:

  Create an alias interface with seom othe IPv4 address and start
  virt-manager.

Steps to Reproduce:
1.  ifconfig br0:1 192.168.7.7 netmask 255.255.255.0 up
2.  virt-manager
3.  Observe log output
  
Actual results:

  libvirtd: 13:13:38.083: error : interfaceGetXMLDesc:355 : internal error
  could not get interface XML description (netcf: NETLINK socket operation
  failed - couldn't find ifindex for interface `br0:1`)

Expected results:

  Silence

Additional info:

--- Additional comment from berrange on 2011-04-20 06:12:43 EDT ---

This is ultimately an issue at the netcf layer. It is reporting existence of an interface 'br0:1' but is incapable of providing its config.

There are two real issues here

 - It should be more robust and always be able to provide some kind of minimal config for any interface it reports as existing

 - Alias interfaces should not actually be reported at all. These are just a figment of imagination of the legacy net-tools commands, and do not exist for the kernel or iproute tools. They should just appear as additional IPv4 addresses within the main NIC config.

--- Additional comment from crobinso on 2011-04-20 10:16:19 EDT ---

Agreed, trying to work around this in virt-manager would just be a pain. Reassigning to netcf

Laine, any thoughts?

--- Additional comment from crobinso on 2011-04-20 10:17:41 EDT ---

*** Bug 693013 has been marked as a duplicate of this bug. ***

--- Additional comment from laine on 2011-04-24 20:57:45 EDT ---

So the problem is that netcf has a single list of interfaces, and assumes that all of those interfaces will have both config file info, as well as in-kernel info - it is totally reasonable to ask for the "inactive" xml of "br0:1".

I'll need to think about this a bit, but I'm sure we can come up with some solution that makes sense.

What has changed in virt-manager that has made this a problem? Is it now displaying the live status of the interfaces rather than just the static config info?

--- Additional comment from troels on 2011-05-27 04:08:57 EDT ---

The problem exists on RHEL 6.1 (libvirt-0.8.7-18.el6.x86_64, netcf-libs-0.1.7-1.el6.x86_64), as well. And like in the closed bug 693013, it doesn't have to be related to aliased bridge interfaces: As long as there is at least one bridge interface (like "br1") which libvirt doesn't know about, there will be a storm of syslog messages when virt-manager is running.

Should a separate BZ be opened for the RHEL 6.1 case, or is this BZ sufficient?

Comment 2 Laine Stump 2011-06-26 20:09:31 UTC
A fix for this problem has been posted to netcf-devel:

https://fedorahosted.org/pipermail/netcf-devel/2011-June/000579.html

Comment 3 Laine Stump 2011-07-26 16:02:27 UTC
A fix for this bug is included in netcf-0.1.9-1.el6. A build is available here:

https://brewweb.devel.redhat.com/buildinfo?buildID=173822

Comment 5 Vivian Bian 2011-08-04 05:55:06 UTC
tested with 
netcf-0.1.9-1.el6.x86_64
libvirt-0.9.4-1.el6.x86_64
virt-manager-0.9.0-5.el6.x86_64


1.  ifconfig br0:1 192.168.7.7 netmask 255.255.255.0 up
2.  virt-manager
3.  Observe log output

Actual results:
Aug  4 05:41:42 dhcp-93-106 kernel: ata1: hard resetting link
Aug  4 05:41:42 dhcp-93-106 kernel: ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Aug  4 05:41:42 dhcp-93-106 kernel: ata1.00: configured for UDMA/133
Aug  4 05:41:42 dhcp-93-106 kernel: ata1: EH complete
Aug  4 05:41:50 dhcp-93-106 cachefilesd[1464]: Scan complete
Aug  4 05:42:20 dhcp-93-106 cachefilesd[1464]: Scan complete
Aug  4 05:42:25 dhcp-93-106 kernel: ida_remove called for id=0 which is not allocated.
Aug  4 05:42:25 dhcp-93-106 kernel: ida_remove called for id=0 which is not allocated.
Aug  4 05:42:25 dhcp-93-106 kernel: ida_remove called for id=0 which is not allocated.
Aug  4 05:42:26 dhcp-93-106 kernel: ida_remove called for id=0 which is not allocated.
Aug  4 05:42:50 dhcp-93-106 cachefilesd[1464]: Scan complete
Aug  4 05:43:20 dhcp-93-106 cachefilesd[1464]: Scan complete
Aug  4 05:43:50 dhcp-93-106 cachefilesd[1464]: Scan complete


There is no interfaceGetXMLDesc error message generated in messages log . So set bug status to VERIFIED

Comment 6 Laine Stump 2011-08-13 01:09:18 UTC
*** Bug 729954 has been marked as a duplicate of this bug. ***

Comment 7 Laine Stump 2011-11-16 16:39:54 UTC
    Technical note added. If any revisions are required, please edit the "Technical Notes" field
    accordingly. All revisions will be proofread by the Engineering Content Services team.
    
    New Contents:
Users had reported many repeated error logs related to certain interfaces. The cause was determined to be that those interfaces had associated config files in /etc/sysconfig/network-scripts, but no corresponding device in the kernel.

There are many situations that will result in this situation. For example, if a bridge interface has been ifdowned, it will not exist at all in the kernel, but its config files will stil exist. Another case is an "alias
interface" (eg "eth0:1", which is not really an interface on its own, but just an obsolete method of specifying a 2nd (or more) IP address for a single interface. (In the example given, the config files willtalk about the interface "eth0:1", but the kernel only knows about
"eth0".)

netcf was returning an error status any time it was asked for the current status of an interface it couldn't find in the kernel, so management applications that
periodically poll netcf for the status of all system interfaces (e.g. virt-manager) would quickly collect scads of error log messages.

The solution is to ignore failure to find an interface in the kernel (which in this situation is really just one more piece of information about the interface's status - the fact that it has a config but doesn't exist in the kernel).

Comment 8 errata-xmlrpc 2011-12-06 15:19:12 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHBA-2011-1631.html