clan_vm_manager: Cache profiler obj for multi call functions
This commit is contained in:
parent
b2d3ff4431
commit
b77ffac4d4
@ -37,3 +37,9 @@ gsettings set org.gtk.Settings.Debug enable-inspector-keybinding true
|
|||||||
# Start the application with the debugger attached
|
# Start the application with the debugger attached
|
||||||
GTK_DEBUG=interactive ./bin/clan-vm-manager --debug
|
GTK_DEBUG=interactive ./bin/clan-vm-manager --debug
|
||||||
```
|
```
|
||||||
|
|
||||||
|
## Profiling
|
||||||
|
To activate profiling execute:
|
||||||
|
```
|
||||||
|
PERF=1 ./bin/clan-vm-manager
|
||||||
|
```
|
@ -2,12 +2,10 @@ import logging
|
|||||||
import sys
|
import sys
|
||||||
|
|
||||||
from clan_vm_manager.app import MainApplication
|
from clan_vm_manager.app import MainApplication
|
||||||
from clan_vm_manager.components.profiler import profile
|
|
||||||
|
|
||||||
log = logging.getLogger(__name__)
|
log = logging.getLogger(__name__)
|
||||||
|
|
||||||
|
|
||||||
@profile
|
|
||||||
def main() -> int:
|
def main() -> int:
|
||||||
app = MainApplication()
|
app = MainApplication()
|
||||||
return app.run(sys.argv)
|
return app.run(sys.argv)
|
||||||
|
@ -1,5 +1,4 @@
|
|||||||
import logging
|
import logging
|
||||||
from collections import OrderedDict
|
|
||||||
from collections.abc import Callable
|
from collections.abc import Callable
|
||||||
from typing import Any, Generic, TypeVar
|
from typing import Any, Generic, TypeVar
|
||||||
|
|
||||||
@ -29,7 +28,8 @@ class GKVStore(GObject.GObject, Gio.ListModel, Generic[K, V]):
|
|||||||
super().__init__()
|
super().__init__()
|
||||||
self.gtype = gtype
|
self.gtype = gtype
|
||||||
self.key_gen = key_gen
|
self.key_gen = key_gen
|
||||||
self._items: "OrderedDict[K, V]" = OrderedDict()
|
# From Python 3.7 onwards dictionaries are ordered by default
|
||||||
|
self._items: "dict[K, V]" = dict()
|
||||||
|
|
||||||
##################################
|
##################################
|
||||||
# #
|
# #
|
||||||
@ -175,7 +175,6 @@ class GKVStore(GObject.GObject, Gio.ListModel, Generic[K, V]):
|
|||||||
else:
|
else:
|
||||||
# Add the new key-value pair
|
# Add the new key-value pair
|
||||||
self._items[key] = value
|
self._items[key] = value
|
||||||
self._items.move_to_end(key)
|
|
||||||
position = max(len(self._items) - 1, 0)
|
position = max(len(self._items) - 1, 0)
|
||||||
self.items_changed(position, 0, 1)
|
self.items_changed(position, 0, 1)
|
||||||
|
|
||||||
|
@ -4,11 +4,80 @@ import logging
|
|||||||
import os
|
import os
|
||||||
import pstats
|
import pstats
|
||||||
import re
|
import re
|
||||||
|
import weakref
|
||||||
from collections.abc import Callable
|
from collections.abc import Callable
|
||||||
from typing import Any
|
from typing import Any
|
||||||
|
|
||||||
# Ensure you have a logger set up for logging exceptions
|
# Ensure you have a logger set up for logging exceptions
|
||||||
log = logging.getLogger(__name__)
|
log = logging.getLogger(__name__)
|
||||||
|
explanation = """
|
||||||
|
cProfile Output Columns Explanation:
|
||||||
|
|
||||||
|
- ncalls: The number of calls to the function. This includes both direct and indirect (recursive) calls.
|
||||||
|
|
||||||
|
- tottime: The total time spent in the given function alone, excluding time spent in calls to sub-functions.
|
||||||
|
This measures the function's own overhead and execution time.
|
||||||
|
|
||||||
|
- percall (first instance): Represents the average time spent in the function per call, calculated as tottime divided by ncalls.
|
||||||
|
This value excludes time spent in sub-function calls, focusing on the function's own processing time.
|
||||||
|
|
||||||
|
- cumtime: The cumulative time spent in this function and all the sub-functions it calls (both directly and indirectly).
|
||||||
|
This includes all execution time within the function, from the start of its invocation to its return,
|
||||||
|
including all calls to other functions and the time those calls take.
|
||||||
|
|
||||||
|
- percall (second instance): Represents the average time per call, including time spent in this function and in all sub-function calls.
|
||||||
|
It is calculated as cumtime divided by ncalls, providing an average over all calls that includes all nested function calls.
|
||||||
|
"""
|
||||||
|
|
||||||
|
|
||||||
|
def print_profile(profiler: cProfile.Profile) -> None:
|
||||||
|
s = io.StringIO()
|
||||||
|
ps = pstats.Stats(profiler, stream=s)
|
||||||
|
ps.sort_stats(pstats.SortKey.CUMULATIVE)
|
||||||
|
ps.print_stats(12)
|
||||||
|
|
||||||
|
# Process the output to trim file paths
|
||||||
|
output_lines = s.getvalue().split("\n")
|
||||||
|
for line in output_lines:
|
||||||
|
try:
|
||||||
|
parts = re.split(r"\s+", line)[
|
||||||
|
1:
|
||||||
|
] # Split on the first space to separate the time from the path
|
||||||
|
fqpath = parts[-1]
|
||||||
|
fpath, line_num = fqpath.split(":")
|
||||||
|
if os.path.sep in fpath: # Check if this looks like it includes a path
|
||||||
|
fpath = trim_path_to_three_levels(fpath)
|
||||||
|
prefix = f"{parts[0]:>7}"
|
||||||
|
prefix += f"{parts[1]:>9}"
|
||||||
|
prefix += f"{parts[2]:>9}"
|
||||||
|
prefix += f"{parts[3]:>9}"
|
||||||
|
prefix += f"{parts[4]:>9}"
|
||||||
|
new_line = f"{prefix:} {fpath}:{line_num}"
|
||||||
|
else:
|
||||||
|
new_line = line
|
||||||
|
except (ValueError, IndexError):
|
||||||
|
new_line = line # If there's no path, leave the line as is
|
||||||
|
print(new_line)
|
||||||
|
|
||||||
|
|
||||||
|
class ProfilerStore:
|
||||||
|
profilers: dict[str, cProfile.Profile]
|
||||||
|
|
||||||
|
def __init__(self) -> None:
|
||||||
|
self.profilers = {}
|
||||||
|
self._exit_callback = weakref.finalize(self, self.on_exit)
|
||||||
|
|
||||||
|
def __getitem__(self, func: Callable) -> cProfile.Profile:
|
||||||
|
key = f"{func.__module__}:{func.__name__}"
|
||||||
|
if key not in self.profilers:
|
||||||
|
self.profilers[key] = cProfile.Profile()
|
||||||
|
return self.profilers[key]
|
||||||
|
|
||||||
|
def on_exit(self) -> None:
|
||||||
|
for key, profiler in self.profilers.items():
|
||||||
|
print("=" * 7 + key + "=" * 7)
|
||||||
|
print_profile(profiler)
|
||||||
|
print(explanation)
|
||||||
|
|
||||||
|
|
||||||
def trim_path_to_three_levels(path: str) -> str:
|
def trim_path_to_three_levels(path: str) -> str:
|
||||||
@ -19,6 +88,9 @@ def trim_path_to_three_levels(path: str) -> str:
|
|||||||
return path
|
return path
|
||||||
|
|
||||||
|
|
||||||
|
PROFS = ProfilerStore()
|
||||||
|
|
||||||
|
|
||||||
def profile(func: Callable) -> Callable:
|
def profile(func: Callable) -> Callable:
|
||||||
"""
|
"""
|
||||||
A decorator that profiles the decorated function, printing out the profiling
|
A decorator that profiles the decorated function, printing out the profiling
|
||||||
@ -26,44 +98,20 @@ def profile(func: Callable) -> Callable:
|
|||||||
"""
|
"""
|
||||||
|
|
||||||
def wrapper(*args: Any, **kwargs: Any) -> Any:
|
def wrapper(*args: Any, **kwargs: Any) -> Any:
|
||||||
pr = cProfile.Profile()
|
global PROFS
|
||||||
res: Any = None
|
profiler = PROFS[func]
|
||||||
|
|
||||||
try:
|
try:
|
||||||
pr.enable()
|
profiler.enable()
|
||||||
res = func(*args, **kwargs)
|
res = func(*args, **kwargs)
|
||||||
pr.disable()
|
profiler.disable()
|
||||||
except Exception as ex:
|
except Exception as ex:
|
||||||
log.exception(ex)
|
log.exception(ex)
|
||||||
pr.disable()
|
profiler.disable()
|
||||||
return None
|
return None
|
||||||
|
|
||||||
s = io.StringIO()
|
|
||||||
ps = pstats.Stats(pr, stream=s)
|
|
||||||
ps.sort_stats(pstats.SortKey.CUMULATIVE)
|
|
||||||
ps.print_stats(12)
|
|
||||||
|
|
||||||
# Process the output to trim file paths
|
|
||||||
output_lines = s.getvalue().split("\n")
|
|
||||||
for line in output_lines:
|
|
||||||
try:
|
|
||||||
parts = re.split(r"\s+", line)[
|
|
||||||
1:
|
|
||||||
] # Split on the first space to separate the time from the path
|
|
||||||
fqpath = parts[-1]
|
|
||||||
fpath, line_num = fqpath.split(":")
|
|
||||||
if os.path.sep in fpath: # Check if this looks like it includes a path
|
|
||||||
fpath = trim_path_to_three_levels(fpath)
|
|
||||||
prefix = f"{parts[0]:>7}"
|
|
||||||
prefix += f"{parts[1]:>9}"
|
|
||||||
prefix += f"{parts[2]:>9}"
|
|
||||||
prefix += f"{parts[3]:>9}"
|
|
||||||
prefix += f"{parts[4]:>9}"
|
|
||||||
new_line = f"{prefix:} {fpath}:{line_num}"
|
|
||||||
else:
|
|
||||||
new_line = line
|
|
||||||
except (ValueError, IndexError):
|
|
||||||
new_line = line # If there's no path, leave the line as is
|
|
||||||
print(new_line)
|
|
||||||
return res
|
return res
|
||||||
|
|
||||||
return wrapper
|
if os.getenv("PERF", "0") == "1":
|
||||||
|
return wrapper
|
||||||
|
else:
|
||||||
|
return func
|
||||||
|
@ -7,6 +7,7 @@ from clan_cli.history.add import HistoryEntry
|
|||||||
|
|
||||||
from clan_vm_manager import assets
|
from clan_vm_manager import assets
|
||||||
from clan_vm_manager.components.gkvstore import GKVStore
|
from clan_vm_manager.components.gkvstore import GKVStore
|
||||||
|
from clan_vm_manager.components.profiler import profile
|
||||||
from clan_vm_manager.components.vmobj import VMObject
|
from clan_vm_manager.components.vmobj import VMObject
|
||||||
|
|
||||||
gi.require_version("GObject", "2.0")
|
gi.require_version("GObject", "2.0")
|
||||||
@ -47,6 +48,7 @@ class ClanStore:
|
|||||||
self.push_history_entry(vm)
|
self.push_history_entry(vm)
|
||||||
return GLib.SOURCE_REMOVE
|
return GLib.SOURCE_REMOVE
|
||||||
|
|
||||||
|
@profile
|
||||||
def push_history_entry(self, entry: HistoryEntry) -> None:
|
def push_history_entry(self, entry: HistoryEntry) -> None:
|
||||||
# TODO: We shouldn't do this here but in the list view
|
# TODO: We shouldn't do this here but in the list view
|
||||||
if entry.flake.icon is None:
|
if entry.flake.icon is None:
|
||||||
|
Loading…
Reference in New Issue
Block a user