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

feat: optimize loggers #443

Merged
merged 2 commits into from
Nov 25, 2024
Merged
Show file tree
Hide file tree
Changes from 1 commit
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
Next Next commit
feat: optimize loggers
  • Loading branch information
BobTheBuidler committed Nov 25, 2024
commit 9a0ab8f0d0d583e8d60c7c71d287d1034c3292b9
46 changes: 27 additions & 19 deletions a_sync/a_sync/abstract.pyx
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,7 @@ is intended for more custom implementations if necessary.
"""

import abc
import logging
from logging import DEBUG, getLogger
from typing import Dict, Any, Tuple

from a_sync._typing import *
Expand All @@ -19,7 +19,7 @@ from a_sync.a_sync._flags cimport validate_and_negate_if_necessary
from a_sync.a_sync._meta import ASyncMeta


logger = logging.getLogger(__name__)
logger = getLogger(__name__)

cdef object c_logger = logger

Expand Down Expand Up @@ -157,27 +157,35 @@ class ASyncABC(metaclass=ASyncMeta):
>>> MyASyncClass.__a_sync_instance_will_be_sync__((), {'sync': True})
True
"""
c_logger.debug(
"checking `%s.%s.__init__` signature against provided kwargs to determine a_sync mode for the new instance",
cls.__module__,
cls.__name__,
)
cdef bint debug_logs
if debug_logs := c_logger.isEnabledFor(DEBUG):
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__,
)

cdef str flag = get_flag_name(kwargs)
cdef bint sync
if flag:
sync = is_sync(flag, kwargs, pop_flag=False) # type: ignore [arg-type]
c_logger.debug(
"kwargs indicate the new instance created with args %s %s is %ssynchronous",
args,
kwargs,
"" if sync else "a",
if not debug_logs:
return is_sync(flag, kwargs, pop_flag=False) if flag else cls.__a_sync_default_mode__() # type: ignore [arg-type]

if not flag:
c_logger._log(
DEBUG,
"No valid flags found in kwargs, checking class definition for defined default"
)
return sync
c_logger.debug(
"No valid flags found in kwargs, checking class definition for defined default"
return cls.__a_sync_default_mode__() # type: ignore [arg-type]

cdef bint sync = is_sync(flag, kwargs, pop_flag=False) # type: ignore [arg-type]
c_logger._log(
DEBUG,
"kwargs indicate the new instance created with args %s %s is %ssynchronous",
args,
kwargs,
"" if sync else "a",
)
return cls.__a_sync_default_mode__() # type: ignore [arg-type]
return sync

####################
# Abstract Methods #
Expand Down
20 changes: 12 additions & 8 deletions a_sync/a_sync/base.pyx
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
import functools
import inspect
import logging
from contextlib import suppress
from logging import DEBUG, getLogger

from a_sync import exceptions
from a_sync._typing import *
Expand All @@ -10,7 +10,7 @@ from a_sync.a_sync.abstract import ASyncABC
from a_sync.a_sync.flags import VIABLE_FLAGS


logger = logging.getLogger(__name__)
logger = getLogger(__name__)

cdef object c_logger = logger

Expand Down Expand Up @@ -69,18 +69,22 @@ class ASyncGenericBase(ASyncABC):
@functools.cached_property
def __a_sync_flag_name__(self) -> str:
# TODO: cythonize this cache
c_logger.debug("checking a_sync flag for %s", self)
cdef bint debug_logs
if debug_logs := c_logger.isEnabledFor(DEBUG):
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:
# We can't get the flag name from the __init__ signature,
# but maybe the implementation sets the flag somewhere else.
# Let's check the instance's atributes
c_logger.debug(
"unable to find flag name using `%s.__init__` signature, checking for flag attributes defined on %s",
self.__class__.__name__,
self,
)
if debug_logs:
c_logger._log(
DEBUG,
"unable to find flag name using `%s.__init__` signature, checking for flag attributes defined on %s",
self.__class__.__name__,
self,
)
present_flags = [flag for flag in VIABLE_FLAGS if hasattr(self, flag)]
if not present_flags:
raise exceptions.NoFlagsFound(self) from None
Expand Down
22 changes: 13 additions & 9 deletions a_sync/a_sync/method.pyx
Original file line number Diff line number Diff line change
Expand Up @@ -9,9 +9,9 @@ asynchronously based on various conditions and configurations.
# mypy: disable-error-code=valid-type
# mypy: disable-error-code=misc
import functools
import logging
import weakref
from inspect import isawaitable
from logging import DEBUG, getLogger

from a_sync._typing import *
from a_sync.a_sync._kwargs cimport get_flag_name, is_sync
Expand All @@ -33,7 +33,7 @@ METHOD_CACHE_TTL = 300
cdef int _METHOD_CACHE_TTL = 300


logger = logging.getLogger(__name__)
logger = getLogger(__name__)

cdef object c_logger = logger

Expand Down Expand Up @@ -600,7 +600,9 @@ class ASyncBoundMethod(ASyncFunction[P, T], Generic[I, P, T]):
>>> bound_method(arg1, arg2, kwarg1=value1, sync=True)
"""
cdef object retval, coro
c_logger.debug("calling %s with args: %s kwargs: %s", self, args, kwargs)
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)
# 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 @@ -610,13 +612,15 @@ class ASyncBoundMethod(ASyncFunction[P, T], Generic[I, P, T]):
pass
elif _should_await(self, kwargs):
# The awaitable was not awaited, so now we need to check the flag as defined on 'self' and await if appropriate.
c_logger.debug(
"awaiting %s for %s args: %s kwargs: %s", coro, self, args, kwargs
)
if debug_logs:
c_logger._log(
DEBUG, "awaiting %s for %s args: %s kwargs: %s", coro, self, args, kwargs
)
retval = _await(coro)
c_logger.debug(
"returning %s for %s args: %s kwargs: %s", retval, self, args, kwargs
)
if debug_logs:
c_logger._log(
DEBUG, "returning %s for %s args: %s kwargs: %s", retval, self, args, kwargs
)
return retval # type: ignore [call-overload, return-value]

@property
Expand Down
38 changes: 21 additions & 17 deletions a_sync/a_sync/property.pyx
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
import functools
import logging
from logging import DEBUG, getLogger

import async_property as ap # type: ignore [import]
from typing_extensions import Unpack
Expand All @@ -25,7 +25,7 @@ if TYPE_CHECKING:
from a_sync.task import TaskMapping


logger = logging.getLogger(__name__)
logger = getLogger(__name__)

cdef object c_logger = logger

Expand Down Expand Up @@ -127,26 +127,30 @@ class _ASyncPropertyDescriptorBase(ASyncDescriptor[I, Tuple[()], T]):
)

cdef object retval

cdef bint debug_logs = c_logger.isEnabledFor(DEBUG)
if should_await:
c_logger.debug(
"awaiting awaitable for %s for instance: %s owner: %s",
awaitable,
self,
instance,
owner,
)
if debug_logs:
c_logger._log(
DEBUG,
"awaiting awaitable for %s for instance: %s owner: %s",
awaitable,
self,
instance,
owner,
)
retval = _await(awaitable)
else:
retval = awaitable

c_logger.debug(
"returning %s for %s for instance: %s owner: %s",
retval,
self,
instance,
owner,
)
if debug_logs:
c_logger._log(
DEBUG,
"returning %s for %s for instance: %s owner: %s",
retval,
self,
instance,
owner,
)

return retval

Expand Down
51 changes: 32 additions & 19 deletions a_sync/primitives/locks/prio_semaphore.pyx
Original file line number Diff line number Diff line change
Expand Up @@ -5,14 +5,14 @@ processed before lower priority ones.
"""

import asyncio
import heapq
import logging
from collections import deque
from heapq import heappop, heappush
from logging import DEBUG, getLogger

from a_sync._typing import *
from a_sync.primitives.locks.semaphore cimport Semaphore

logger = logging.getLogger(__name__)
logger = getLogger(__name__)

cdef object c_logger = logger

Expand Down Expand Up @@ -144,7 +144,7 @@ cdef class _AbstractPrioritySemaphore(Semaphore):
context_manager = self._context_manager_class(
self, priority, name=self.name
)
heapq.heappush(self.__waiters, context_manager) # type: ignore [misc]
heappush(self.__waiters, context_manager) # type: ignore [misc]
self._context_managers[priority] = context_manager
return self._context_managers[priority]

Expand Down Expand Up @@ -200,32 +200,37 @@ cdef class _AbstractPrioritySemaphore(Semaphore):
>>> semaphore._wake_up_next()
"""
cdef _AbstractPrioritySemaphoreContextManager manager
cdef bint debug_logs = c_logger.isEnabledFor(DEBUG)
while self.__waiters:
manager = heapq.heappop(self.__waiters)
manager = heappop(self.__waiters)
if len(manager) == 0:
# There are no more waiters, get rid of the empty manager
c_logger.debug(
"manager %s has no more waiters, popping from %s",
manager._c_repr_no_parent_(),
self,
)
if debug_logs:
c_logger._log(
DEBUG,
"manager %s has no more waiters, popping from %s",
manager._c_repr_no_parent_(),
self,
)
self._context_managers.pop(manager._priority)
continue
c_logger.debug("waking up next for %s", manager._c_repr_no_parent_())

woke_up = False
start_len = len(manager)

if not manager._waiters:
c_logger.debug("not manager._waiters")
if debug_logs:
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")

while manager._waiters:
waiter = manager._waiters.popleft()
self._potential_lost_waiters.remove(waiter)
if not waiter.done():
waiter.set_result(None)
c_logger.debug("woke up %s", waiter)
woke_up = True
if debug_logs:
c_logger._log(DEBUG, "woke up %s", waiter)
break

if not woke_up:
Expand All @@ -238,21 +243,29 @@ cdef class _AbstractPrioritySemaphore(Semaphore):

if end_len:
# There are still waiters, put the manager back
heapq.heappush(self.__waiters, manager) # type: ignore [misc]
heappush(self.__waiters, manager) # type: ignore [misc]
else:
# There are no more waiters, get rid of the empty manager
self._context_managers.pop(manager._priority)
return

# emergency procedure (hopefully temporary):
if not debug_logs:
while self._potential_lost_waiters:
waiter = self._potential_lost_waiters.pop(0)
if not waiter.done():
waiter.set_result(None)
return

while self._potential_lost_waiters:
waiter = self._potential_lost_waiters.pop(0)
c_logger.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.debug("woke up lost waiter %s", waiter)
c_logger._log(DEBUG, "woke up lost waiter %s", waiter)
return
c_logger.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 Expand Up @@ -490,7 +503,7 @@ cdef class PrioritySemaphore(_AbstractPrioritySemaphore): # type: ignore [type-
cdef dict[int, _PrioritySemaphoreContextManager] context_managers = self._context_managers
if <int>priority not in context_managers:
context_manager = _PrioritySemaphoreContextManager(self, <int>priority, name=self.name)
heapq.heappush(
heappush(
<list[_PrioritySemaphoreContextManager]>self.__waiters,
context_manager,
) # type: ignore [misc]
Expand Down
9 changes: 6 additions & 3 deletions a_sync/utils/iterators.py
Original file line number Diff line number Diff line change
Expand Up @@ -6,15 +6,15 @@

import asyncio
import asyncio.futures
import logging
import traceback
from logging import DEBUG, getLogger
from types import TracebackType

import a_sync.asyncio
from a_sync._typing import *
from a_sync.primitives.queue import Queue

logger = logging.getLogger(__name__)
logger = getLogger(__name__)


async def exhaust_iterator(
Expand Down Expand Up @@ -43,9 +43,12 @@ async def exhaust_iterator(
if queue is None:
async for thing in iterator:
pass
elif logger.isEnabledFor(DEBUG):
async for thing in iterator:
logger._log(DEBUG, "putting %s from %s to queue %s", thing, iterator, queue)
queue.put_nowait(thing)
else:
async for thing in iterator:
logger.debug("putting %s from %s to queue %s", thing, iterator, queue)
queue.put_nowait(thing)


Expand Down
Loading