Currently we have an http_client.close() in the oidc.py: https://git.knut.univention.de/univention/dev/ucs/-/blob/10f40e10fb8d31e685d74d3a2333d1226ee531c0/management/univention-management-console/src/univention/management/console/oidc.py#L344 This closes the http_client for the whole Tornado IOLoop. See: https://www.tornadoweb.org/en/stable/httpclient.html#tornado.httpclient.AsyncHTTPClient https://www.tornadoweb.org/en/stable/auth.html#tornado.auth.OpenIdMixin.get_auth_http_client If one tests OIDC logins with some concurrency (greater than 1), logins start failing. To replicate, I added concurrency to the code from https://git.knut.univention.de/univention/dev/ucs/-/issues/2388#note_448700
It was introduced here and we should find out, what should have been solved with it: commit 71a5c0c1f4212cf4b52ec87dedf64ddb35a8f556 Author: Felix Botner <botner@univention.de> Date: Thu Aug 29 20:19:31 2024 +0200 Issue univention/ucs#2388: close http client after getting access token diff --git management/univention-management-console/src/univention/management/console/oidc.py management/univention-management-console/src/univention/management/console/oidc.py index 58d29c5832e..422287cb745 100644 --- management/univention-management-console/src/univention/management/console/oidc.py +++ management/univention-management-console/src/univention/management/console/oidc.py @@ -338,6 +338,8 @@ class OIDCResource(OAuth2Mixin, Resource): ) except HTTPClientError: raise # handled in get() + # TODO why do we need that, see univention/ucs#2388 + http_client.close() return escape.json_decode(response.body) async def refresh_session_tokens(self, user):
Created attachment 11311 [details] Sketch for a patch The original problems seems to be that there was a file descriptor leak in case of too many connections which have been established (but never closed?). I attached a sketch for a patch, which just needs close-handling and checking if the connection can be used again. e.g. by two attempts to do things in case of a certain exception.
Experienced a UMC server crash - happened a single time on OpenStack: Aug 29 00:09:09 master /usr/bin/python[4143267]: python3 /usr/sbin/univention-management-console-server: Verified payload: {"exp":1756426449,"iat":1756426149,"auth_time":1756423546,"jti":"802910fc-393f-42aa-8cae-e90d9854aa5f","iss":"https://ucs-sso-ng.ucs.test/realms/ucs","aud":["ldaps://ucs.test/","account"],"> Aug 31 00:00:05 master systemd[1]: univention-management-console-server.service: Sent signal SIGHUP to main process 4143267 (/usr/bin/python) on client request. Sep 01 07:10:55 master univention-management-console-server[4143267]: python3 /usr/sbin/univention-management-console-server: src/threadsupport.c:29: pycurl_get_thread_state: Assertion `self->handle != NULL' failed. Sep 01 07:10:55 master systemd[1]: univention-management-console-server.service: Main process exited, code=killed, status=6/ABRT Sep 01 07:10:55 master systemd[1]: univention-management-console-server.service: Failed with result 'signal'. Sep 01 07:10:55 master systemd[1]: univention-management-console-server.service: Consumed 15min 36.828s CPU time. This is most likely caused by the http_client.close().
[New Thread 0x7f73b930c6c0 (LWP 71988)] [Thread 0x7f73b930c6c0 (LWP 71988) exited] Thread 1 "/usr/bin/python" received signal SIGABRT, Aborted. __pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=6, no_tid=no_tid@entry=0) at ./nptl/pthread_kill.c:44 44 ./nptl/pthread_kill.c: No such file or directory. (gdb) thread apply all bt Thread 1 (Thread 0x7f73c69562c0 (LWP 71884) "/usr/bin/python"): #0 __pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=6, no_tid=no_tid@entry=0) at ./nptl/pthread_kill.c:44 #1 0x00007f73c69e1f4f in __pthread_kill_internal (signo=6, threadid=<optimized out>) at ./nptl/pthread_kill.c:78 #2 0x00007f73c6992fb2 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26 #3 0x00007f73c697d472 in __GI_abort () at ./stdlib/abort.c:79 #4 0x00007f73c697d395 in __assert_fail_base (fmt=0x7f73c6af2a90 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x7f73b9861f8b "self->handle != NULL", file=file@entry=0x7f73b9861f77 "src/threadsupport.c", line=line@entry=29, function=function@entry=0x7f73b9862050 "pycurl_get_thread_state") at ./assert/assert.c:94 #5 0x00007f73c698bec2 in __GI___assert_fail (assertion=0x7f73b9861f8b "self->handle != NULL", file=0x7f73b9861f77 "src/threadsupport.c", line=29, function=0x7f73b9862050 "pycurl_get_thread_state") at ./assert/assert.c:103 #6 0x00007f73b9856250 in pycurl_get_thread_state () from /usr/lib/python3/dist-packages/pycurl.cpython-311-x86_64-linux-gnu.so #7 0x00007f73b98562d9 in pycurl_acquire_thread () from /usr/lib/python3/dist-packages/pycurl.cpython-311-x86_64-linux-gnu.so #8 0x00007f73b984a161 in debug_callback () from /usr/lib/python3/dist-packages/pycurl.cpython-311-x86_64-linux-gnu.so #9 0x00007f73c2f72daa in ?? () from /lib/x86_64-linux-gnu/libcurl-gnutls.so.4 #10 0x00007f73c2f73086 in ?? () from /lib/x86_64-linux-gnu/libcurl-gnutls.so.4 #11 0x00007f73c2fbfbe9 in ?? () from /lib/x86_64-linux-gnu/libcurl-gnutls.so.4 #12 0x00007f73c2f9f837 in ?? () from /lib/x86_64-linux-gnu/libcurl-gnutls.so.4 #13 0x00007f73c2f9ff59 in curl_multi_remove_handle () from /lib/x86_64-linux-gnu/libcurl-gnutls.so.4 #14 0x00007f73b984857a in util_curl_xdecref () from /usr/lib/python3/dist-packages/pycurl.cpython-311-x86_64-linux-gnu.so #15 0x00007f73b9848c21 in ?? () from /usr/lib/python3/dist-packages/pycurl.cpython-311-x86_64-linux-gnu.so #16 0x00007f73b9848e35 in ?? () from /usr/lib/python3/dist-packages/pycurl.cpython-311-x86_64-linux-gnu.so #17 0x000000000051f62b in cfunction_vectorcall_NOARGS (func=<built-in method close of pycurl.Curl object at remote 0x35d81830>, args=<optimized out>, nargsf=<optimized out>, kwnames=<optimized out>) at ../Include/cpython/methodobject.h:52 #18 0x000000000053acbc in _PyObject_VectorcallTstate (kwnames=<optimized out>, nargsf=<optimized out>, args=<optimized out>, callable=<built-in method close of pycurl.Curl object at remote 0x35d81830>, tstate=0xa840f8 <_PyRuntime+166328>) at ../Include/internal/pycore_call.h:92 #19 PyObject_Vectorcall (callable=<built-in method close of pycurl.Curl object at remote 0x35d81830>, args=<optimized out>, nargsf=<optimized out>, kwnames=<optimized out>) at ../Objects/call.c:299 #20 0x000000000052b9e0 in _PyEval_EvalFrameDefault (tstate=<optimized out>, frame=<optimized out>, throwflag=<optimized out>) at ../Python/ceval.c:4772 #21 0x00000000005dd3f0 in _PyEval_EvalFrame (throwflag=0, frame=0x7f73b95d6010, tstate=0xa840f8 <_PyRuntime+166328>) at ../Include/internal/pycore_ceval.h:73 #22 gen_send_ex2 (closing=0, exc=0, presult=0x7ffdb4dd27b0, arg=None, gen=0x7f73b95d5fc0) at ../Objects/genobject.c:219 #23 PyGen_am_send (result=0x7ffdb4dd27b0, arg=None, gen=0x7f73b95d5fc0) at ../Objects/genobject.c:280 #24 PyIter_Send (iter=<coroutine at remote 0x7f73b95d5fc0>, arg=None, result=0x7ffdb4dd27b0) at ../Objects/abstract.c:2882 #25 0x0000000000530072 in _PyEval_EvalFrameDefault (tstate=<optimized out>, frame=<optimized out>, throwflag=<optimized out>) at ../Python/ceval.c:2589 #26 0x00000000005dd3f0 in _PyEval_EvalFrame (throwflag=0, frame=0x7f73b9483290, tstate=0xa840f8 <_PyRuntime+166328>) at ../Include/internal/pycore_ceval.h:73 #27 gen_send_ex2 (closing=0, exc=0, presult=0x7ffdb4dd2960, arg=None, gen=0x7f73b9483240) at ../Objects/genobject.c:219 #28 PyGen_am_send (result=0x7ffdb4dd2960, arg=None, gen=0x7f73b9483240) at ../Objects/genobject.c:280 #29 PyIter_Send (iter=<coroutine at remote 0x7f73b9483240>, arg=None, result=0x7ffdb4dd2960) at ../Objects/abstract.c:2882 #30 0x0000000000530072 in _PyEval_EvalFrameDefault (tstate=<optimized out>, frame=<optimized out>, throwflag=<optimized out>) at ../Python/ceval.c:2589 #31 0x00000000005dd3f0 in _PyEval_EvalFrame (throwflag=0, frame=0x7f73b959f010, tstate=0xa840f8 <_PyRuntime+166328>) at ../Include/internal/pycore_ceval.h:73 #32 gen_send_ex2 (closing=0, exc=0, presult=0x7ffdb4dd2b10, arg=None, gen=0x7f73b959efc0) at ../Objects/genobject.c:219 #33 PyGen_am_send (result=0x7ffdb4dd2b10, arg=None, gen=0x7f73b959efc0) at ../Objects/genobject.c:280 #34 PyIter_Send (iter=<coroutine at remote 0x7f73b959efc0>, arg=None, result=0x7ffdb4dd2b10) at ../Objects/abstract.c:2882 #35 0x0000000000530072 in _PyEval_EvalFrameDefault (tstate=<optimized out>, frame=<optimized out>, throwflag=<optimized out>) at ../Python/ceval.c:2589 #36 0x00000000005dd3f0 in _PyEval_EvalFrame (throwflag=0, frame=0x7f73b94bb7d0, tstate=0xa840f8 <_PyRuntime+166328>) at ../Include/internal/pycore_ceval.h:73 #37 gen_send_ex2 (closing=0, exc=0, presult=0x7ffdb4dd2cc0, arg=None, gen=0x7f73b94bb780) at ../Objects/genobject.c:219 #38 PyGen_am_send (result=0x7ffdb4dd2cc0, arg=None, gen=0x7f73b94bb780) at ../Objects/genobject.c:280 #39 PyIter_Send (iter=<coroutine at remote 0x7f73b94bb780>, arg=None, result=0x7ffdb4dd2cc0) at ../Objects/abstract.c:2882 #40 0x0000000000530072 in _PyEval_EvalFrameDefault (tstate=<optimized out>, frame=<optimized out>, throwflag=<optimized out>) at ../Python/ceval.c:2589 #41 0x00000000005dd3f0 in _PyEval_EvalFrame (throwflag=0, frame=0x7f73b94bb280, tstate=0xa840f8 <_PyRuntime+166328>) at ../Include/internal/pycore_ceval.h:73 --Type <RET> for more, q to quit, c to continue without paging-- #42 gen_send_ex2 (closing=0, exc=0, presult=0x7ffdb4dd2e10, arg=None, gen=0x7f73b94bb230) at ../Objects/genobject.c:219 #43 PyGen_am_send (result=0x7ffdb4dd2e10, arg=None, gen=0x7f73b94bb230) at ../Objects/genobject.c:280 #44 PyIter_Send (iter=<coroutine at remote 0x7f73b94bb230>, arg=None, result=0x7ffdb4dd2e10) at ../Objects/abstract.c:2882 #45 0x00007f73c628ee22 in task_step_impl (task=task@entry=0x7f73b94371c0, exc=exc@entry=0x0) at ../Modules/_asynciomodule.c:2690 #46 0x00007f73c628ff43 in task_step (exc=0x0, task=0x7f73b94371c0) at ../Modules/_asynciomodule.c:2990 #47 task_wakeup (task=0x7f73b94371c0, o=<optimized out>) at ../Modules/_asynciomodule.c:3027 #48 0x0000000000545963 in cfunction_vectorcall_O (func=<built-in method task_wakeup of _asyncio.Task object at remote 0x7f73b94371c0>, args=0x7f73b94ea6e0, nargsf=<optimized out>, kwnames=<optimized out>) at ../Include/cpython/methodobject.h:52 #49 0x0000000000648ed2 in _PyObject_VectorcallTstate (tstate=0xa840f8 <_PyRuntime+166328>, callable=<built-in method task_wakeup of _asyncio.Task object at remote 0x7f73b94371c0>, args=<optimized out>, nargsf=<optimized out>, kwnames=<optimized out>) at ../Include/internal/pycore_call.h:92 #50 0x0000000000695d1f in context_run (self=0x7f73b939c980, args=0x7f73b94ea6d8, nargs=2, kwnames=0x0) at ../Python/context.c:673 #51 0x000000000053ad87 in cfunction_vectorcall_FASTCALL_KEYWORDS (func=<built-in method run of _contextvars.Context object at remote 0x7f73b939c980>, args=0x7f73b94ea6d8, nargsf=<optimized out>, kwnames=<optimized out>) at ../Include/cpython/methodobject.h:52 #52 0x0000000000534789 in do_call_core (use_tracing=<optimized out>, kwdict=0x0, callargs=(<built-in method task_wakeup of _asyncio.Task object at remote 0x7f73b94371c0>, <_asyncio.Future at remote 0x7f73b94c5d80>), func=<built-in method run of _contextvars.Context object at remote 0x7f73b939c980>, tstate=<optimized out>) at ../Python/ceval.c:7325 #53 _PyEval_EvalFrameDefault (tstate=<optimized out>, frame=<optimized out>, throwflag=<optimized out>) at ../Python/ceval.c:5379 #54 0x00000000005236bb in _PyEval_EvalFrame (throwflag=0, frame=0x7f73c6c65020, tstate=0xa840f8 <_PyRuntime+166328>) at ../Include/internal/pycore_ceval.h:73 #55 _PyEval_Vector (args=0x0, argcount=0, kwnames=0x0, locals=<optimized out>, func=0x7f73c65cdf80, tstate=0xa840f8 <_PyRuntime+166328>) at ../Python/ceval.c:6435 #56 PyEval_EvalCode (co=<code at remote 0x33cd7280>, globals=<optimized out>, locals=<optimized out>) at ../Python/ceval.c:1154 #57 0x0000000000647d97 in run_eval_code_obj (tstate=0xa840f8 <_PyRuntime+166328>, co=0x33cd7280, globals={'__name__': '__main__', '__doc__': None, '__package__': None, '__loader__': <SourceFileLoader(name='__main__', path='/usr/sbin/univention-management-console-server') at remote 0x7f73c65f2f50>, '__spec__': None, '__annotations__': {}, '__builtins__': <module at remote 0x7f73c6588ae0>, '__file__': '/usr/sbin/univention-management-console-server', '__cached__': None, 're': <module at remote 0x7f73c64459e0>, 'sys': <module at remote 0x7f73c657aca0>, '__requires__': 'univention-management-console==14.3.0', 'distribution': <function at remote 0x7f73c612bec0>, 'importlib_load_entry_point': <function at remote 0x7f73c63b0720>, 'load_entry_point': <function at remote 0x7f73c63b0720>}, locals={'__name__': '__main__', '__doc__': None, '__package__': None, '__loader__': <SourceFileLoader(name='__main__', path='/usr/sbin/univention-management-console-server') at remote 0x7f73c65f2f50>, '__spec__': None, '__annotations__': {}, '__builtins__': <module at remote 0x7f73c6588ae0>, '__file__': '/usr/sbin/univention-management-console-server', '__cached__': None, 're': <module at remote 0x7f73c64459e0>, 'sys': <module at remote 0x7f73c657aca0>, '__requires__': 'univention-management-console==14.3.0', 'distribution': <function at remote 0x7f73c612bec0>, 'importlib_load_entry_point': <function at remote 0x7f73c63b0720>, 'load_entry_point': <function at remote 0x7f73c63b0720>}) at ../Python/pythonrun.c:1714 #58 0x00000000006456ef in run_mod (mod=<optimized out>, filename=<optimized out>, globals={'__name__': '__main__', '__doc__': None, '__package__': None, '__loader__': <SourceFileLoader(name='__main__', path='/usr/sbin/univention-management-console-server') at remote 0x7f73c65f2f50>, '__spec__': None, '__annotations__': {}, '__builtins__': <module at remote 0x7f73c6588ae0>, '__file__': '/usr/sbin/univention-management-console-server', '__cached__': None, 're': <module at remote 0x7f73c64459e0>, 'sys': <module at remote 0x7f73c657aca0>, '__requires__': 'univention-management-console==14.3.0', 'distribution': <function at remote 0x7f73c612bec0>, 'importlib_load_entry_point': <function at remote 0x7f73c63b0720>, 'load_entry_point': <function at remote 0x7f73c63b0720>}, locals={'__name__': '__main__', '__doc__': None, '__package__': None, '__loader__': <SourceFileLoader(name='__main__', path='/usr/sbin/univention-management-console-server') at remote 0x7f73c65f2f50>, '__spec__': None, '__annotations__': {}, '__builtins__': <module at remote 0x7f73c6588ae0>, '__file__': '/usr/sbin/univention-management-console-server', '__cached__': None, 're': <module at remote 0x7f73c64459e0>, 'sys': <module at remote 0x7f73c657aca0>, '__requires__': 'univention-management-console==14.3.0', 'distribution': <function at remote 0x7f73c612bec0>, 'importlib_load_entry_point': <function at remote 0x7f73c63b0720>, 'load_entry_point': <function at remote 0x7f73c63b0720>}, flags=<optimized out>, arena=<optimized out>) at ../Python/pythonrun.c:1735 #59 0x0000000000651770 in pyrun_file (fp=fp@entry=0x33cf4ce0, filename=filename@entry='/usr/sbin/univention-management-console-server', start=start@entry=257, globals=globals@entry={'__name__': '__main__', '__doc__': None, '__package__': None, '__loader__': <SourceFileLoader(name='__main__', path='/usr/sbin/univention-management-console-server') at remote 0x7f73c65f2f50>, '__spec__': None, '__annotations__': {}, '__builtins__': <module at remote 0x7f73c6588ae0>, '__file__': '/usr/sbin/univention-management-console-server', '__cached__': None, 're': <module at remote 0x7f73c64459e0>, 'sys': <module at remote 0x7f73c657aca0>, '__requires__': 'univention-management-console==14.3.0', 'distribution': <function at remote 0x7f73c612bec0>, 'importlib_load_entry_point': <function at remote 0x7f73c63b0720>, 'load_entry_point': <function at remote 0x7f73c63b0720>}, locals=locals@entry={'__name__': '__main__', '__doc__': None, '__package__': None, '__loader__': <SourceFileLoader(name='__main__', path='/usr/sbin/univention-management-console-server') at remote 0x7f73c65f2f50>, '__spec__': None, '__annotations__': {}, '__builtins__': <module at remote 0x7f73c6588ae0>, '__file__': '/usr/sbin/univention-management-console-server', '__cached__': None, 're': <module at remote 0x7f73c64459e0>, 'sys': <module at remote 0x7f73c657aca0>, '__requires__': 'univention-management-console==14.3.0', 'distribution': <function at remote 0x7f73c612bec0>, 'importlib_load_entry_point': <function at remote 0x7f73c63b0720>, 'load_entry_point': <function at remote 0x7f73c63b0720>}, closeit=closeit@entry=1, flags=0x7ffdb4dd32c8) at ../Python/pythonrun.c:1630 #60 0x00000000006514bb in _PyRun_SimpleFileObject (fp=fp@entry=0x33cf4ce0, filename=filename@entry='/usr/sbin/univention-management-console-server', closeit=closeit@entry=1, flags=flags@entry=0x7ffdb4dd32c8) at ../Python/pythonrun.c:440 #61 0x00000000006512e4 in _PyRun_AnyFileObject (fp=0x33cf4ce0, filename='/usr/sbin/univention-management-console-server', closeit=1, flags=0x7ffdb4dd32c8) at ../Python/pythonrun.c:79 #62 0x000000000065007f in pymain_run_file_obj (skip_source_first_line=0, filename='/usr/sbin/univention-management-console-server', program_name='/usr/bin/python3') at ../Modules/main.c:360 --Type <RET> for more, q to quit, c to continue without paging-- #63 pymain_run_file (config=0xa6a140 <_PyRuntime+59904>) at ../Modules/main.c:379 #64 pymain_run_python (exitcode=0x7ffdb4dd32c4) at ../Modules/main.c:601 #65 Py_RunMain () at ../Modules/main.c:680 #66 0x0000000000627d37 in Py_BytesMain (argc=<optimized out>, argv=<optimized out>) at ../Modules/main.c:734 #67 0x00007f73c697e24a in __libc_start_call_main (main=main@entry=0x627ca0 <main>, argc=argc@entry=2, argv=argv@entry=0x7ffdb4dd34f8) at ../sysdeps/nptl/libc_start_call_main.h:58 #68 0x00007f73c697e305 in __libc_start_main_impl (main=0x627ca0 <main>, argc=2, argv=0x7ffdb4dd34f8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffdb4dd34e8) at ../csu/libc-start.c:360 #69 0x0000000000627bd1 in _start ()
https://www.tornadoweb.org/en/stable/httpclient.html#tornado.httpclient.AsyncHTTPClient says: > [AsyncHTTPClient] instances are reused as a kind of pseudo-singleton (one per IOLoop). So, we don't need to cache them but can always re-initialize. it also says: > close() → None > > Destroys this HTTP client, freeing any file descriptors used. > > This method is not needed in normal use due to the way that AsyncHTTPClient objects are transparently reused. close() is generally only necessary when either the IOLoop is also being closed, or the force_instance=True argument was used when creating the AsyncHTTPClient. > > No other methods may be called on the AsyncHTTPClient after close(). → So, it should never be closed. Instead the timeouts should be configured, which should solve the problem when logging in, logging out and re-logging in.
Introduced HTTP Client timeouts to prevent failures on concurrent OIDC logins.
OK: code review OK: test case from Felix OK: advisory univention-management-console.yaml 8efb48b7ce7b | fix(umc-server): appropriate http client timeouts prevent failures on concurrent OIDC logins univention-management-console (14.3.1) 8efb48b7ce7b | fix(umc-server): appropriate http client timeouts prevent failures on concurrent OIDC logins ucs-test (12.3.2) 497f29cdf8f4 | test(ucs-test): parallel umc oidc login test
<https://errata.software-univention.de/#/?erratum=5.2x215>