Storage celery client raises badly formed hexadecimal UUID string and is not handled on the webserver #7413
Description
This is the trace-back of the log in master
log_level=ERROR | log_timestamp=2025-03-24 10:53:39,243 | log_source=servicelib.aiohttp.monitoring:middleware_handler(227) | log_uid=None | log_oec=None| log_trace_id=0 | log_span_id=0 | log_resource.service.name= | log_trace_sampled=False] | log_msg=Unexpected server error "<class 'aiohttp.web_exceptions.HTTPGatewayTimeout'>" from access: 10.2.86.29 "GET /v0/catalog/services/simcore/services/dynamic/sim4life-8-0-0-dy/3.2.29" done in 20.32 secs. Responding with status 504
Traceback (most recent call last):
File "/usr/local/lib/python3.11/asyncio/tasks.py", line 500, in wait_for
return fut.result()
^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/aio_pika/patterns/rpc.py", line 371, in call
return await future
^^^^^^^^^^^^
asyncio.exceptions.CancelledError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/aiohttp/rest_middlewares.py", line 83, in _middleware_handler
return await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/aiohttp/rest_middlewares.py", line 175, in _middleware_handler
resp = await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_webserver/products/_web_middlewares.py", line 101, in discover_product_middleware
return await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/aiohttp/profiler_middleware.py", line 49, in profiling_middleware
return await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/aiohttp/long_running_tasks/_error_handlers.py", line 18, in base_long_running_error_handler
return await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_webserver/login/decorators.py", line 71, in _wrapper
return await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_webserver/security/decorators.py", line 24, in _wrapped
return await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_webserver/exception_handling/_base.py", line 145, in _wrapper
return await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_webserver/catalog/_controller_rest.py", line 113, in get_service
service = await _service.get_service_v2(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_webserver/catalog/_service.py", line 126, in get_service_v2
service = await catalog_rpc.get_service(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/logging_utils.py", line 359, in _async_wrapper
result = await func_or_coro(*args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/rabbitmq/rpc_interfaces/catalog/services.py", line 104, in get_service
result = await _call(
^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/pydantic/_internal/_validate_call.py", line 33, in wrapper_function
return await wrapper(*args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/rabbitmq/rpc_interfaces/catalog/services.py", line 94, in _call
return await rpc_client.request(
^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/rabbitmq/_client_rpc.py", line 96, in request
return await asyncio.wait_for(awaitable, timeout=timeout_s)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/asyncio/tasks.py", line 502, in wait_for
raise exceptions.TimeoutError() from exc
TimeoutError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/aiohttp/monitoring.py", line 183, in middleware_handler
resp = await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/opentelemetry/instrumentation/aiohttp_server/__init__.py", line 230, in middleware
resp = await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/aiohttp_session/__init__.py", line 215, in factory
raise cast(web.HTTPException, response)
File "/home/scu/.venv/lib/python3.11/site-packages/aiohttp_session/__init__.py", line 199, in factory
response = await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/aiohttp/rest_middlewares.py", line 139, in _middleware_handler
raise http_error from err
aiohttp.web_exceptions.HTTPGatewayTimeout
Stack (most recent call last):
File "/home/scu/.venv/bin/gunicorn", line 10, in <module>
sys.exit(run())
File "/home/scu/.venv/lib/python3.11/site-packages/gunicorn/app/wsgiapp.py", line 66, in run
WSGIApplication("%(prog)s [OPTIONS] [APP_MODULE]", prog=prog).run()
File "/home/scu/.venv/lib/python3.11/site-packages/gunicorn/app/base.py", line 235, in run
super().run()
File "/home/scu/.venv/lib/python3.11/site-packages/gunicorn/app/base.py", line 71, in run
Arbiter(self).run()
File "/home/scu/.venv/lib/python3.11/site-packages/gunicorn/arbiter.py", line 201, in run
self.manage_workers()
File "/home/scu/.venv/lib/python3.11/site-packages/gunicorn/arbiter.py", line 570, in manage_workers
self.spawn_workers()
File "/home/scu/.venv/lib/python3.11/site-packages/gunicorn/arbiter.py", line 641, in spawn_workers
self.spawn_worker()
File "/home/scu/.venv/lib/python3.11/site-packages/gunicorn/arbiter.py", line 608, in spawn_worker
worker.init_process()
File "/home/scu/.venv/lib/python3.11/site-packages/aiohttp/worker.py", line 51, in init_process
super().init_process()
File "/home/scu/.venv/lib/python3.11/site-packages/gunicorn/workers/base.py", line 143, in init_process
self.run()
File "/home/scu/.venv/lib/python3.11/site-packages/aiohttp/worker.py", line 57, in run
self.loop.run_until_complete(self._task)
File "/usr/local/lib/python3.11/asyncio/base_events.py", line 641, in run_until_complete
self.run_forever()
File "/usr/local/lib/python3.11/asyncio/base_events.py", line 608, in run_forever
self._run_once()
File "/usr/local/lib/python3.11/asyncio/base_events.py", line 1936, in _run_once
handle._run()
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/aiohttp/monitor_slow_callbacks.py", line 33, in instrumented
retval = _run(self)
File "/home/scu/.venv/lib/python3.11/site-packages/aiodebug/log_slow_callbacks.py", line 27, in instrumented
return_value = _run(self)
File "/usr/local/lib/python3.11/asyncio/events.py", line 84, in _run
self._context.run(self._callback, *self._args)
File "/home/scu/.venv/lib/python3.11/site-packages/aiohttp/web_protocol.py", line 433, in _handle_request
resp = await request_handler(request)
File "/home/scu/.venv/lib/python3.11/site-packages/aiohttp/web_app.py", line 504, in _handle
resp = await handler(request)
File "/home/scu/.venv/lib/python3.11/site-packages/aiohttp/web_middlewares.py", line 117, in impl
return await handler(request)
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/aiohttp/monitoring.py", line 227, in middleware_handler
log.error(
log_level=ERROR | log_timestamp=2025-03-24 10:52:25,624 | log_source=servicelib.aiohttp.rest_middlewares:_process_and_raise_unexpected_error(63) | log_uid=None | log_oec=OEC:e9779942adee-1742813545617| log_trace_id=8f844658bb4761d605c5c5b7d3d862ab | log_span_id=905bc4a9cfdaa408 | log_resource.service.name= | log_trace_sampled=True] | log_msg=We apologize for the inconvenience. The issue has been recorded, please report it if it persists..
{'context': "{'code': 'RuntimeError.BaseRPCError.RPCServerError',
"
" 'exc_message': 'badly formed hexadecimal UUID string',
"
" 'exc_type': 'builtins.ValueError',
"
' \'message\': "While running method \'list_jobs\' raised '
'\'builtins.ValueError\': "
'
' "\'badly formed hexadecimal UUID string\'\
"
'
" ' File '
"
' '
'\'"/home/scu/.venv/lib/python3.11/site-packages/servicelib/rabbitmq/_rpc_router.py", '
"'
"
" 'line 55, in _wrapper\
'
"
" ' return await func(*args, **kwargs)\
'
"
" ' ^^^^^^^^^^^^^^^^^^^^^^^^^^^\
'
"
" '\
'
"
" ' File '
"
' '
'\'"/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/api/rpc/_async_jobs.py", '
"'
"
" 'line 141, in list_jobs\
'
"
" ' task_uuids = await "
"get_celery_client(app).get_task_uuids(\
'
"
" ' "
"^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\
'
"
" '\
'
"
" ' File '
"
' '
'\'"/home/scu/.venv/lib/python3.11/site-packages/common_library/async_tools.py", '
"'
"
" 'line 18, in wrapper\
'
"
" ' return await loop.run_in_executor(\
'
"
" ' ^^^^^^^^^^^^^^^^^^^^^^^^^^^\
'
"
" '\
'
"
" ' File "
'"/usr/local/lib/python3.11/concurrent/futures/thread.py", \'
'
" 'line 58, in run\
'
"
" ' result = self.fn(*self.args, **self.kwargs)\
'
"
" ' ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\
'
"
" '\
'
"
" ' File '
"
' '
'\'"/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/modules/celery/client.py", '
"'
"
" 'line 133, in get_task_uuids\
'
"
" ' task_uuids = "
"self._get_completed_task_uuids(task_context)\
'
"
" ' "
"^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\
'
"
" '\
'
"
" ' File '
"
' '
'\'"/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/modules/celery/client.py", '
"'
"
" 'line 123, in _get_completed_task_uuids\
'
"
" ' return {\
'
"
" ' ^\
'
"
" '\
'
"
" ' File '
"
' '
'\'"/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/modules/celery/client.py", '
"'
"
" 'line 124, in <setcomp>\
'
"
" ' TaskUUID(\
'
"
" '\
'
"
' \' File "/usr/local/lib/python3.11/uuid.py", line '
"178, in '
"
" '__init__\
'
"
' " raise ValueError(\'badly formed hexadecimal UUID '
'string\')\
",
'
" 'method_name': 'list_jobs',
"
" 'request.method': 'GET',
"
" 'request.path': '/v0/tasks',
"
" 'request.remote': '10.2.86.31',
"
" 'traceback': ' File '
"
' '
'\'"/home/scu/.venv/lib/python3.11/site-packages/servicelib/rabbitmq/_rpc_router.py", '
"'
"
" 'line 55, in _wrapper\
'
"
" ' return await func(*args, **kwargs)\
'
"
" ' ^^^^^^^^^^^^^^^^^^^^^^^^^^^\
'
"
" '\
'
"
" ' File '
"
' '
'\'"/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/api/rpc/_async_jobs.py", '
"'
"
" 'line 141, in list_jobs\
'
"
" ' task_uuids = await "
"get_celery_client(app).get_task_uuids(\
'
"
" ' "
"^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\
'
"
" '\
'
"
" ' File '
"
' '
'\'"/home/scu/.venv/lib/python3.11/site-packages/common_library/async_tools.py", '
"'
"
" 'line 18, in wrapper\
'
"
" ' return await loop.run_in_executor(\
'
"
" ' ^^^^^^^^^^^^^^^^^^^^^^^^^^^\
'
"
" '\
'
"
" ' File '
"
' '
'\'"/usr/local/lib/python3.11/concurrent/futures/thread.py", line '
"'
"
" '58, in run\
'
"
" ' result = self.fn(*self.args, "
"**self.kwargs)\
'
"
" ' "
"^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\
'
"
" '\
'
"
" ' File '
"
' '
'\'"/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/modules/celery/client.py", '
"'
"
" 'line 133, in get_task_uuids\
'
"
" ' task_uuids = "
"self._get_completed_task_uuids(task_context)\
'
"
" ' "
"^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\
'
"
" '\
'
"
" ' File '
"
' '
'\'"/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/modules/celery/client.py", '
"'
"
" 'line 123, in _get_completed_task_uuids\
'
"
" ' return {\
'
"
" ' ^\
'
"
" '\
'
"
" ' File '
"
' '
'\'"/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/modules/celery/client.py", '
"'
"
" 'line 124, in <setcomp>\
'
"
" ' TaskUUID(\
'
"
" '\
'
"
' \' File "/usr/local/lib/python3.11/uuid.py", line '
"178, in '
"
" '__init__\
'
"
' " raise ValueError(\'badly formed hexadecimal '
'UUID string\')\
"}',
'error_code': 'OEC:e9779942adee-1742813545617',
'exception_details': "While running method 'list_jobs' raised "
"'builtins.ValueError': 'badly formed hexadecimal UUID "
"string'
"
' File '
'"/home/scu/.venv/lib/python3.11/site-packages/servicelib/rabbitmq/_rpc_router.py", '
'line 55, in _wrapper
'
' return await func(*args, **kwargs)
'
' ^^^^^^^^^^^^^^^^^^^^^^^^^^^
'
'
'
' File '
'"/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/api/rpc/_async_jobs.py", '
'line 141, in list_jobs
'
' task_uuids = await '
'get_celery_client(app).get_task_uuids(
'
' '
'^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
'
'
'
' File '
'"/home/scu/.venv/lib/python3.11/site-packages/common_library/async_tools.py", '
'line 18, in wrapper
'
' return await loop.run_in_executor(
'
' ^^^^^^^^^^^^^^^^^^^^^^^^^^^
'
'
'
' File '
'"/usr/local/lib/python3.11/concurrent/futures/thread.py", '
'line 58, in run
'
' result = self.fn(*self.args, **self.kwargs)
'
' ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
'
'
'
' File '
'"/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/modules/celery/client.py", '
'line 133, in get_task_uuids
'
' task_uuids = '
'self._get_completed_task_uuids(task_context)
'
' '
'^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
'
'
'
' File '
'"/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/modules/celery/client.py", '
'line 123, in _get_completed_task_uuids
'
' return {
'
' ^
'
'
'
' File '
'"/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/modules/celery/client.py", '
'line 124, in <setcomp>
'
' TaskUUID(
'
'
'
' File "/usr/local/lib/python3.11/uuid.py", line 178, '
'in __init__
'
" raise ValueError('badly formed hexadecimal UUID "
"string')
",
'exception_type': "<class 'servicelib.rabbitmq._errors.RPCServerError'>",
'tip': None}
Traceback (most recent call last):
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/aiohttp/rest_middlewares.py", line 83, in _middleware_handler
return await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/aiohttp/rest_middlewares.py", line 175, in _middleware_handler
resp = await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_webserver/products/_web_middlewares.py", line 101, in discover_product_middleware
return await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/aiohttp/profiler_middleware.py", line 49, in profiling_middleware
return await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/aiohttp/long_running_tasks/_error_handlers.py", line 18, in base_long_running_error_handler
return await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_webserver/login/decorators.py", line 71, in _wrapper
return await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_webserver/security/decorators.py", line 24, in _wrapped
return await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_webserver/exception_handling/_base.py", line 145, in _wrapper
return await handler(request)
^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_webserver/tasks/_rest.py", line 76, in get_async_jobs
user_async_jobs = await async_jobs.list_jobs(
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/rabbitmq/rpc_interfaces/async_jobs/async_jobs.py", line 79, in list_jobs
_result: list[AsyncJobGet] = await rabbitmq_rpc_client.request(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/rabbitmq/_client_rpc.py", line 96, in request
return await asyncio.wait_for(awaitable, timeout=timeout_s)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/asyncio/tasks.py", line 489, in wait_for
return fut.result()
^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/aio_pika/patterns/rpc.py", line 371, in call
return await future
^^^^^^^^^^^^
servicelib.rabbitmq._errors.RPCServerError: While running method 'list_jobs' raised 'builtins.ValueError': 'badly formed hexadecimal UUID string'
File "/home/scu/.venv/lib/python3.11/site-packages/servicelib/rabbitmq/_rpc_router.py", line 55, in _wrapper
return await func(*args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/api/rpc/_async_jobs.py", line 141, in list_jobs
task_uuids = await get_celery_client(app).get_task_uuids(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/common_library/async_tools.py", line 18, in wrapper
return await loop.run_in_executor(
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 58, in run
result = self.fn(*self.args, **self.kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/modules/celery/client.py", line 133, in get_task_uuids
task_uuids = self._get_completed_task_uuids(task_context)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/modules/celery/client.py", line 123, in _get_completed_task_uuids
return {
^
File "/home/scu/.venv/lib/python3.11/site-packages/simcore_service_storage/modules/celery/client.py", line 124, in <setcomp>
TaskUUID(
File "/usr/local/lib/python3.11/uuid.py", line 178, in __init__
raise ValueError('badly formed hexadecimal UUID string')