Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix: optimize loggers when DEBUG enabled #444

Merged
merged 2 commits into from
Nov 25, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
7 changes: 2 additions & 5 deletions a_sync/a_sync/abstract.pyx
Original file line number Diff line number Diff line change
Expand Up @@ -162,8 +162,7 @@ class ASyncABC(metaclass=ASyncMeta):
c_logger._log(
DEBUG,
"checking `%s.%s.__init__` signature against provided kwargs to determine a_sync mode for the new instance",
cls.__module__,
cls.__name__,
(cls.__module__, cls.__name__),
)

cdef str flag = get_flag_name(kwargs)
Expand All @@ -181,9 +180,7 @@ class ASyncABC(metaclass=ASyncMeta):
c_logger._log(
DEBUG,
"kwargs indicate the new instance created with args %s %s is %ssynchronous",
args,
kwargs,
"" if sync else "a",
(args, kwargs, "" if sync else "a"),
)
return sync

Expand Down
19 changes: 8 additions & 11 deletions a_sync/a_sync/base.pyx
Original file line number Diff line number Diff line change
Expand Up @@ -71,7 +71,7 @@ class ASyncGenericBase(ASyncABC):
# TODO: cythonize this cache
cdef bint debug_logs
if debug_logs := c_logger.isEnabledFor(DEBUG):
c_logger._log(DEBUG, "checking a_sync flag for %s", self)
c_logger._log(DEBUG, "checking a_sync flag for %s", (self, ))
try:
flag = _get_a_sync_flag_name_from_signature(type(self))
except exceptions.ASyncFlagException:
Expand All @@ -82,8 +82,7 @@ class ASyncGenericBase(ASyncABC):
c_logger._log(
DEBUG,
"unable to find flag name using `%s.__init__` signature, checking for flag attributes defined on %s",
self.__class__.__name__,
self,
(self.__class__.__name__, self),
)
present_flags = [flag for flag in VIABLE_FLAGS if hasattr(self, flag)]
if not present_flags:
Expand Down Expand Up @@ -132,9 +131,7 @@ class ASyncGenericBase(ASyncABC):
c_logger._log(
DEBUG,
"`%s.%s` indicates default mode is %ssynchronous",
cls,
flag,
"a" if sync is False else "",
(cls, flag, "a" if sync is False else ""),
)
return sync

Expand All @@ -160,15 +157,15 @@ cdef bint _a_sync_flag_default_value_from_signature(object cls):
return signature.parameters[_get_a_sync_flag_name_from_signature(cls)].default

c_logger._log(
DEBUG, "checking `__init__` signature for default %s a_sync flag value", cls
DEBUG, "checking `__init__` signature for default %s a_sync flag value", (cls, )
)
cdef str flag = _get_a_sync_flag_name_from_signature(cls)
cdef object flag_value = signature.parameters[flag].default
if flag_value is inspect._empty: # type: ignore [attr-defined]
raise NotImplementedError(
"The implementation for 'cls' uses an arg to specify sync mode, instead of a kwarg. We are unable to proceed. I suppose we can extend the code to accept positional arg flags if necessary"
)
c_logger._log(DEBUG, "%s defines %s, default value %s", cls, flag, flag_value)
c_logger._log(DEBUG, "%s defines %s, default value %s", (cls, flag, flag_value))
return flag_value


Expand All @@ -184,9 +181,9 @@ cdef str _get_a_sync_flag_name_from_signature(object cls):
# we can also skip assigning params to a var
return _parse_flag_name_from_list(cls, inspect.signature(cls.__init__).parameters)

c_logger._log(DEBUG, "Searching for flags defined on %s.__init__", cls)
c_logger._log(DEBUG, "Searching for flags defined on %s.__init__", (cls, ))
cdef object parameters = inspect.signature(cls.__init__).parameters
c_logger._log(DEBUG, "parameters: %s", parameters)
c_logger._log(DEBUG, "parameters: %s", (parameters, ))
return _parse_flag_name_from_list(cls, parameters)


Expand All @@ -201,7 +198,7 @@ cdef str _parse_flag_name_from_list(object cls, object items):
raise exceptions.TooManyFlags(cls, present_flags)
if c_logger.isEnabledFor(DEBUG):
flag = present_flags[0]
c_logger._log(DEBUG, "found flag %s", flag)
c_logger._log(DEBUG, "found flag %s", (flag, ))
return flag
return present_flags[0]

Expand Down
6 changes: 3 additions & 3 deletions a_sync/a_sync/method.pyx
Original file line number Diff line number Diff line change
Expand Up @@ -602,7 +602,7 @@ class ASyncBoundMethod(ASyncFunction[P, T], Generic[I, P, T]):
cdef object retval, coro
cdef bint debug_logs
if debug_logs := c_logger.isEnabledFor(DEBUG):
c_logger._log(DEBUG, "calling %s with args: %s kwargs: %s", self, args, kwargs)
c_logger._log(DEBUG, "calling %s with args: %s kwargs: %s", (self, args, kwargs))
# This could either be a coroutine or a return value from an awaited coroutine,
# depending on if an overriding flag kwarg was passed into the function call.
retval = coro = ASyncFunction.__call__(self, self.__self__, *args, **kwargs)
Expand All @@ -614,12 +614,12 @@ class ASyncBoundMethod(ASyncFunction[P, T], Generic[I, P, T]):
# The awaitable was not awaited, so now we need to check the flag as defined on 'self' and await if appropriate.
if debug_logs:
c_logger._log(
DEBUG, "awaiting %s for %s args: %s kwargs: %s", coro, self, args, kwargs
DEBUG, "awaiting %s for %s args: %s kwargs: %s", (coro, self, args, kwargs)
)
retval = _await(coro)
if debug_logs:
c_logger._log(
DEBUG, "returning %s for %s args: %s kwargs: %s", retval, self, args, kwargs
DEBUG, "returning %s for %s args: %s kwargs: %s", (retval, self, args, kwargs)
)
return retval # type: ignore [call-overload, return-value]

Expand Down
10 changes: 2 additions & 8 deletions a_sync/a_sync/property.pyx
Original file line number Diff line number Diff line change
Expand Up @@ -133,10 +133,7 @@ class _ASyncPropertyDescriptorBase(ASyncDescriptor[I, Tuple[()], T]):
c_logger._log(
DEBUG,
"awaiting awaitable for %s for instance: %s owner: %s",
awaitable,
self,
instance,
owner,
(awaitable, self, instance, owner),
)
retval = _await(awaitable)
else:
Expand All @@ -146,10 +143,7 @@ class _ASyncPropertyDescriptorBase(ASyncDescriptor[I, Tuple[()], T]):
c_logger._log(
DEBUG,
"returning %s for %s for instance: %s owner: %s",
retval,
self,
instance,
owner,
(retval, self, instance, owner),
)

return retval
Expand Down
13 changes: 6 additions & 7 deletions a_sync/primitives/locks/prio_semaphore.pyx
Original file line number Diff line number Diff line change
Expand Up @@ -209,8 +209,7 @@ cdef class _AbstractPrioritySemaphore(Semaphore):
c_logger._log(
DEBUG,
"manager %s has no more waiters, popping from %s",
manager._c_repr_no_parent_(),
self,
(manager._c_repr_no_parent_(), self),
)
self._context_managers.pop(manager._priority)
continue
Expand All @@ -219,7 +218,7 @@ cdef class _AbstractPrioritySemaphore(Semaphore):
start_len = len(manager)

if debug_logs:
c_logger._log(DEBUG, "waking up next for %s", manager._c_repr_no_parent_())
c_logger._log(DEBUG, "waking up next for %s", (manager._c_repr_no_parent_(), ))
if not manager._waiters:
c_logger._log(DEBUG, "not manager._waiters")

Expand All @@ -230,7 +229,7 @@ cdef class _AbstractPrioritySemaphore(Semaphore):
waiter.set_result(None)
woke_up = True
if debug_logs:
c_logger._log(DEBUG, "woke up %s", waiter)
c_logger._log(DEBUG, "woke up %s", (waiter, ))
break

if not woke_up:
Expand Down Expand Up @@ -259,13 +258,13 @@ cdef class _AbstractPrioritySemaphore(Semaphore):

while self._potential_lost_waiters:
waiter = self._potential_lost_waiters.pop(0)
c_logger._log(DEBUG, "we found a lost waiter %s", waiter)
c_logger._log(DEBUG, "we found a lost waiter %s", (waiter, ))
if not waiter.done():
waiter.set_result(None)
c_logger._log(DEBUG, "woke up lost waiter %s", waiter)
c_logger._log(DEBUG, "woke up lost waiter %s", (waiter, ))
return

c_logger._log(DEBUG, "%s has no waiters to wake", self)
c_logger._log(DEBUG, "%s has no waiters to wake", (self, ))


cdef class _AbstractPrioritySemaphoreContextManager(Semaphore):
Expand Down
4 changes: 3 additions & 1 deletion a_sync/utils/iterators.py
Original file line number Diff line number Diff line change
Expand Up @@ -45,7 +45,9 @@ async def exhaust_iterator(
pass
elif logger.isEnabledFor(DEBUG):
async for thing in iterator:
logger._log(DEBUG, "putting %s from %s to queue %s", thing, iterator, queue)
logger._log(
DEBUG, "putting %s from %s to queue %s", (thing, iterator, queue)
)
queue.put_nowait(thing)
else:
async for thing in iterator:
Expand Down