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

add lock to cachetools usage #11373

Merged

Conversation

rebeccahhh
Copy link
Member

SUMMARY

@chrismeyersfsu and I observed daphne giving tracebacks when accessing logging settings.
Originally, configure tower in tower settings was not a suspect because daphne is not multi-process. We've had issues with configure tower in tower settings and multi-process before. The trouble with that is that Daphne is multi-threaded.
We created a situation locally that showed to show that multiple threads accessing settings can cause a daphne error traceback along the lines of:

ERROR    Exception in callback AsyncioSelectorReactor.callLater.<locals>.run() at /var/lib/awx/venv/awx/lib64/python3.6/site-packages/twisted/internet/asyncioreactor.py:287
handle: <TimerHandle when=2827684.549986961 AsyncioSelectorReactor.callLater.<locals>.run() at /var/lib/awx/venv/awx/lib64/python3.6/site-packages/twisted/internet/asyncioreactor.py:287>
Traceback (most recent call last):
  File "/usr/lib64/python3.6/asyncio/events.py", line 145, in _run
    self._callback(*self._args)
  File "/var/lib/awx/venv/awx/lib64/python3.6/site-packages/twisted/internet/asyncioreactor.py", line 290, in run
    f(*args, **kwargs)
  File "/var/lib/awx/venv/awx/lib64/python3.6/site-packages/daphne/server.py", line 292, in application_checker
    "Exception inside application: %s", exception_output
  File "/usr/lib64/python3.6/logging/__init__.py", line 1337, in error
    self._log(ERROR, msg, args, **kwargs)
  File "/usr/lib64/python3.6/logging/__init__.py", line 1444, in _log
    self.handle(record)
  File "/usr/lib64/python3.6/logging/__init__.py", line 1454, in handle
    self.callHandlers(record)
  File "/usr/lib64/python3.6/logging/__init__.py", line 1516, in callHandlers
    hdlr.handle(record)
  File "/usr/lib64/python3.6/logging/__init__.py", line 861, in handle
    rv = self.filter(record)
  File "/usr/lib64/python3.6/logging/__init__.py", line 720, in filter
    result = f.filter(record)
  File "/var/lib/awx/venv/awx/lib64/python3.6/site-packages/awx/main/utils/common.py", line 123, in filter
    return settings.DEBUG or settings.IS_TESTING()
  File "/var/lib/awx/venv/awx/lib64/python3.6/site-packages/awx/conf/settings.py", line 527, in __getattr_without_cache__
    return getattr(self._wrapped, name)
  File "/var/lib/awx/venv/awx/lib64/python3.6/site-packages/cachetools/decorators.py", line 24, in wrapper
    cache[k] = v
  File "/var/lib/awx/venv/awx/lib64/python3.6/site-packages/cachetools/ttl.py", line 88, in __setitem__
    self.expire(time)
  File "/var/lib/awx/venv/awx/lib64/python3.6/site-packages/cachetools/ttl.py", line 168, in expire
    cache_delitem(self, curr.key)
  File "/var/lib/awx/venv/awx/lib64/python3.6/site-packages/cachetools/cache.py", line 61, in __delitem__
    del self.__data[key]
KeyError: (<SettingsWrapper>, 'SESSION_SERIALIZER')
ISSUE TYPE
  • Bugfix Pull Request
COMPONENT NAME
  • API
AWX VERSION
awx: 19.2.3
ADDITIONAL INFORMATION

This addition, while proved on our end, is somewhat of a hypothesis. We're hoping this fixes things but will be equally, if not more, pleased if a community member catches something we missed.

@AlanCoding
Copy link
Member

bump, @rebeccahhh can you rebase and merge this?

@rebeccahhh
Copy link
Member Author

yep, rebase incoming after I get out of a meeting.

* We observed daphne giving tracebacks when accessing logging settings.
  Originally, configure tower in tower settings was no a suspect because
  daphne is not multi-process. We've had issues with configure tower in
  tower settings and multi-process before. We later learned that Daphne
  is multi-threaded. Configure tower in tower was back to being a
  suspect. We constructed a minimal reproducer to show that multiple
  threads accessing settings can cause the same traceback that we saw in
  daphne. See
  https://gist.github.com/chrismeyersfsu/7aa4bdcf76e435efd617cb078c64d413
  for that recreator. These fixes stop the recreation.
@rebeccahhh rebeccahhh force-pushed the fix-settings_cache_threading_awx branch from afc9401 to 21972c9 Compare May 6, 2022 20:25
@rebeccahhh rebeccahhh merged commit b73078e into ansible:devel May 9, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants