From a4b029d03c952067287a9e5b0ceb2c2a58d18cc0 Mon Sep 17 00:00:00 2001 From: Lincoln Stein Date: Tue, 15 Aug 2023 18:21:31 -0400 Subject: [PATCH 1/9] write RAM usage and change after each generation --- invokeai/app/services/invocation_stats.py | 50 ++++++++++++++++------- 1 file changed, 36 insertions(+), 14 deletions(-) diff --git a/invokeai/app/services/invocation_stats.py b/invokeai/app/services/invocation_stats.py index 50320a6611..9d50375c09 100644 --- a/invokeai/app/services/invocation_stats.py +++ b/invokeai/app/services/invocation_stats.py @@ -29,6 +29,7 @@ The abstract base class for this class is InvocationStatsServiceBase. An impleme writes to the system log is stored in InvocationServices.performance_statistics. """ +import psutil import time from abc import ABC, abstractmethod from contextlib import AbstractContextManager @@ -83,13 +84,14 @@ class InvocationStatsServiceBase(ABC): pass @abstractmethod - def update_invocation_stats( - self, - graph_id: str, - invocation_type: str, - time_used: float, - vram_used: float, - ): + def update_invocation_stats(self, + graph_id: str, + invocation_type: str, + time_used: float, + vram_used: float, + ram_used: float, + ram_changed: float, + ): """ Add timing information on execution of a node. Usually used internally. @@ -97,6 +99,8 @@ class InvocationStatsServiceBase(ABC): :param invocation_type: String literal type of the node :param time_used: Time used by node's exection (sec) :param vram_used: Maximum VRAM used during exection (GB) + :param ram_used: Current RAM available (GB) + :param ram_changed: Change in RAM usage over course of the run (GB) """ pass @@ -140,18 +144,23 @@ class InvocationStatsService(InvocationStatsServiceBase): self.collector = collector self.graph_id = graph_id self.start_time = 0 + self.ram_info = None def __enter__(self): self.start_time = time.time() if torch.cuda.is_available(): torch.cuda.reset_peak_memory_stats() + self.ram_info = psutil.virtual_memory() + def __exit__(self, *args): self.collector.update_invocation_stats( - self.graph_id, - self.invocation.type, - time.time() - self.start_time, - torch.cuda.max_memory_allocated() / 1e9 if torch.cuda.is_available() else 0.0, + graph_id = self.graph_id, + invocation_type = self.invocation.type, + time_used = time.time() - self.start_time, + vram_used = torch.cuda.max_memory_allocated() / 1e9 if torch.cuda.is_available() else 0.0, + ram_used = psutil.virtual_memory().used / 1e9, + ram_changed = (psutil.virtual_memory().used - self.ram_info.used) / 1e9, ) def collect_stats( @@ -179,13 +188,23 @@ class InvocationStatsService(InvocationStatsServiceBase): except KeyError: logger.warning(f"Attempted to clear statistics for unknown graph {graph_execution_id}") - def update_invocation_stats(self, graph_id: str, invocation_type: str, time_used: float, vram_used: float): + def update_invocation_stats(self, + graph_id: str, + invocation_type: str, + time_used: float, + vram_used: float, + ram_used: float, + ram_changed: float, + ): """ Add timing information on execution of a node. Usually used internally. :param graph_id: ID of the graph that is currently executing :param invocation_type: String literal type of the node - :param time_used: Floating point seconds used by node's exection + :param time_used: Time used by node's exection (sec) + :param vram_used: Maximum VRAM used during exection (GB) + :param ram_used: Current RAM available (GB) + :param ram_changed: Change in RAM usage over course of the run (GB) """ if not self._stats[graph_id].nodes.get(invocation_type): self._stats[graph_id].nodes[invocation_type] = NodeStats() @@ -193,6 +212,8 @@ class InvocationStatsService(InvocationStatsServiceBase): stats.calls += 1 stats.time_used += time_used stats.max_vram = max(stats.max_vram, vram_used) + stats.ram_used = ram_used + stats.ram_changed = ram_changed def log_stats(self): """ @@ -214,8 +235,9 @@ class InvocationStatsService(InvocationStatsServiceBase): total_time += stats.time_used logger.info(f"TOTAL GRAPH EXECUTION TIME: {total_time:7.3f}s") + logger.info("Current RAM used: " + "%4.2fG" % stats.ram_used + f" (delta={stats.ram_changed:4.2f}G)") if torch.cuda.is_available(): - logger.info("Current VRAM utilization " + "%4.2fG" % (torch.cuda.memory_allocated() / 1e9)) + logger.info("Current VRAM used: " + "%4.2fG" % (torch.cuda.memory_allocated() / 1e9)) completed.add(graph_id) From ec10aca91ed3d17487fd546b8b49c257d17f3203 Mon Sep 17 00:00:00 2001 From: Lincoln Stein Date: Tue, 15 Aug 2023 21:00:30 -0400 Subject: [PATCH 2/9] report RAM and RAM cache statistics --- invokeai/app/services/invocation_stats.py | 95 +++++++++++++------ .../app/services/model_manager_service.py | 14 +++ invokeai/app/services/processor.py | 4 +- .../backend/model_management/model_cache.py | 38 +++++++- 4 files changed, 115 insertions(+), 36 deletions(-) diff --git a/invokeai/app/services/invocation_stats.py b/invokeai/app/services/invocation_stats.py index 9d50375c09..484544e40d 100644 --- a/invokeai/app/services/invocation_stats.py +++ b/invokeai/app/services/invocation_stats.py @@ -43,6 +43,11 @@ import invokeai.backend.util.logging as logger from ..invocations.baseinvocation import BaseInvocation from .graph import GraphExecutionState from .item_storage import ItemStorageABC +from .model_manager_service import ModelManagerService +from invokeai.backend.model_management.model_cache import CacheStats + +# size of GIG in bytes +GIG = 1073741824 class InvocationStatsServiceBase(ABC): @@ -84,14 +89,15 @@ class InvocationStatsServiceBase(ABC): pass @abstractmethod - def update_invocation_stats(self, - graph_id: str, - invocation_type: str, - time_used: float, - vram_used: float, - ram_used: float, - ram_changed: float, - ): + def update_invocation_stats( + self, + graph_id: str, + invocation_type: str, + time_used: float, + vram_used: float, + ram_used: float, + ram_changed: float, + ): """ Add timing information on execution of a node. Usually used internally. @@ -119,6 +125,9 @@ class NodeStats: calls: int = 0 time_used: float = 0.0 # seconds max_vram: float = 0.0 # GB + cache_hits: int = 0 + cache_misses: int = 0 + cache_high_watermark: int = 0 @dataclass @@ -137,36 +146,50 @@ class InvocationStatsService(InvocationStatsServiceBase): self.graph_execution_manager = graph_execution_manager # {graph_id => NodeLog} self._stats: Dict[str, NodeLog] = {} + self._cache_stats: Dict[str, CacheStats] = {} class StatsContext: - def __init__(self, invocation: BaseInvocation, graph_id: str, collector: "InvocationStatsServiceBase"): + """Context manager for collecting statistics.""" + + def __init__( + self, + invocation: BaseInvocation, + graph_id: str, + model_manager: ModelManagerService, + collector: "InvocationStatsServiceBase", + ): + """Initialize statistics for this run.""" self.invocation = invocation self.collector = collector self.graph_id = graph_id self.start_time = 0 - self.ram_info = None + self.ram_used = 0 + self.model_manager = model_manager def __enter__(self): self.start_time = time.time() if torch.cuda.is_available(): torch.cuda.reset_peak_memory_stats() - self.ram_info = psutil.virtual_memory() - + self.ram_used = psutil.Process().memory_info().rss + self.model_manager.collect_cache_stats(self.collector._cache_stats[self.graph_id]) def __exit__(self, *args): + """Called on exit from the context.""" + ram_used = psutil.Process().memory_info().rss self.collector.update_invocation_stats( - graph_id = self.graph_id, - invocation_type = self.invocation.type, - time_used = time.time() - self.start_time, - vram_used = torch.cuda.max_memory_allocated() / 1e9 if torch.cuda.is_available() else 0.0, - ram_used = psutil.virtual_memory().used / 1e9, - ram_changed = (psutil.virtual_memory().used - self.ram_info.used) / 1e9, + graph_id=self.graph_id, + invocation_type=self.invocation.type, + time_used=time.time() - self.start_time, + vram_used=torch.cuda.max_memory_allocated() / GIG if torch.cuda.is_available() else 0.0, + ram_used=ram_used / GIG, + ram_changed=(ram_used - self.ram_used) / GIG, ) def collect_stats( self, invocation: BaseInvocation, graph_execution_state_id: str, + model_manager: ModelManagerService, ) -> StatsContext: """ Return a context object that will capture the statistics. @@ -175,7 +198,8 @@ class InvocationStatsService(InvocationStatsServiceBase): """ if not self._stats.get(graph_execution_state_id): # first time we're seeing this self._stats[graph_execution_state_id] = NodeLog() - return self.StatsContext(invocation, graph_execution_state_id, self) + self._cache_stats[graph_execution_state_id] = CacheStats() + return self.StatsContext(invocation, graph_execution_state_id, model_manager, self) def reset_all_stats(self): """Zero all statistics""" @@ -188,14 +212,15 @@ class InvocationStatsService(InvocationStatsServiceBase): except KeyError: logger.warning(f"Attempted to clear statistics for unknown graph {graph_execution_id}") - def update_invocation_stats(self, - graph_id: str, - invocation_type: str, - time_used: float, - vram_used: float, - ram_used: float, - ram_changed: float, - ): + def update_invocation_stats( + self, + graph_id: str, + invocation_type: str, + time_used: float, + vram_used: float, + ram_used: float, + ram_changed: float, + ): """ Add timing information on execution of a node. Usually used internally. @@ -218,7 +243,7 @@ class InvocationStatsService(InvocationStatsServiceBase): def log_stats(self): """ Send the statistics to the system logger at the info level. - Stats will only be printed if when the execution of the graph + Stats will only be printed when the execution of the graph is complete. """ completed = set() @@ -235,11 +260,21 @@ class InvocationStatsService(InvocationStatsServiceBase): total_time += stats.time_used logger.info(f"TOTAL GRAPH EXECUTION TIME: {total_time:7.3f}s") - logger.info("Current RAM used: " + "%4.2fG" % stats.ram_used + f" (delta={stats.ram_changed:4.2f}G)") + logger.info("RAM used: " + "%4.2fG" % stats.ram_used + f" (delta={stats.ram_changed:4.2f}G)") if torch.cuda.is_available(): - logger.info("Current VRAM used: " + "%4.2fG" % (torch.cuda.memory_allocated() / 1e9)) + logger.info("VRAM used (all processes): " + "%4.2fG" % (torch.cuda.memory_allocated() / GIG)) + cache_stats = self._cache_stats[graph_id] + logger.info("RAM cache statistics:") + logger.info(f" Model cache hits: {cache_stats.hits}") + logger.info(f" Model cache misses: {cache_stats.misses}") + logger.info(f" Models cached: {cache_stats.in_cache}") + logger.info(f" Models cleared from cache: {cache_stats.cleared}") + hwm = cache_stats.high_watermark / GIG + tot = cache_stats.cache_size / GIG + logger.info(f" Cache RAM usage: {hwm:4.2f}/{tot:4.2f}G") completed.add(graph_id) for graph_id in completed: del self._stats[graph_id] + del self._cache_stats[graph_id] diff --git a/invokeai/app/services/model_manager_service.py b/invokeai/app/services/model_manager_service.py index fd14e26364..675bc71257 100644 --- a/invokeai/app/services/model_manager_service.py +++ b/invokeai/app/services/model_manager_service.py @@ -22,6 +22,7 @@ from invokeai.backend.model_management import ( ModelNotFoundException, ) from invokeai.backend.model_management.model_search import FindModels +from invokeai.backend.model_management.model_cache import CacheStats import torch from invokeai.app.models.exceptions import CanceledException @@ -276,6 +277,13 @@ class ModelManagerServiceBase(ABC): """ pass + @abstractmethod + def collect_cache_stats(self, cache_stats: CacheStats): + """ + Reset model cache statistics for graph with graph_id. + """ + pass + @abstractmethod def commit(self, conf_file: Optional[Path] = None) -> None: """ @@ -500,6 +508,12 @@ class ModelManagerService(ModelManagerServiceBase): self.logger.debug(f"convert model {model_name}") return self.mgr.convert_model(model_name, base_model, model_type, convert_dest_directory) + def collect_cache_stats(self, cache_stats: CacheStats): + """ + Reset model cache statistics for graph with graph_id. + """ + self.mgr.cache.stats = cache_stats + def commit(self, conf_file: Optional[Path] = None): """ Write current configuration out to the indicated file. diff --git a/invokeai/app/services/processor.py b/invokeai/app/services/processor.py index 41170a304b..6f35b3cb9e 100644 --- a/invokeai/app/services/processor.py +++ b/invokeai/app/services/processor.py @@ -86,7 +86,9 @@ class DefaultInvocationProcessor(InvocationProcessorABC): # Invoke try: - with statistics.collect_stats(invocation, graph_execution_state.id): + graph_id = graph_execution_state.id + model_manager = self.__invoker.services.model_manager + with statistics.collect_stats(invocation, graph_id, model_manager): outputs = invocation.invoke( InvocationContext( services=self.__invoker.services, diff --git a/invokeai/backend/model_management/model_cache.py b/invokeai/backend/model_management/model_cache.py index 2b8d020269..a610694d0e 100644 --- a/invokeai/backend/model_management/model_cache.py +++ b/invokeai/backend/model_management/model_cache.py @@ -21,12 +21,12 @@ import os import sys import hashlib from contextlib import suppress +from dataclasses import dataclass from pathlib import Path from typing import Dict, Union, types, Optional, Type, Any import torch -import logging import invokeai.backend.util.logging as logger from .models import BaseModelType, ModelType, SubModelType, ModelBase @@ -41,6 +41,16 @@ DEFAULT_MAX_VRAM_CACHE_SIZE = 2.75 GIG = 1073741824 +@dataclass +class CacheStats(object): + hits: int = 0 + misses: int = 0 + high_watermark: int = 0 + in_cache: int = 0 + cleared: int = 0 + cache_size: int = 0 + + class ModelLocker(object): "Forward declaration" pass @@ -115,6 +125,9 @@ class ModelCache(object): self.sha_chunksize = sha_chunksize self.logger = logger + # used for stats collection + self.stats = None + self._cached_models = dict() self._cache_stack = list() @@ -188,6 +201,8 @@ class ModelCache(object): self.logger.info( f"Loading model {model_path}, type {base_model.value}:{model_type.value}{':'+submodel.value if submodel else ''}" ) + if self.stats: + self.stats.misses += 1 # this will remove older cached models until # there is sufficient room to load the requested model @@ -201,6 +216,14 @@ class ModelCache(object): cache_entry = _CacheRecord(self, model, mem_used) self._cached_models[key] = cache_entry + else: + if self.stats: + self.stats.hits += 1 + self.stats.cache_size = self.max_cache_size * GIG + + if self.stats: + self.stats.high_watermark = max(self.stats.high_watermark, self._cache_size()) + self.stats.in_cache = len(self._cached_models) with suppress(Exception): self._cache_stack.remove(key) @@ -280,14 +303,14 @@ class ModelCache(object): """ Given the HF repo id or path to a model on disk, returns a unique hash. Works for legacy checkpoint files, HF models on disk, and HF repo IDs + :param model_path: Path to model file/directory on disk. """ return self._local_model_hash(model_path) def cache_size(self) -> float: - "Return the current size of the cache, in GB" - current_cache_size = sum([m.size for m in self._cached_models.values()]) - return current_cache_size / GIG + """Return the current size of the cache, in GB.""" + return self._cache_size() / GIG def _has_cuda(self) -> bool: return self.execution_device.type == "cuda" @@ -310,12 +333,15 @@ class ModelCache(object): f"Current VRAM/RAM usage: {vram}/{ram}; cached_models/loaded_models/locked_models/ = {cached_models}/{loaded_models}/{locked_models}" ) + def _cache_size(self) -> int: + return sum([m.size for m in self._cached_models.values()]) + def _make_cache_room(self, model_size): # calculate how much memory this model will require # multiplier = 2 if self.precision==torch.float32 else 1 bytes_needed = model_size maximum_size = self.max_cache_size * GIG # stored in GB, convert to bytes - current_size = sum([m.size for m in self._cached_models.values()]) + current_size = self._cache_size() if current_size + bytes_needed > maximum_size: self.logger.debug( @@ -364,6 +390,8 @@ class ModelCache(object): f"Unloading model {model_key} to free {(model_size/GIG):.2f} GB (-{(cache_entry.size/GIG):.2f} GB)" ) current_size -= cache_entry.size + if self.stats: + self.stats.cleared += 1 del self._cache_stack[pos] del self._cached_models[model_key] del cache_entry From f9958de6be8b11284c0d4d96e6afad56baafbbeb Mon Sep 17 00:00:00 2001 From: Lincoln Stein Date: Tue, 15 Aug 2023 21:56:19 -0400 Subject: [PATCH 3/9] added memory used to load models --- invokeai/app/services/invocation_stats.py | 21 +++++++++++------- .../backend/model_management/model_cache.py | 22 +++++++++++-------- 2 files changed, 26 insertions(+), 17 deletions(-) diff --git a/invokeai/app/services/invocation_stats.py b/invokeai/app/services/invocation_stats.py index 484544e40d..4c1c65a998 100644 --- a/invokeai/app/services/invocation_stats.py +++ b/invokeai/app/services/invocation_stats.py @@ -256,22 +256,27 @@ class InvocationStatsService(InvocationStatsServiceBase): logger.info(f"Graph stats: {graph_id}") logger.info("Node Calls Seconds VRAM Used") for node_type, stats in self._stats[graph_id].nodes.items(): - logger.info(f"{node_type:<20} {stats.calls:>5} {stats.time_used:7.3f}s {stats.max_vram:4.2f}G") + logger.info(f"{node_type:<20} {stats.calls:>5} {stats.time_used:7.3f}s {stats.max_vram:4.3f}G") total_time += stats.time_used - logger.info(f"TOTAL GRAPH EXECUTION TIME: {total_time:7.3f}s") - logger.info("RAM used: " + "%4.2fG" % stats.ram_used + f" (delta={stats.ram_changed:4.2f}G)") - if torch.cuda.is_available(): - logger.info("VRAM used (all processes): " + "%4.2fG" % (torch.cuda.memory_allocated() / GIG)) cache_stats = self._cache_stats[graph_id] + hwm = cache_stats.high_watermark / GIG + tot = cache_stats.cache_size / GIG + loaded = sum([v for v in cache_stats.loaded_model_sizes.values()]) / GIG + + logger.info(f"TOTAL GRAPH EXECUTION TIME: {total_time:7.3f}s") + logger.info( + "RAM used by InvokeAI process: " + "%4.2fG" % stats.ram_used + f" (delta={stats.ram_changed:4.2f}G)" + ) + logger.info(f"RAM used to load models: {loaded:4.2f}G") + if torch.cuda.is_available(): + logger.info("VRAM in use: " + "%4.3fG" % (torch.cuda.memory_allocated() / GIG)) logger.info("RAM cache statistics:") logger.info(f" Model cache hits: {cache_stats.hits}") logger.info(f" Model cache misses: {cache_stats.misses}") logger.info(f" Models cached: {cache_stats.in_cache}") logger.info(f" Models cleared from cache: {cache_stats.cleared}") - hwm = cache_stats.high_watermark / GIG - tot = cache_stats.cache_size / GIG - logger.info(f" Cache RAM usage: {hwm:4.2f}/{tot:4.2f}G") + logger.info(f" Cache high water mark: {hwm:4.2f}/{tot:4.2f}G") completed.add(graph_id) diff --git a/invokeai/backend/model_management/model_cache.py b/invokeai/backend/model_management/model_cache.py index a610694d0e..e83fd68102 100644 --- a/invokeai/backend/model_management/model_cache.py +++ b/invokeai/backend/model_management/model_cache.py @@ -21,7 +21,7 @@ import os import sys import hashlib from contextlib import suppress -from dataclasses import dataclass +from dataclasses import dataclass, field from pathlib import Path from typing import Dict, Union, types, Optional, Type, Any @@ -43,12 +43,14 @@ GIG = 1073741824 @dataclass class CacheStats(object): - hits: int = 0 - misses: int = 0 - high_watermark: int = 0 - in_cache: int = 0 - cleared: int = 0 - cache_size: int = 0 + hits: int = 0 # cache hits + misses: int = 0 # cache misses + high_watermark: int = 0 # amount of cache used + in_cache: int = 0 # number of models in cache + cleared: int = 0 # number of models cleared to make space + cache_size: int = 0 # total size of cache + # {submodel_key => size} + loaded_model_sizes: Dict[str, int] = field(default_factory=dict) class ModelLocker(object): @@ -194,7 +196,6 @@ class ModelCache(object): model_type=model_type, submodel_type=submodel, ) - # TODO: lock for no copies on simultaneous calls? cache_entry = self._cached_models.get(key, None) if cache_entry is None: @@ -219,11 +220,14 @@ class ModelCache(object): else: if self.stats: self.stats.hits += 1 - self.stats.cache_size = self.max_cache_size * GIG if self.stats: + self.stats.cache_size = self.max_cache_size * GIG self.stats.high_watermark = max(self.stats.high_watermark, self._cache_size()) self.stats.in_cache = len(self._cached_models) + self.stats.loaded_model_sizes[key] = max( + self.stats.loaded_model_sizes.get("key", 0), model_info.get_size(submodel) + ) with suppress(Exception): self._cache_stack.remove(key) From 21e1c0a5f0e0cbe7fa1ab08e45ba6e0d34423a19 Mon Sep 17 00:00:00 2001 From: Lincoln Stein Date: Tue, 15 Aug 2023 22:25:30 -0400 Subject: [PATCH 4/9] tweaked formatting --- invokeai/app/services/invocation_stats.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/invokeai/app/services/invocation_stats.py b/invokeai/app/services/invocation_stats.py index 4c1c65a998..1b2217e422 100644 --- a/invokeai/app/services/invocation_stats.py +++ b/invokeai/app/services/invocation_stats.py @@ -254,9 +254,9 @@ class InvocationStatsService(InvocationStatsServiceBase): total_time = 0 logger.info(f"Graph stats: {graph_id}") - logger.info("Node Calls Seconds VRAM Used") + logger.info(f"{'Node':>30} {'Calls':>7}{'Seconds':>9} {'VRAM Used':>10}") for node_type, stats in self._stats[graph_id].nodes.items(): - logger.info(f"{node_type:<20} {stats.calls:>5} {stats.time_used:7.3f}s {stats.max_vram:4.3f}G") + logger.info(f"{node_type:>30} {stats.calls:>4} {stats.time_used:7.3f}s {stats.max_vram:4.3f}G") total_time += stats.time_used cache_stats = self._cache_stats[graph_id] From bb1b8ceaa8de08809e56db4e866890410c30a882 Mon Sep 17 00:00:00 2001 From: Lincoln Stein Date: Wed, 16 Aug 2023 08:48:44 -0400 Subject: [PATCH 5/9] Update invokeai/backend/model_management/model_cache.py Co-authored-by: StAlKeR7779 --- invokeai/backend/model_management/model_cache.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/invokeai/backend/model_management/model_cache.py b/invokeai/backend/model_management/model_cache.py index e83fd68102..a11e0a8a8f 100644 --- a/invokeai/backend/model_management/model_cache.py +++ b/invokeai/backend/model_management/model_cache.py @@ -226,7 +226,7 @@ class ModelCache(object): self.stats.high_watermark = max(self.stats.high_watermark, self._cache_size()) self.stats.in_cache = len(self._cached_models) self.stats.loaded_model_sizes[key] = max( - self.stats.loaded_model_sizes.get("key", 0), model_info.get_size(submodel) + self.stats.loaded_model_sizes.get(key, 0), model_info.get_size(submodel) ) with suppress(Exception): From a93bd013537bd4278012f79ed04583d4717495ac Mon Sep 17 00:00:00 2001 From: Lincoln Stein Date: Wed, 16 Aug 2023 08:53:07 -0400 Subject: [PATCH 6/9] fix bad merge --- invokeai/app/services/invocation_stats.py | 3 ++- invokeai/app/services/processor.py | 2 +- 2 files changed, 3 insertions(+), 2 deletions(-) diff --git a/invokeai/app/services/invocation_stats.py b/invokeai/app/services/invocation_stats.py index 1b2217e422..b49084e6fe 100644 --- a/invokeai/app/services/invocation_stats.py +++ b/invokeai/app/services/invocation_stats.py @@ -171,7 +171,8 @@ class InvocationStatsService(InvocationStatsServiceBase): if torch.cuda.is_available(): torch.cuda.reset_peak_memory_stats() self.ram_used = psutil.Process().memory_info().rss - self.model_manager.collect_cache_stats(self.collector._cache_stats[self.graph_id]) + if self.model_manager: + self.model_manager.collect_cache_stats(self.collector._cache_stats[self.graph_id]) def __exit__(self, *args): """Called on exit from the context.""" diff --git a/invokeai/app/services/processor.py b/invokeai/app/services/processor.py index dba8ae8906..37da17d318 100644 --- a/invokeai/app/services/processor.py +++ b/invokeai/app/services/processor.py @@ -88,7 +88,7 @@ class DefaultInvocationProcessor(InvocationProcessorABC): try: graph_id = graph_execution_state.id model_manager = self.__invoker.services.model_manager - with statistics.collect_stats(invocation, graph_id model_manager): + with statistics.collect_stats(invocation, graph_id, model_manager): # use the internal invoke_internal(), which wraps the node's invoke() method in # this accomodates nodes which require a value, but get it only from a # connection From 2ca8611723b3c602bc4cab732b2e28ca724d4fd9 Mon Sep 17 00:00:00 2001 From: Lincoln Stein Date: Wed, 16 Aug 2023 15:53:01 -0400 Subject: [PATCH 7/9] add +/- sign in front of RAM delta --- invokeai/app/services/invocation_stats.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/invokeai/app/services/invocation_stats.py b/invokeai/app/services/invocation_stats.py index b49084e6fe..0cef3d5e29 100644 --- a/invokeai/app/services/invocation_stats.py +++ b/invokeai/app/services/invocation_stats.py @@ -266,9 +266,7 @@ class InvocationStatsService(InvocationStatsServiceBase): loaded = sum([v for v in cache_stats.loaded_model_sizes.values()]) / GIG logger.info(f"TOTAL GRAPH EXECUTION TIME: {total_time:7.3f}s") - logger.info( - "RAM used by InvokeAI process: " + "%4.2fG" % stats.ram_used + f" (delta={stats.ram_changed:4.2f}G)" - ) + logger.info("RAM used by InvokeAI process: " + "%4.2fG" % stats.ram_used + f" ({stats.ram_changed:+5.3f}G)") logger.info(f"RAM used to load models: {loaded:4.2f}G") if torch.cuda.is_available(): logger.info("VRAM in use: " + "%4.3fG" % (torch.cuda.memory_allocated() / GIG)) From c39f8b478b55e941e41c7be5d1d494b45d7e4501 Mon Sep 17 00:00:00 2001 From: Lincoln Stein Date: Wed, 16 Aug 2023 21:39:18 -0400 Subject: [PATCH 8/9] fix misplaced ram_used and ram_changed attributes --- invokeai/app/services/invocation_stats.py | 34 ++++++++++++++++++----- 1 file changed, 27 insertions(+), 7 deletions(-) diff --git a/invokeai/app/services/invocation_stats.py b/invokeai/app/services/invocation_stats.py index 0cef3d5e29..d1b6f0c155 100644 --- a/invokeai/app/services/invocation_stats.py +++ b/invokeai/app/services/invocation_stats.py @@ -147,9 +147,17 @@ class InvocationStatsService(InvocationStatsServiceBase): # {graph_id => NodeLog} self._stats: Dict[str, NodeLog] = {} self._cache_stats: Dict[str, CacheStats] = {} + self.ram_used: float = 0.0 + self.ram_changed: float = 0.0 class StatsContext: """Context manager for collecting statistics.""" + invocation: BaseInvocation = None + collector: "InvocationStatsServiceBase" = None + graph_id: str = None + start_time: int = 0 + ram_used: int = 0 + model_manager: ModelManagerService = None def __init__( self, @@ -177,13 +185,15 @@ class InvocationStatsService(InvocationStatsServiceBase): def __exit__(self, *args): """Called on exit from the context.""" ram_used = psutil.Process().memory_info().rss + self.collector.update_mem_stats( + ram_used=ram_used / GIG, + ram_changed=(ram_used - self.ram_used) / GIG, + ) self.collector.update_invocation_stats( graph_id=self.graph_id, invocation_type=self.invocation.type, time_used=time.time() - self.start_time, vram_used=torch.cuda.max_memory_allocated() / GIG if torch.cuda.is_available() else 0.0, - ram_used=ram_used / GIG, - ram_changed=(ram_used - self.ram_used) / GIG, ) def collect_stats( @@ -213,14 +223,26 @@ class InvocationStatsService(InvocationStatsServiceBase): except KeyError: logger.warning(f"Attempted to clear statistics for unknown graph {graph_execution_id}") + def update_mem_stats( + self, + ram_used: float, + ram_changed: float, + ): + """ + Update the collector with RAM memory usage info. + + :param ram_used: How much RAM is currently in use. + :param ram_changed: How much RAM changed since last generation. + """ + self.ram_used = ram_used + self.ram_changed = ram_changed + def update_invocation_stats( self, graph_id: str, invocation_type: str, time_used: float, vram_used: float, - ram_used: float, - ram_changed: float, ): """ Add timing information on execution of a node. Usually @@ -238,8 +260,6 @@ class InvocationStatsService(InvocationStatsServiceBase): stats.calls += 1 stats.time_used += time_used stats.max_vram = max(stats.max_vram, vram_used) - stats.ram_used = ram_used - stats.ram_changed = ram_changed def log_stats(self): """ @@ -266,7 +286,7 @@ class InvocationStatsService(InvocationStatsServiceBase): loaded = sum([v for v in cache_stats.loaded_model_sizes.values()]) / GIG logger.info(f"TOTAL GRAPH EXECUTION TIME: {total_time:7.3f}s") - logger.info("RAM used by InvokeAI process: " + "%4.2fG" % stats.ram_used + f" ({stats.ram_changed:+5.3f}G)") + logger.info("RAM used by InvokeAI process: " + "%4.2fG" % self.ram_used + f" ({self.ram_changed:+5.3f}G)") logger.info(f"RAM used to load models: {loaded:4.2f}G") if torch.cuda.is_available(): logger.info("VRAM in use: " + "%4.3fG" % (torch.cuda.memory_allocated() / GIG)) From daf75a1361c61e8eda99f731521ae20ee9a0e4bb Mon Sep 17 00:00:00 2001 From: Lincoln Stein Date: Wed, 16 Aug 2023 21:47:29 -0400 Subject: [PATCH 9/9] blackify --- invokeai/app/services/invocation_stats.py | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/invokeai/app/services/invocation_stats.py b/invokeai/app/services/invocation_stats.py index d1b6f0c155..35c3a5e403 100644 --- a/invokeai/app/services/invocation_stats.py +++ b/invokeai/app/services/invocation_stats.py @@ -152,6 +152,7 @@ class InvocationStatsService(InvocationStatsServiceBase): class StatsContext: """Context manager for collecting statistics.""" + invocation: BaseInvocation = None collector: "InvocationStatsServiceBase" = None graph_id: str = None @@ -224,9 +225,9 @@ class InvocationStatsService(InvocationStatsServiceBase): logger.warning(f"Attempted to clear statistics for unknown graph {graph_execution_id}") def update_mem_stats( - self, - ram_used: float, - ram_changed: float, + self, + ram_used: float, + ram_changed: float, ): """ Update the collector with RAM memory usage info.