zuul
/
nodepool
Code Issues Proposed changes

Add debug log messages to handler assignment/removal 

In some circumstances, I'm seeing the assign handlers method
run much longer than expected.  This may help identify the
problem.

Change-Id: I9a636dc325fa83125a20e5a3d4c24c215078093e
This commit is contained in:
James E. Blair 2023-02-04 07:37:31 -08:00 committed by Benjamin Schanzel
parent 1baa3193f4
commit 06e5d2f843
1 changed files with 14 additions and 2 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

16
nodepool/launcher.py
View File

@ -108,6 +108,7 @@ class PoolWorker(threading.Thread, stats.StatsReporter):
in order to give us time to call _removeCompletedHandlers. Otherwise
it returns True to signal that it is finished for now.
'''
self.log.debug("Starting handler assignment")
start = time.monotonic()
provider = self.getProviderConfig()
if not provider:
@ -143,7 +144,7 @@ class PoolWorker(threading.Thread, stats.StatsReporter):
return len(missing_labels), request.priority
requests = sorted(self.zk.nodeRequestIterator(), key=_sort_key)
for req in requests:
for req_count, req in enumerate(requests):
if not self.running:
return True
@ -279,8 +280,15 @@ class PoolWorker(threading.Thread, stats.StatsReporter):
self.request_handlers.append(rh)
# if we exceeded the timeout stop iterating here
if time.monotonic() - start > timeout:
elapsed = time.monotonic() - start
if elapsed > timeout:
self.log.debug("Early exit from handler assignment on timeout "
"after %s/%s requests in %s",
req_count + 1, len(requests), elapsed)
return False
elapsed = time.monotonic() - start
self.log.debug("Finished handler assignment %s requests in %s",
len(requests), elapsed)
return True
def _removeCompletedHandlers(self):
@ -288,6 +296,8 @@ class PoolWorker(threading.Thread, stats.StatsReporter):
Poll handlers to see which have completed.
'''
active_handlers = []
self.log.debug("Starting handler removal with %s handlers",
len(self.request_handlers))
for r in self.request_handlers:
log = get_annotated_logger(self.log, event_id=r.request.event_id,
node_request_id=r.request.id)
@ -311,6 +321,8 @@ class PoolWorker(threading.Thread, stats.StatsReporter):
active_handlers.append(r)
self.request_handlers = active_handlers
active_reqs = [r.request.id for r in self.request_handlers]
self.log.debug("Finished handler removal with %s handlers",
len(self.request_handlers))
self.log.debug("Active requests: %s", active_reqs)
def _hasTenantQuota(self, request, provider_manager):