Skip to content

Commit 728cc14

Browse files
authored
Log manager counts on change, not every poll period (#4011)
The poll period is 10ms by default, meaning that before this PR, the manager count was logged around 100 times per second. When htex.worker_debug is turned on, that is a lot of disk logging activity. For example in one run of the test suite, which takes around 18 seconds, interchange log size pytest parsl/tests/ --config parsl/tests/configs/htex_local.py Before this PR: 6544 lines, 928kb with around 1800 of those being this affected manager log line. After this PR: 4703 lines, 678kb With an interchange that is mostly idle, for example, with tasks performing real work rather than the trivial test tasks here, I expect the savings to be much greater. History: This line has always been logged like this, but previously the interchange was verbose in other ways per-poll-iteration. Work since then has reduced the per-poll log cost substantially. # Changed Behaviour much reduced debug logging ## Type of change - Update to human readable text: Documentation/error messages/comments
1 parent c7b2d8a commit 728cc14

File tree

1 file changed

+17
-6
lines changed

1 file changed

+17
-6
lines changed

parsl/executors/high_throughput/interchange.py

Lines changed: 17 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -160,6 +160,7 @@ def __init__(self,
160160
logger.info(f"Bound to port {worker_port} for incoming worker connections")
161161

162162
self._ready_managers: Dict[bytes, ManagerRecord] = {}
163+
self._logged_manager_count_token: object = None
163164
self.connected_block_history: List[str] = []
164165

165166
self.heartbeat_threshold = heartbeat_threshold
@@ -313,6 +314,7 @@ def start(self) -> None:
313314
self.process_manager_socket_message(interesting_managers, monitoring_radio, kill_event)
314315
self.expire_bad_managers(interesting_managers, monitoring_radio)
315316
self.expire_drained_managers(interesting_managers, monitoring_radio)
317+
self.log_manager_counts(interesting_managers)
316318
self.process_tasks_to_send(interesting_managers, monitoring_radio)
317319

318320
self.zmq_context.destroy()
@@ -523,15 +525,24 @@ def expire_drained_managers(self, interesting_managers: Set[bytes], monitoring_r
523525
m['active'] = False
524526
self._send_monitoring_info(monitoring_radio, m)
525527

528+
def log_manager_counts(self, interesting_managers: Set[bytes]) -> None:
529+
count_interesting = len(interesting_managers)
530+
count_ready = len(self._ready_managers)
531+
532+
new_logged_manager_count_token = (count_interesting, count_ready)
533+
534+
if self._logged_manager_count_token != new_logged_manager_count_token:
535+
536+
logger.debug(
537+
"Managers count (interesting/total): %d/%d",
538+
count_interesting,
539+
count_ready
540+
)
541+
self._logged_manager_count_token = new_logged_manager_count_token
542+
526543
def process_tasks_to_send(self, interesting_managers: Set[bytes], monitoring_radio: Optional[MonitoringRadioSender]) -> None:
527544
# Check if there are tasks that could be sent to managers
528545

529-
logger.debug(
530-
"Managers count (interesting/total): %d/%d",
531-
len(interesting_managers),
532-
len(self._ready_managers)
533-
)
534-
535546
if interesting_managers and self.pending_task_queue:
536547
shuffled_managers = self.manager_selector.sort_managers(self._ready_managers, interesting_managers)
537548

0 commit comments

Comments
 (0)