Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1146019

Summary: [vdsm] vdsm fails configuring the network if it doens't find NM_CONTROLLED=no also on a system without NetworkManager
Product: [Retired] oVirt Reporter: Simone Tiraboschi <stirabos>
Component: vdsmAssignee: Dan Kenigsberg <danken>
Status: CLOSED INSUFFICIENT_DATA QA Contact: Gil Klein <gklein>
Severity: medium Docs Contact:
Priority: low    
Version: 3.5CC: bazulay, bugs, ecohen, gklein, iheim, lsurette, mgoldboi, rbalakri, stirabos, yeylon
Target Milestone: ---   
Target Release: 3.6.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: network
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-01-21 09:25:52 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Network RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
Logs from a failing setup none

Description Simone Tiraboschi 2014-09-24 10:05:40 UTC
Description of problem:
During oVirt all-in-one setup on a Centos 6.5 host with iptables and without NetworkManager, vdsm fails configuring the network if /etc/sysconfig/ifcfg-eth0 doesn't include "NM_CONTROLLED=no"

In the vdsm log I can found:
 Thread-16::ERROR::2014-09-24 04:51:50,049::API::1487::vds::(_rollback) connectivity check failed
 Traceback (most recent call last):
   File "/usr/share/vdsm/API.py", line 1485, in _rollback
     yield rollbackCtx
   File "/usr/share/vdsm/API.py", line 1373, in setupNetworks
     supervdsm.getProxy().setupNetworks(networks, bondings, options)
   File "/usr/share/vdsm/supervdsm.py", line 50, in __call__
     return callMethod()
   File "/usr/share/vdsm/supervdsm.py", line 48, in <lambda>
     **kwargs)
   File "<string>", line 2, in setupNetworks
   File "/usr/lib64/python2.6/multiprocessing/managers.py", line 740, in _callmethod
     raise convert_to_error(kind, result)
 ConfigNetworkError: (10, 'connectivity check failed')

Version-Release number of selected component (if applicable):
vdsm 4.16.5-0.el6

How reproducible:
100% on centos65


Steps to Reproduce:
1. remove/disable NetworkManager, enable network service, if present remove "NM_CONTROLLED=no" from /etc/sysconfig/ifcfg-eth0 
2. run engine-setup
3. during engine-setup choose to configure also VDSM

Actual results:
VDSM fails configuring the network

Expected results:
VDSM correctly configures the network

Additional info:
I'm attaching the relevant logs.
NetworkManager was disable, firewalld also.
Executing again adding NM_CONTROLLED=no is enough to bypass the problem

Comment 1 Simone Tiraboschi 2014-09-24 10:09:22 UTC
Created attachment 940734 [details]
Logs from a failing setup

Logs from a failing setup

Comment 2 Dan Kenigsberg 2014-09-24 13:24:30 UTC
I doubt that this is related to NM_CONTROLLED missing from ifcfg-eth0. How many times did you try this? 

Could you supply supervdsm.log of a successful run? And the connectivity.log of the failed run?

Which Engine version is it? (we had a problem with pings over json-rpc in the past).
 
Thread-15::DEBUG::2014-09-24 04:49:36,716::__init__::467::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'Host.ping' in bridge with {}
Thread-15::DEBUG::2014-09-24 04:49:36,719::__init__::498::jsonrpc.JsonRpcServer::(_serveRequest) Return 'Host.ping' in bridge with True
Thread-15::DEBUG::2014-09-24 04:49:36,719::stompReactor::163::yajsonrpc.StompServer::(send) Sending response
Detector thread::DEBUG::2014-09-24 04:49:36,819::protocoldetector::166::vds.MultiProtocolAcceptor::(_add_connection) Adding connection from 192.168.1.122:54263
Detector thread::DEBUG::2014-09-24 04:49:36,819::protocoldetector::177::vds.MultiProtocolAcceptor::(_remove_connection) Connection removed from 192.168.1.122:54263
Detector thread::DEBUG::2014-09-24 04:49:36,819::protocoldetector::203::vds.MultiProtocolAcceptor::(_handle_connection_read) Detected protocol stomp from 192.168.1.122:54263
Detector thread::DEBUG::2014-09-24 04:49:36,820::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling message <StompFrame command='CONNECT'>
Detector thread::INFO::2014-09-24 04:49:36,820::stompReactor::66::Broker.StompAdapter::(_cmd_connect) Processing CONNECT request
Detector thread::DEBUG::2014-09-24 04:49:36,820::stompReactor::338::protocoldetector.StompDetector::(handleSocket) Stomp detected from ('192.168.1.122', 54263)
JsonRpc (StompReactor)::DEBUG::2014-09-24 04:49:36,821::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling message <StompFrame command='SUBSCRIBE'>
JsonRpc (StompReactor)::DEBUG::2014-09-24 04:49:36,821::stompReactor::89::Broker.StompAdapter::(_cmd_subscribe) Subscribe command ignored
JsonRpc (StompReactor)::DEBUG::2014-09-24 04:49:36,861::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling message <StompFrame command='SEND'>
Thread-16::DEBUG::2014-09-24 04:49:36,862::__init__::467::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'Host.setupNetworks' in bridge with {u'bondings': {}, u'networks': {u'ovirtmgmt': {u'nic': u'eth0', u'mtu': u'1500', u'bootproto': u'dhcp', u'STP': u'no', u'bridged': u'true', u'defaultRoute': True}}, u'options': {u'connectivityCheck': u'true', u'connectivityTimeout': 120}}
JsonRpcServer::DEBUG::2014-09-24 04:49:36,862::__init__::504::jsonrpc.JsonRpcServer::(serve_requests) Waiting for request
Thread-16::ERROR::2014-09-24 04:51:50,049::API::1487::vds::(_rollback) connectivity check failed


but Vdsm got its IP back well before 04:51:50:

sourceRoute::INFO::2014-09-24 04:49:42,386::sourceroute::81::root::(configure) Configuring gateway - ip: 192.168.1.122, network: 192.168.1.0/24, subnet: 255.255.255.0, gateway: 192.168.1.1, table: 3232235898, device: ovirtmgmt

Comment 3 Simone Tiraboschi 2014-09-24 15:38:00 UTC
(In reply to Dan Kenigsberg from comment #2)
> I doubt that this is related to NM_CONTROLLED missing from ifcfg-eth0. How
> many times did you try this? 

2 this morning but both on the same host. Honestly I'm not really sure about the reason but it started to work at the 3rd reason just adding NM_CONTROLLED=no
Maybe it's just a coincidence.

> Could you supply supervdsm.log of a successful run? And the connectivity.log
> of the failed run?

Unfortunately I've than destroyed that VM. 

> Which Engine version is it? (we had a problem with pings over json-rpc in
> the past).

3.5.0 RC3 from this morning. All the packages was updated at the latest available release.

> Thread-15::DEBUG::2014-09-24
> 04:49:36,716::__init__::467::jsonrpc.JsonRpcServer::(_serveRequest) Calling
> 'Host.ping' in bridge with {}
> Thread-15::DEBUG::2014-09-24
> 04:49:36,719::__init__::498::jsonrpc.JsonRpcServer::(_serveRequest) Return
> 'Host.ping' in bridge with True
> Thread-15::DEBUG::2014-09-24
> 04:49:36,719::stompReactor::163::yajsonrpc.StompServer::(send) Sending
> response
> Detector thread::DEBUG::2014-09-24
> 04:49:36,819::protocoldetector::166::vds.MultiProtocolAcceptor::
> (_add_connection) Adding connection from 192.168.1.122:54263
> Detector thread::DEBUG::2014-09-24
> 04:49:36,819::protocoldetector::177::vds.MultiProtocolAcceptor::
> (_remove_connection) Connection removed from 192.168.1.122:54263
> Detector thread::DEBUG::2014-09-24
> 04:49:36,819::protocoldetector::203::vds.MultiProtocolAcceptor::
> (_handle_connection_read) Detected protocol stomp from 192.168.1.122:54263
> Detector thread::DEBUG::2014-09-24
> 04:49:36,820::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling
> message <StompFrame command='CONNECT'>
> Detector thread::INFO::2014-09-24
> 04:49:36,820::stompReactor::66::Broker.StompAdapter::(_cmd_connect)
> Processing CONNECT request
> Detector thread::DEBUG::2014-09-24
> 04:49:36,820::stompReactor::338::protocoldetector.StompDetector::
> (handleSocket) Stomp detected from ('192.168.1.122', 54263)
> JsonRpc (StompReactor)::DEBUG::2014-09-24
> 04:49:36,821::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling
> message <StompFrame command='SUBSCRIBE'>
> JsonRpc (StompReactor)::DEBUG::2014-09-24
> 04:49:36,821::stompReactor::89::Broker.StompAdapter::(_cmd_subscribe)
> Subscribe command ignored
> JsonRpc (StompReactor)::DEBUG::2014-09-24
> 04:49:36,861::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling
> message <StompFrame command='SEND'>
> Thread-16::DEBUG::2014-09-24
> 04:49:36,862::__init__::467::jsonrpc.JsonRpcServer::(_serveRequest) Calling
> 'Host.setupNetworks' in bridge with {u'bondings': {}, u'networks':
> {u'ovirtmgmt': {u'nic': u'eth0', u'mtu': u'1500', u'bootproto': u'dhcp',
> u'STP': u'no', u'bridged': u'true', u'defaultRoute': True}}, u'options':
> {u'connectivityCheck': u'true', u'connectivityTimeout': 120}}
> JsonRpcServer::DEBUG::2014-09-24
> 04:49:36,862::__init__::504::jsonrpc.JsonRpcServer::(serve_requests) Waiting
> for request
> Thread-16::ERROR::2014-09-24 04:51:50,049::API::1487::vds::(_rollback)
> connectivity check failed
> 
> 
> but Vdsm got its IP back well before 04:51:50:
> 
> sourceRoute::INFO::2014-09-24
> 04:49:42,386::sourceroute::81::root::(configure) Configuring gateway - ip:
> 192.168.1.122, network: 192.168.1.0/24, subnet: 255.255.255.0, gateway:
> 192.168.1.1, table: 3232235898, device: ovirtmgmt

I see.

If it can help that VM was created from the Centos 6.5 image we distributing from oVirt public glance repository.

Comment 4 Dan Kenigsberg 2015-01-21 09:25:52 UTC
Please reopen if anything like this reproduces, and remember to attach supervdsm.log.