expanded performance logging and switched to monotonic_ns for accurate measurements

This commit is contained in:
2025-04-03 17:13:48 +02:00
parent 4fad9bdbd2
commit 38381f60b5
5 changed files with 36 additions and 15 deletions
+10
View File
@@ -0,0 +1,10 @@
def format_time_ns(elapsed_ns: float) -> str:
"""Format elapsed time dynamically in an appropriate unit."""
if elapsed_ns < 1_000: # Less than 1 µs
return f"{elapsed_ns} ns" # Nanoseconds
elif elapsed_ns < 1_000_000: # Less than 1 ms
return f"{elapsed_ns / 1_000:.2f} µs" # Microseconds
elif elapsed_ns < 1_000_000_000: # Less than 1 second
return f"{elapsed_ns / 1_000_000:.2f} ms" # Milliseconds
else:
return f"{elapsed_ns / 1_000_000_000:.2f} s" # Seconds
+3 -3
View File
@@ -2,11 +2,12 @@ from cpu_governor_auto_adjust.app_class import AppClass
from cpu_governor_auto_adjust.config import Config from cpu_governor_auto_adjust.config import Config
from cpu_governor_auto_adjust.trigger import Trigger from cpu_governor_auto_adjust.trigger import Trigger
from cpu_governor_auto_adjust.governor import GovernorControl, Governor, _governor_list from cpu_governor_auto_adjust.governor import GovernorControl, Governor, _governor_list
from cpu_governor_auto_adjust.helper import format_time_ns
import asyncio import asyncio
import signal import signal
from asyncio import Task from asyncio import Task
from functools import cached_property, partial from functools import cached_property, partial
from time import monotonic from time import monotonic_ns as monotonic
from typing import Callable, Any, Optional from typing import Callable, Any, Optional
@@ -60,8 +61,7 @@ class TriggerScheduler(AppClass):
self.log.debug("scheduling task: %s", task.__name__) self.log.debug("scheduling task: %s", task.__name__)
start = monotonic() start = monotonic()
await self.loop.create_task(task(*args)) await self.loop.create_task(task(*args))
end = monotonic() self.log.debug("task %s finished in %s", task.__name__, format_time_ns(monotonic() - start))
self.log.debug("task %s finished in %.3f ms", task.__name__, (end - start) * 1000)
async def run(self) -> None: async def run(self) -> None:
"""Run the scheduler and keep it alive until stopped.""" """Run the scheduler and keep it alive until stopped."""
+20 -9
View File
@@ -3,9 +3,10 @@ from cpu_governor_auto_adjust.config import Config, TriggerTuple
from cpu_governor_auto_adjust.exceptions import MissingConfig, TriggerImportError from cpu_governor_auto_adjust.exceptions import MissingConfig, TriggerImportError
from cpu_governor_auto_adjust.governor import Governor, _governor_list from cpu_governor_auto_adjust.governor import Governor, _governor_list
from functools import cached_property from functools import cached_property
from time import monotonic from time import monotonic_ns as monotonic
from datetime import datetime from datetime import datetime
import asyncio import asyncio
from cpu_governor_auto_adjust.helper import format_time_ns
class Trigger(AppClass): class Trigger(AppClass):
@@ -15,16 +16,25 @@ class Trigger(AppClass):
self.log.setLevel(self.config.loglevel.upper()) self.log.setLevel(self.config.loglevel.upper())
self._timestamp_last_statistics = monotonic() self._timestamp_last_statistics = monotonic()
self._total_consumed_time = 0 self._total_consumed_time = 0
self._minimum_consumed_time = 10000000000
self._maximum_consumed_time = 0
self.runs = 0 self.runs = 0
def __hash__(self): def __hash__(self):
return super().__hash__(hash(self.name)) return super().__hash__(hash(self.name))
@property @property
def average_consumed_time(self) -> str: def consumed_time(self) -> dict[str, str]:
_dict = {
"total": format_time_ns(self._total_consumed_time),
"minimum": format_time_ns(self._minimum_consumed_time),
"maximum": format_time_ns(self._maximum_consumed_time),
"average": 0,
}
if self.runs == 0: if self.runs == 0:
return 0 return _dict
return f"{(self._total_consumed_time / self.runs) * 1_000_000:.3f} µs" _dict["average"] = format_time_ns(self._total_consumed_time / self.runs)
return _dict
def log_statistics(self): def log_statistics(self):
class_vars = {} class_vars = {}
@@ -50,8 +60,7 @@ class Trigger(AppClass):
value = str(value) value = str(value)
class_vars[key] = value class_vars[key] = value
end = monotonic() self.log.info("info and statistics [time taken: %s]: %s", format_time_ns(monotonic() - start), class_vars)
self.log.info("info and statistics [time taken: %.3fµs]: %s", (end - start) * 1_000_000, class_vars)
@property @property
def trigger_state(self) -> str: def trigger_state(self) -> str:
@@ -91,13 +100,15 @@ class Trigger(AppClass):
while True: while True:
start = monotonic() start = monotonic()
self.log.debug("run trigger code of %s", self.__class__.__name__) self.log.debug("run trigger code of %s", self.__class__.__name__)
if self._timestamp_last_statistics + int(self._config.statistics_interval_in_seconds) < monotonic(): if self._timestamp_last_statistics + (int(self._config.statistics_interval_in_seconds) * 1_000_000_000) < start:
self.log_statistics() self.log_statistics()
self._timestamp_last_statistics = monotonic() self._timestamp_last_statistics = start
self.trigger_code() self.trigger_code()
end = monotonic() end = monotonic()
self._total_consumed_time += end - start self._total_consumed_time += end - start
self._minimum_consumed_time = min(self._minimum_consumed_time, end - start)
self._maximum_consumed_time = max(self._maximum_consumed_time, end - start)
self.runs += 1 self.runs += 1
self.log.debug("trigger state: %s, finished in %.3f µs", self.trigger_state, (end - start) * 1_000_000) self.log.debug("trigger state: %s, finished in %s", self.trigger_state, format_time_ns(end - start))
await asyncio.sleep(self.config.interval_in_seconds) await asyncio.sleep(self.config.interval_in_seconds)
@@ -51,13 +51,13 @@ class CpuLoadTrigger(Trigger):
return any(load >= threshold for load, threshold in zip(self.current_load, self.high_threshold)) return any(load >= threshold for load, threshold in zip(self.current_load, self.high_threshold))
@property @property
def current_load_average_over_under_threshold(self) -> bool: def current_load_average_under_low_threshold(self) -> bool:
return any(load <= threshold for load, threshold in zip(self.current_load, self.low_threshold)) return any(load <= threshold for load, threshold in zip(self.current_load, self.low_threshold))
def trigger_code(self) -> None: def trigger_code(self) -> None:
current_active = self._active current_active = self._active
new_high_load_active = self.current_load_average_over_high_threshold new_high_load_active = self.current_load_average_over_high_threshold
new_low_load_active = self.current_load_average_over_under_threshold new_low_load_active = self.current_load_average_under_low_threshold
if not current_active and new_high_load_active: if not current_active and new_high_load_active:
self.log.info( self.log.info(
+1 -1
View File
@@ -1,6 +1,6 @@
[project] [project]
name = "cpu_governor_auto_adjust" name = "cpu_governor_auto_adjust"
version = "0.5.12" version = "0.5.17"
description = "This application has been developed to automatically change cpu governor based on certain triggers." description = "This application has been developed to automatically change cpu governor based on certain triggers."
authors = [ authors = [
{ name = "Martin Reurekas", email = "martin@semrks.nl" } { name = "Martin Reurekas", email = "martin@semrks.nl" }