Change ovs-agent iteration log level to INFO
Operators may want to see how long it takes in the port
processing procedure since DEBUG log does not enable
basically in the production envrionment.
Related-Bug: #1813703
Related-Bug: #1813707
Related-Bug: #1813706
Related-Bug: #1813709
Conflicts:
neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py
Change-Id: I43733546abf5421d0e3f4cd5a959d279e1b89d1e
(cherry picked from commit 8e73de8bc4
)
This commit is contained in:
parent
a96f950e4b
commit
713ad71c6f
|
@ -1760,15 +1760,15 @@ class OVSNeutronAgent(l2population_rpc.L2populationRpcCallBackTunnelMixin,
|
||||||
failed_devices['added']) = (
|
failed_devices['added']) = (
|
||||||
self.treat_devices_added_or_updated(
|
self.treat_devices_added_or_updated(
|
||||||
devices_added_updated, provisioning_needed, re_added))
|
devices_added_updated, provisioning_needed, re_added))
|
||||||
LOG.debug("process_network_ports - iteration:%(iter_num)d - "
|
LOG.info("process_network_ports - iteration:%(iter_num)d - "
|
||||||
"treat_devices_added_or_updated completed. "
|
"treat_devices_added_or_updated completed. "
|
||||||
"Skipped %(num_skipped)d devices of "
|
"Skipped %(num_skipped)d devices of "
|
||||||
"%(num_current)d devices currently available. "
|
"%(num_current)d devices currently available. "
|
||||||
"Time elapsed: %(elapsed).3f",
|
"Time elapsed: %(elapsed).3f",
|
||||||
{'iter_num': self.iter_num,
|
{'iter_num': self.iter_num,
|
||||||
'num_skipped': len(skipped_devices),
|
'num_skipped': len(skipped_devices),
|
||||||
'num_current': len(port_info['current']),
|
'num_current': len(port_info['current']),
|
||||||
'elapsed': time.time() - start})
|
'elapsed': time.time() - start})
|
||||||
# Update the list of current ports storing only those which
|
# Update the list of current ports storing only those which
|
||||||
# have been actually processed.
|
# have been actually processed.
|
||||||
skipped_devices = set(skipped_devices)
|
skipped_devices = set(skipped_devices)
|
||||||
|
@ -1793,17 +1793,17 @@ class OVSNeutronAgent(l2population_rpc.L2populationRpcCallBackTunnelMixin,
|
||||||
start = time.time()
|
start = time.time()
|
||||||
failed_devices['removed'] |= self.treat_devices_removed(
|
failed_devices['removed'] |= self.treat_devices_removed(
|
||||||
port_info['removed'])
|
port_info['removed'])
|
||||||
LOG.debug("process_network_ports - iteration:%(iter_num)d - "
|
LOG.info("process_network_ports - iteration:%(iter_num)d - "
|
||||||
"treat_devices_removed completed in %(elapsed).3f",
|
"treat_devices_removed completed in %(elapsed).3f",
|
||||||
{'iter_num': self.iter_num,
|
{'iter_num': self.iter_num,
|
||||||
'elapsed': time.time() - start})
|
'elapsed': time.time() - start})
|
||||||
if skipped_devices:
|
if skipped_devices:
|
||||||
start = time.time()
|
start = time.time()
|
||||||
self.treat_devices_skipped(skipped_devices)
|
self.treat_devices_skipped(skipped_devices)
|
||||||
LOG.debug("process_network_ports - iteration:%(iter_num)d - "
|
LOG.info("process_network_ports - iteration:%(iter_num)d - "
|
||||||
"treat_devices_skipped completed in %(elapsed).3f",
|
"treat_devices_skipped completed in %(elapsed).3f",
|
||||||
{'iter_num': self.iter_num,
|
{'iter_num': self.iter_num,
|
||||||
'elapsed': time.time() - start})
|
'elapsed': time.time() - start})
|
||||||
return failed_devices
|
return failed_devices
|
||||||
|
|
||||||
def process_install_ports_egress_flows(self, ports):
|
def process_install_ports_egress_flows(self, ports):
|
||||||
|
@ -1889,11 +1889,11 @@ class OVSNeutronAgent(l2population_rpc.L2populationRpcCallBackTunnelMixin,
|
||||||
start = time.time()
|
start = time.time()
|
||||||
failed_added = self.treat_ancillary_devices_added(
|
failed_added = self.treat_ancillary_devices_added(
|
||||||
port_info['added'])
|
port_info['added'])
|
||||||
LOG.debug("process_ancillary_network_ports - iteration: "
|
LOG.info("process_ancillary_network_ports - iteration: "
|
||||||
"%(iter_num)d - treat_ancillary_devices_added "
|
"%(iter_num)d - treat_ancillary_devices_added "
|
||||||
"completed in %(elapsed).3f",
|
"completed in %(elapsed).3f",
|
||||||
{'iter_num': self.iter_num,
|
{'iter_num': self.iter_num,
|
||||||
'elapsed': time.time() - start})
|
'elapsed': time.time() - start})
|
||||||
failed_devices['added'] = failed_added
|
failed_devices['added'] = failed_added
|
||||||
|
|
||||||
if 'removed' in port_info and port_info['removed']:
|
if 'removed' in port_info and port_info['removed']:
|
||||||
|
@ -1902,11 +1902,11 @@ class OVSNeutronAgent(l2population_rpc.L2populationRpcCallBackTunnelMixin,
|
||||||
port_info['removed'])
|
port_info['removed'])
|
||||||
failed_devices['removed'] = failed_removed
|
failed_devices['removed'] = failed_removed
|
||||||
|
|
||||||
LOG.debug("process_ancillary_network_ports - iteration: "
|
LOG.info("process_ancillary_network_ports - iteration: "
|
||||||
"%(iter_num)d - treat_ancillary_devices_removed "
|
"%(iter_num)d - treat_ancillary_devices_removed "
|
||||||
"completed in %(elapsed).3f",
|
"completed in %(elapsed).3f",
|
||||||
{'iter_num': self.iter_num,
|
{'iter_num': self.iter_num,
|
||||||
'elapsed': time.time() - start})
|
'elapsed': time.time() - start})
|
||||||
return failed_devices
|
return failed_devices
|
||||||
|
|
||||||
@classmethod
|
@classmethod
|
||||||
|
@ -1999,12 +1999,12 @@ class OVSNeutronAgent(l2population_rpc.L2populationRpcCallBackTunnelMixin,
|
||||||
def loop_count_and_wait(self, start_time, port_stats):
|
def loop_count_and_wait(self, start_time, port_stats):
|
||||||
# sleep till end of polling interval
|
# sleep till end of polling interval
|
||||||
elapsed = time.time() - start_time
|
elapsed = time.time() - start_time
|
||||||
LOG.debug("Agent rpc_loop - iteration:%(iter_num)d "
|
LOG.info("Agent rpc_loop - iteration:%(iter_num)d "
|
||||||
"completed. Processed ports statistics: "
|
"completed. Processed ports statistics: "
|
||||||
"%(port_stats)s. Elapsed:%(elapsed).3f",
|
"%(port_stats)s. Elapsed:%(elapsed).3f",
|
||||||
{'iter_num': self.iter_num,
|
{'iter_num': self.iter_num,
|
||||||
'port_stats': port_stats,
|
'port_stats': port_stats,
|
||||||
'elapsed': elapsed})
|
'elapsed': elapsed})
|
||||||
if elapsed < self.polling_interval:
|
if elapsed < self.polling_interval:
|
||||||
time.sleep(self.polling_interval - elapsed)
|
time.sleep(self.polling_interval - elapsed)
|
||||||
else:
|
else:
|
||||||
|
@ -2076,11 +2076,11 @@ class OVSNeutronAgent(l2population_rpc.L2populationRpcCallBackTunnelMixin,
|
||||||
if self.ancillary_brs:
|
if self.ancillary_brs:
|
||||||
ancillary_port_info = self.scan_ancillary_ports(
|
ancillary_port_info = self.scan_ancillary_ports(
|
||||||
ancillary_ports, sync)
|
ancillary_ports, sync)
|
||||||
LOG.debug("Agent rpc_loop - iteration:%(iter_num)d"
|
LOG.info("Agent rpc_loop - iteration:%(iter_num)d"
|
||||||
" - ancillary port info retrieved. "
|
" - ancillary port info retrieved. "
|
||||||
"Elapsed:%(elapsed).3f",
|
"Elapsed:%(elapsed).3f",
|
||||||
{'iter_num': self.iter_num,
|
{'iter_num': self.iter_num,
|
||||||
'elapsed': time.time() - start})
|
'elapsed': time.time() - start})
|
||||||
else:
|
else:
|
||||||
ancillary_port_info = {}
|
ancillary_port_info = {}
|
||||||
|
|
||||||
|
@ -2186,8 +2186,8 @@ class OVSNeutronAgent(l2population_rpc.L2populationRpcCallBackTunnelMixin,
|
||||||
port_info = {}
|
port_info = {}
|
||||||
ancillary_port_info = {}
|
ancillary_port_info = {}
|
||||||
start = time.time()
|
start = time.time()
|
||||||
LOG.debug("Agent rpc_loop - iteration:%d started",
|
LOG.info("Agent rpc_loop - iteration:%d started",
|
||||||
self.iter_num)
|
self.iter_num)
|
||||||
ovs_status = self.check_ovs_status()
|
ovs_status = self.check_ovs_status()
|
||||||
if ovs_status == constants.OVS_RESTARTED:
|
if ovs_status == constants.OVS_RESTARTED:
|
||||||
self.setup_integration_br()
|
self.setup_integration_br()
|
||||||
|
@ -2250,10 +2250,10 @@ class OVSNeutronAgent(l2population_rpc.L2populationRpcCallBackTunnelMixin,
|
||||||
if (self._agent_has_updates(polling_manager) or sync
|
if (self._agent_has_updates(polling_manager) or sync
|
||||||
or devices_need_retry):
|
or devices_need_retry):
|
||||||
try:
|
try:
|
||||||
LOG.debug("Agent rpc_loop - iteration:%(iter_num)d - "
|
LOG.info("Agent rpc_loop - iteration:%(iter_num)d - "
|
||||||
"starting polling. Elapsed:%(elapsed).3f",
|
"starting polling. Elapsed:%(elapsed).3f",
|
||||||
{'iter_num': self.iter_num,
|
{'iter_num': self.iter_num,
|
||||||
'elapsed': time.time() - start})
|
'elapsed': time.time() - start})
|
||||||
# Save updated ports dict to perform rollback in
|
# Save updated ports dict to perform rollback in
|
||||||
# case resync would be needed, and then clear
|
# case resync would be needed, and then clear
|
||||||
# self.updated_ports. As the greenthread should not yield
|
# self.updated_ports. As the greenthread should not yield
|
||||||
|
@ -2272,11 +2272,11 @@ class OVSNeutronAgent(l2population_rpc.L2populationRpcCallBackTunnelMixin,
|
||||||
if ofport_changed_ports:
|
if ofport_changed_ports:
|
||||||
port_info.setdefault('updated', set()).update(
|
port_info.setdefault('updated', set()).update(
|
||||||
ofport_changed_ports)
|
ofport_changed_ports)
|
||||||
LOG.debug("Agent rpc_loop - iteration:%(iter_num)d - "
|
LOG.info("Agent rpc_loop - iteration:%(iter_num)d - "
|
||||||
"port information retrieved. "
|
"port information retrieved. "
|
||||||
"Elapsed:%(elapsed).3f",
|
"Elapsed:%(elapsed).3f",
|
||||||
{'iter_num': self.iter_num,
|
{'iter_num': self.iter_num,
|
||||||
'elapsed': time.time() - start})
|
'elapsed': time.time() - start})
|
||||||
# Secure and wire/unwire VIFs and update their status
|
# Secure and wire/unwire VIFs and update their status
|
||||||
# on Neutron server
|
# on Neutron server
|
||||||
if (self._port_info_has_changes(port_info) or
|
if (self._port_info_has_changes(port_info) or
|
||||||
|
@ -2291,10 +2291,10 @@ class OVSNeutronAgent(l2population_rpc.L2populationRpcCallBackTunnelMixin,
|
||||||
if need_clean_stale_flow:
|
if need_clean_stale_flow:
|
||||||
self.cleanup_stale_flows()
|
self.cleanup_stale_flows()
|
||||||
need_clean_stale_flow = False
|
need_clean_stale_flow = False
|
||||||
LOG.debug("Agent rpc_loop - iteration:%(iter_num)d - "
|
LOG.info("Agent rpc_loop - iteration:%(iter_num)d - "
|
||||||
"ports processed. Elapsed:%(elapsed).3f",
|
"ports processed. Elapsed:%(elapsed).3f",
|
||||||
{'iter_num': self.iter_num,
|
{'iter_num': self.iter_num,
|
||||||
'elapsed': time.time() - start})
|
'elapsed': time.time() - start})
|
||||||
|
|
||||||
ports = port_info['current']
|
ports = port_info['current']
|
||||||
|
|
||||||
|
@ -2302,11 +2302,11 @@ class OVSNeutronAgent(l2population_rpc.L2populationRpcCallBackTunnelMixin,
|
||||||
failed_ancillary_devices = (
|
failed_ancillary_devices = (
|
||||||
self.process_ancillary_network_ports(
|
self.process_ancillary_network_ports(
|
||||||
ancillary_port_info))
|
ancillary_port_info))
|
||||||
LOG.debug("Agent rpc_loop - iteration: "
|
LOG.info("Agent rpc_loop - iteration: "
|
||||||
"%(iter_num)d - ancillary ports "
|
"%(iter_num)d - ancillary ports "
|
||||||
"processed. Elapsed:%(elapsed).3f",
|
"processed. Elapsed:%(elapsed).3f",
|
||||||
{'iter_num': self.iter_num,
|
{'iter_num': self.iter_num,
|
||||||
'elapsed': time.time() - start})
|
'elapsed': time.time() - start})
|
||||||
ancillary_ports = ancillary_port_info['current']
|
ancillary_ports = ancillary_port_info['current']
|
||||||
|
|
||||||
polling_manager.polling_completed()
|
polling_manager.polling_completed()
|
||||||
|
|
Loading…
Reference in New Issue