Skip to content

Commit

Permalink
Change ovs-agent iteration log level to INFO
Browse files Browse the repository at this point in the history 
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

Change-Id: I43733546abf5421d0e3f4cd5a959d279e1b89d1e
  • Loading branch information
@ralonsoh
LIU Yulong authored and ralonsoh committed Sep 7, 2019
1 parent 0d51102 commit 8e73de8
Showing 1 changed file with 61 additions and 61 deletions.
122 changes: 61 additions & 61 deletions neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1966,18 +1966,18 @@ def process_network_ports(self, port_info, provisioning_needed):
need_binding_devices, failed_devices['added']) = (
self.treat_devices_added_or_updated(
devices_added_updated, provisioning_needed))
LOG.debug("process_network_ports - iteration:%(iter_num)d - "
"treat_devices_added_or_updated completed. "
"Skipped %(num_skipped)d and no activated binding "
"devices %(num_no_active_binding)d of %(num_current)d "
"devices currently available. "
"Time elapsed: %(elapsed).3f",
{'iter_num': self.iter_num,
'num_skipped': len(skipped_devices),
'num_no_active_binding':
len(binding_no_activated_devices),
'num_current': len(port_info['current']),
'elapsed': time.time() - start})
LOG.info("process_network_ports - iteration:%(iter_num)d - "
"treat_devices_added_or_updated completed. "
"Skipped %(num_skipped)d and no activated binding "
"devices %(num_no_active_binding)d of %(num_current)d "
"devices currently available. "
"Time elapsed: %(elapsed).3f",
{'iter_num': self.iter_num,
'num_skipped': len(skipped_devices),
'num_no_active_binding':
len(binding_no_activated_devices),
'num_current': len(port_info['current']),
'elapsed': time.time() - start})
# Update the list of current ports storing only those which
# have been actually processed.
skipped_devices = set(skipped_devices)
Expand All @@ -2000,17 +2000,17 @@ def process_network_ports(self, port_info, provisioning_needed):
start = time.time()
failed_devices['removed'] |= self.treat_devices_removed(
port_info['removed'])
LOG.debug("process_network_ports - iteration:%(iter_num)d - "
"treat_devices_removed completed in %(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
LOG.info("process_network_ports - iteration:%(iter_num)d - "
"treat_devices_removed completed in %(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
if skipped_devices:
start = time.time()
self.treat_devices_skipped(skipped_devices)
LOG.debug("process_network_ports - iteration:%(iter_num)d - "
"treat_devices_skipped completed in %(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
LOG.info("process_network_ports - iteration:%(iter_num)d - "
"treat_devices_skipped completed in %(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
return failed_devices

def process_ancillary_network_ports(self, port_info):
Expand All @@ -2019,11 +2019,11 @@ def process_ancillary_network_ports(self, port_info):
start = time.time()
failed_added = self.treat_ancillary_devices_added(
port_info['added'])
LOG.debug("process_ancillary_network_ports - iteration: "
"%(iter_num)d - treat_ancillary_devices_added "
"completed in %(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
LOG.info("process_ancillary_network_ports - iteration: "
"%(iter_num)d - treat_ancillary_devices_added "
"completed in %(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
failed_devices['added'] = failed_added

if 'removed' in port_info and port_info['removed']:
Expand All @@ -2032,11 +2032,11 @@ def process_ancillary_network_ports(self, port_info):
port_info['removed'])
failed_devices['removed'] = failed_removed

LOG.debug("process_ancillary_network_ports - iteration: "
"%(iter_num)d - treat_ancillary_devices_removed "
"completed in %(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
LOG.info("process_ancillary_network_ports - iteration: "
"%(iter_num)d - treat_ancillary_devices_removed "
"completed in %(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
return failed_devices

@classmethod
Expand Down Expand Up @@ -2132,12 +2132,12 @@ def check_ovs_status(self):
def loop_count_and_wait(self, start_time, port_stats):
# sleep till end of polling interval
elapsed = time.time() - start_time
LOG.debug("Agent rpc_loop - iteration:%(iter_num)d "
"completed. Processed ports statistics: "
"%(port_stats)s. Elapsed:%(elapsed).3f",
{'iter_num': self.iter_num,
'port_stats': port_stats,
'elapsed': elapsed})
LOG.info("Agent rpc_loop - iteration:%(iter_num)d "
"completed. Processed ports statistics: "
"%(port_stats)s. Elapsed:%(elapsed).3f",
{'iter_num': self.iter_num,
'port_stats': port_stats,
'elapsed': elapsed})
if elapsed < self.polling_interval:
time.sleep(self.polling_interval - elapsed)
else:
Expand Down Expand Up @@ -2209,11 +2209,11 @@ def process_port_info(self, start, polling_manager, sync, ovs_restarted,
if self.ancillary_brs:
ancillary_port_info = self.scan_ancillary_ports(
ancillary_ports, sync)
LOG.debug("Agent rpc_loop - iteration:%(iter_num)d"
" - ancillary port info retrieved. "
"Elapsed:%(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
LOG.info("Agent rpc_loop - iteration:%(iter_num)d"
" - ancillary port info retrieved. "
"Elapsed:%(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
else:
ancillary_port_info = {}

Expand Down Expand Up @@ -2348,8 +2348,8 @@ def rpc_loop(self, polling_manager):
port_info = {}
ancillary_port_info = {}
start = time.time()
LOG.debug("Agent rpc_loop - iteration:%d started",
self.iter_num)
LOG.info("Agent rpc_loop - iteration:%d started",
self.iter_num)
ovs_status = self.check_ovs_status()
if ovs_status == constants.OVS_RESTARTED:
self._handle_ovs_restart(polling_manager)
Expand Down Expand Up @@ -2380,10 +2380,10 @@ def rpc_loop(self, polling_manager):
if (self._agent_has_updates(polling_manager) or sync or
devices_need_retry):
try:
LOG.debug("Agent rpc_loop - iteration:%(iter_num)d - "
"starting polling. Elapsed:%(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
LOG.info("Agent rpc_loop - iteration:%(iter_num)d - "
"starting polling. Elapsed:%(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})

if self.conf.AGENT.baremetal_smartnic:
if sync:
Expand Down Expand Up @@ -2417,11 +2417,11 @@ def rpc_loop(self, polling_manager):
if ofport_changed_ports:
port_info.setdefault('updated', set()).update(
ofport_changed_ports)
LOG.debug("Agent rpc_loop - iteration:%(iter_num)d - "
"port information retrieved. "
"Elapsed:%(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
LOG.info("Agent rpc_loop - iteration:%(iter_num)d - "
"port information retrieved. "
"Elapsed:%(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
# Secure and wire/unwire VIFs and update their status
# on Neutron server
if (self._port_info_has_changes(port_info) or
Expand All @@ -2436,22 +2436,22 @@ def rpc_loop(self, polling_manager):
if need_clean_stale_flow:
self.cleanup_stale_flows()
need_clean_stale_flow = False
LOG.debug("Agent rpc_loop - iteration:%(iter_num)d - "
"ports processed. Elapsed:%(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
LOG.info("Agent rpc_loop - iteration:%(iter_num)d - "
"ports processed. Elapsed:%(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})

ports = port_info['current']

if self.ancillary_brs:
failed_ancillary_devices = (
self.process_ancillary_network_ports(
ancillary_port_info))
LOG.debug("Agent rpc_loop - iteration: "
"%(iter_num)d - ancillary ports "
"processed. Elapsed:%(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
LOG.info("Agent rpc_loop - iteration: "
"%(iter_num)d - ancillary ports "
"processed. Elapsed:%(elapsed).3f",
{'iter_num': self.iter_num,
'elapsed': time.time() - start})
ancillary_ports = ancillary_port_info['current']

polling_manager.polling_completed()
Expand Down

0 comments on commit 8e73de8

Please sign in to comment.