22import inspect
33import logging
44from collections .abc import Callable
5+ from contextlib import ContextDecorator
56from copy import deepcopy
7+ from datetime import datetime
68from enum import Enum
7- from typing import Any , Protocol
9+ from types import TracebackType
10+ from typing import Any , Final , Protocol
811
912import arrow
1013from aiohttp import web
1518
1619from .application_keys import APP_CONFIG_KEY , APP_SETTINGS_KEY
1720
18- log = logging .getLogger (__name__ )
21+ _logger = logging .getLogger (__name__ )
1922
20- APP_SETUP_COMPLETED_KEY = f"{ __name__ } .setup"
23+ APP_SETUP_COMPLETED_KEY : Final [ str ] = f"{ __name__ } .setup"
2124
2225
2326class _SetupFunc (Protocol ):
2427 __name__ : str
2528
26- def __call__ (self , app : web .Application , * args : Any , ** kwds : Any ) -> bool :
27- ...
29+ def __call__ (self , app : web .Application , * args : Any , ** kwds : Any ) -> bool : ...
2830
2931
3032class _ApplicationSettings (Protocol ):
31- def is_enabled (self , field_name : str ) -> bool :
32- ...
33+ def is_enabled (self , field_name : str ) -> bool : ...
3334
3435
3536class ModuleCategory (Enum ):
@@ -46,12 +47,10 @@ def __init__(self, *, reason) -> None:
4647 super ().__init__ (reason )
4748
4849
49- class ApplicationSetupError (Exception ):
50- ...
50+ class ApplicationSetupError (Exception ): ...
5151
5252
53- class DependencyError (ApplicationSetupError ):
54- ...
53+ class DependencyError (ApplicationSetupError ): ...
5554
5655
5756class SetupMetadataDict (TypedDict ):
@@ -134,20 +133,122 @@ def _get_app_settings_and_field_name(
134133 return app_settings , settings_field_name
135134
136135
136+ class _SetupTimingContext (ContextDecorator ):
137+ """Context manager/decorator for timing and logging module setup operations."""
138+
139+ def __init__ (
140+ self ,
141+ module_name : str ,
142+ * ,
143+ logger : logging .Logger ,
144+ category : ModuleCategory | None = None ,
145+ depends : list [str ] | None = None ,
146+ ) -> None :
147+ """Initialize timing context.
148+
149+ :param module_name: Name of the module being set up
150+ :param category: Optional module category for detailed logging
151+ :param depends: Optional dependencies for detailed logging
152+ """
153+ self .module_name = module_name
154+ self .category = category
155+ self .depends = depends
156+ self .started : datetime | None = None
157+ self .head_msg = f"Setup of { module_name } "
158+ self .logger = logger
159+
160+ def __enter__ (self ) -> None :
161+ self .started = arrow .utcnow ().datetime
162+ if self .category is not None :
163+ self .logger .info (
164+ "%s (%s, %s) started ... " ,
165+ self .head_msg ,
166+ f"{ self .category .name = } " ,
167+ f"{ self .depends } " ,
168+ )
169+ else :
170+ self .logger .info ("%s started ..." , self .head_msg )
171+
172+ def __exit__ (
173+ self ,
174+ exc_type : type [BaseException ] | None ,
175+ exc_val : BaseException | None ,
176+ exc_tb : TracebackType | None ,
177+ ) -> None :
178+ if self .started :
179+ elapsed = (arrow .utcnow () - self .started ).total_seconds ()
180+ _logger .info ("%s completed [Elapsed: %3.1f secs]" , self .head_msg , elapsed )
181+
182+
137183# PUBLIC API ------------------------------------------------------------------
138184
139185
140186def is_setup_completed (module_name : str , app : web .Application ) -> bool :
141187 return module_name in app [APP_SETUP_COMPLETED_KEY ]
142188
143189
190+ def ensure_single_setup (
191+ module_name : str ,
192+ * ,
193+ logger : logging .Logger ,
194+ ) -> Callable [[Callable [..., Any ]], Callable [..., Any ]]:
195+ """Ensures a setup function is executed only once per application and handles completion.
196+
197+ :param module_name: Name of the module being set up
198+ """
199+
200+ def _log_skip (reason : str ) -> bool :
201+ logger .info ("Skipping '%s' setup: %s" , module_name , reason )
202+ return False
203+
204+ def decorator (setup_func : _SetupFunc ) -> _SetupFunc :
205+
206+ @functools .wraps (setup_func )
207+ def _wrapper (app : web .Application , * args : Any , ** kwargs : Any ) -> bool :
208+
209+ # pre-setup init
210+ if APP_SETUP_COMPLETED_KEY not in app :
211+ app [APP_SETUP_COMPLETED_KEY ] = []
212+
213+ # check
214+ if is_setup_completed (module_name , app ):
215+ _log_skip (
216+ f"'{ module_name } ' was already initialized in { app } ."
217+ " Setup can only be executed once per app."
218+ )
219+ return False
220+
221+ try :
222+ completed = setup_func (app , * args , ** kwargs )
223+
224+ # post-setup handling
225+ if completed is None :
226+ completed = True
227+
228+ if completed : # registers completed setup
229+ app [APP_SETUP_COMPLETED_KEY ].append (module_name )
230+ return completed
231+
232+ assert not completed # nosec
233+ _log_skip ("Undefined (setup function returned false)" )
234+ return False
235+
236+ except SkipModuleSetupError as err :
237+ _log_skip (err .reason )
238+ return False
239+
240+ return _wrapper
241+
242+ return decorator
243+
244+
144245def app_module_setup (
145246 module_name : str ,
146247 category : ModuleCategory ,
147248 * ,
148249 settings_name : str | None = None ,
149250 depends : list [str ] | None = None ,
150- logger : logging .Logger = log ,
251+ logger : logging .Logger = _logger ,
151252 # TODO: SEE https://github.com/ITISFoundation/osparc-simcore/issues/2008
152253 # TODO: - settings_name becomes module_name!!
153254 # TODO: - plugin base should be aware of setup and settings -> model instead of function?
@@ -190,35 +291,27 @@ def setup(app: web.Application):
190291 module_name , depends , config_section , config_enabled
191292 )
192293
193- def _decorate (setup_func : _SetupFunc ):
194- if "setup" not in setup_func .__name__ :
195- logger .warning ("Rename '%s' to contain 'setup'" , setup_func .__name__ )
196-
197- # metadata info
198- def setup_metadata () -> SetupMetadataDict :
199- return SetupMetadataDict (
200- module_name = module_name ,
201- dependencies = depends ,
202- config_section = section ,
203- config_enabled = config_enabled ,
204- )
294+ # metadata info
295+ def _setup_metadata () -> SetupMetadataDict :
296+ return SetupMetadataDict (
297+ module_name = module_name ,
298+ dependencies = depends ,
299+ config_section = section ,
300+ config_enabled = config_enabled ,
301+ )
205302
206- # wrapper
207- @functools .wraps (setup_func )
208- def _wrapper (app : web .Application , * args , ** kargs ) -> bool :
209- # pre-setup
210- head_msg = f"Setup of { module_name } "
211- started = arrow .utcnow ()
212- logger .info (
213- "%s (%s, %s) started ... " ,
214- head_msg ,
215- f"{ category .name = } " ,
216- f"{ depends } " ,
217- )
303+ def decorator (setup_func : _SetupFunc ) -> _SetupFunc :
218304
219- if APP_SETUP_COMPLETED_KEY not in app :
220- app [APP_SETUP_COMPLETED_KEY ] = []
305+ assert ( # nosec
306+ "setup_" in setup_func .__name__
307+ ), f"Rename '{ setup_func .__name__ } ' like 'setup_$(plugin-name)'"
221308
309+ @functools .wraps (setup_func )
310+ @ensure_single_setup (module_name , logger = logger )
311+ @_SetupTimingContext (
312+ module_name , category = category , depends = depends , logger = logger
313+ )
314+ def _wrapper (app : web .Application , * args , ** kargs ) -> bool :
222315 if category == ModuleCategory .ADDON :
223316 # ONLY addons can be enabled/disabled
224317
@@ -258,60 +351,31 @@ def _wrapper(app: web.Application, *args, **kargs) -> bool:
258351 return False
259352
260353 if depends :
261- # TODO: no need to enforce. Use to deduce order instead.
262354 uninitialized = [
263355 dep for dep in depends if not is_setup_completed (dep , app )
264356 ]
265357 if uninitialized :
266358 msg = f"Cannot setup app module '{ module_name } ' because the following dependencies are still uninitialized: { uninitialized } "
267359 raise DependencyError (msg )
268360
269- # execution of setup
270- try :
271- if is_setup_completed (module_name , app ):
272- raise SkipModuleSetupError ( # noqa: TRY301
273- reason = f"'{ module_name } ' was already initialized in { app } ."
274- " Setup can only be executed once per app."
275- )
276-
277- completed = setup_func (app , * args , ** kargs )
278-
279- # post-setup
280- if completed is None :
281- completed = True
282-
283- if completed : # registers completed setup
284- app [APP_SETUP_COMPLETED_KEY ].append (module_name )
285- else :
286- raise SkipModuleSetupError ( # noqa: TRY301
287- reason = "Undefined (setup function returned false)"
288- )
361+ # execution of setup with module name
362+ completed : bool = setup_func (app , * args , ** kargs )
289363
290- except SkipModuleSetupError as exc :
291- logger .info ("Skipping '%s' setup: %s" , module_name , exc .reason )
292- completed = False
293-
294- elapsed = arrow .utcnow () - started
295- logger .info (
296- "%s %s [Elapsed: %3.1f secs]" ,
297- head_msg ,
298- "completed" if completed else "skipped" ,
299- elapsed .total_seconds (),
300- )
301364 return completed
302365
303- _wrapper .metadata = setup_metadata # type: ignore[attr-defined]
304- _wrapper .mark_as_simcore_servicelib_setup_func = True # type: ignore[attr-defined]
305- # NOTE: this is added by functools.wraps decorated
306- assert _wrapper .__wrapped__ == setup_func # nosec
366+ assert (
367+ _wrapper .__wrapped__ == setup_func
368+ ), "this is added by functools.wraps decorator" # nosec
369+
370+ setattr (_wrapper , "metadata" , _setup_metadata ) # noqa: B010
371+ setattr (_wrapper , "mark_as_simcore_servicelib_setup_func" , True ) # noqa: B010
307372
308373 return _wrapper
309374
310- return _decorate
375+ return decorator
311376
312377
313378def is_setup_function (fun : Callable ) -> bool :
314- # TODO: use _SetupFunc protocol to check in runtime
315379 return (
316380 inspect .isfunction (fun )
317381 and hasattr (fun , "mark_as_simcore_servicelib_setup_func" )
0 commit comments