Add update_id for ResourceUpdate

Add a unique id for resource update, then we can calculate
the resource processing time and track it.

Related-Bug: #1825152
Related-Bug: #1824911
Related-Bug: #1821912
Related-Bug: #1813787

Change-Id: Ib4d197c6c180c32860964440882393794aabb6ef
This commit is contained in:
LIU Yulong 2019-04-23 15:27:02 +08:00 committed by LIU Yulong
parent 5d607a13ba
commit 9d60716cf1
2 changed files with 39 additions and 5 deletions

View File

@ -14,8 +14,10 @@
# #
import datetime import datetime
import time
from oslo_utils import timeutils from oslo_utils import timeutils
from oslo_utils import uuidutils
from six.moves import queue as Queue from six.moves import queue as Queue
@ -38,6 +40,25 @@ class ResourceUpdate(object):
self.action = action self.action = action
self.resource = resource self.resource = resource
self.tries = tries self.tries = tries
# NOTE: Because one resource can be processed multiple times, this
# update_id will be used for tracking one resource processing
# procedure.
self.update_id = uuidutils.generate_uuid()
self.create_time = self.start_time = time.time()
def set_start_time(self):
# Set the start_time to 'now' - can be used by callers to help
# track time spent in procedures.
self.start_time = time.time()
@property
def time_elapsed_since_create(self):
return time.time() - self.create_time
@property
def time_elapsed_since_start(self):
# Time elapsed between processing start and end.
return time.time() - self.start_time
def __lt__(self, other): def __lt__(self, other):
"""Implements priority among updates """Implements priority among updates
@ -163,4 +184,5 @@ class ResourceProcessingQueue(object):
# rp.updates() will not yield and so this will essentially be a # rp.updates() will not yield and so this will essentially be a
# noop. # noop.
for update in rp.updates(): for update in rp.updates():
update.set_start_time()
yield (rp, update) yield (rp, update)

View File

@ -618,11 +618,17 @@ class L3NATAgent(ha.AgentMixin,
def _process_router_update(self): def _process_router_update(self):
for rp, update in self._queue.each_update_to_next_resource(): for rp, update in self._queue.each_update_to_next_resource():
LOG.info("Starting router update for %s, action %s, priority %s", LOG.info("Starting router update for %s, action %s, priority %s, "
update.id, update.action, update.priority) "update_id %s. Wait time elapsed: %.3f",
update.id, update.action, update.priority,
update.update_id,
update.time_elapsed_since_create)
if update.action == PD_UPDATE: if update.action == PD_UPDATE:
self.pd.process_prefix_update() self.pd.process_prefix_update()
LOG.info("Finished a router update for %s", update.id) LOG.info("Finished a router update for %s IPv6 PD, "
"update_id. %s. Time elapsed: %.3f",
update.id, update.update_id,
update.time_elapsed_since_start)
continue continue
routers = [update.resource] if update.resource else [] routers = [update.resource] if update.resource else []
@ -658,7 +664,10 @@ class L3NATAgent(ha.AgentMixin,
# processing queue (like events from fullsync) in order to # processing queue (like events from fullsync) in order to
# prevent deleted router re-creation # prevent deleted router re-creation
rp.fetched_and_processed(update.timestamp) rp.fetched_and_processed(update.timestamp)
LOG.info("Finished a router update for %s", update.id) LOG.info("Finished a router update for %s, update_id %s. "
"Time elapsed: %.3f",
update.id, update.update_id,
update.time_elapsed_since_start)
continue continue
if not self._process_routers_if_compatible(routers, update): if not self._process_routers_if_compatible(routers, update):
@ -666,7 +675,10 @@ class L3NATAgent(ha.AgentMixin,
continue continue
rp.fetched_and_processed(update.timestamp) rp.fetched_and_processed(update.timestamp)
LOG.info("Finished a router update for %s", update.id) LOG.info("Finished a router update for %s, update_id %s. "
"Time elapsed: %.3f",
update.id, update.update_id,
update.time_elapsed_since_start)
def _process_routers_if_compatible(self, routers, update): def _process_routers_if_compatible(self, routers, update):
process_result = True process_result = True