- Notifications
You must be signed in to change notification settings - Fork277
Open
Description
Looking for advice on ThreadPool separation for middleware and actual event, looking for ContextVars to be passed
Reproducible in:
pip freeze| grep slackpython --versionsw_vers&& uname -v# or `ver`
Theslack_bolt version
slack_bolt==1.20.1
slack_sdk==3.34.0
slackclient==2.9.4
Python runtime version
Python 3.11.10
OS info
ProductName:macOS
ProductVersion:15.3.1
BuildVersion:24D70
Darwin Kernel Version 24.3.0: Thu Jan 2 20:24:16 PST 2025; root:xnu-11215.81.4~3/RELEASE_ARM64_T6000
Steps to reproduce:
I am attempting to create a trace_id/correlation_id for all slack events/actions/views etc to help with tracking in our structured logs.
- Create Global middleware, contextvar, and LogFilter
Context
fromcontextvarsimportContextVarfromtypingimportOptionalfromslack_boltimportBoltContext# Middlewarecorrelation_id:ContextVar[Optional[str]]=ContextVar("correlation_id",default=None)
LogFilter
fromloggingimportFilter,LogRecordfromtypingimportOptionalfrom.modules.loggingimportcorrelation_iddef_trim_string(string:Optional[str],string_length:Optional[int])->Optional[str]:returnstring[:string_length]ifstring_lengthisnotNoneandstringelsestringclassCorrelationIdFilter(Filter):"""Logging filter to attached correlation IDs to log records"""def__init__(self,name:str="",uuid_length:int|None=None,default_value:str|None=None, ):super().__init__(name=name)self.uuid_length=uuid_lengthself.default_value=default_valuedeffilter(self,record:"LogRecord")->bool:""" Attach a correlation ID to the log record. Since the correlation ID is defined in the middleware layer, any log generated from a request after this point can easily be searched for, if the correlation ID is added to the message, or included as metadata. """cid=correlation_id.get(self.default_value)record.correlation_id=_trim_string(cid,self.uuid_length)returnTrue
Middleware
from.modules.loggingimportcorrelation_iddefcall(context:BoltContext,logger:Logger,next:Callable[[],None])->None:# Capture the current contextcurrent_context=copy_context()current_thread=threading.current_thread()id_value:str|None=correlation_id.get()ifid_valueisnotNone:logger.info(f"{__name__}{id_value=} found id in contextvar{current_thread=}" )elifcontext.get("correlation_id",None)isnotNone:id_value=context["correlation_id"]token=correlation_id.set(id_value)logger.info(f"{__name__}{id_value=} found id in context{current_thread=}")else:id_value=uuid4().hexcontext["correlation_id"]=id_valuetoken=correlation_id.set(id_value)logger.info(f"{__name__}{id_value=} generated new id{current_thread=}")try:current_context.run(next)finally:iftoken:correlation_id.reset(token)
- Since middleware is ran in a separate threadpool worker as the action/event/view, the contextvar isn't shared between them.
- Log filter always print None from the ContextVar due to this...
Expected result:
{"levelname": "INFO", "correlation_id": "34a110e2ba6d4100a099e18fd2fb4c74", "name": "module_name", "message": "log message here", "lineno": 44, "asctime": "2025-03-07 13:47:16,182", "exc_info": null}Actual result:
{"levelname": "INFO", "correlation_id": null, "name": "module_name", "message": "log message here", "lineno": 44, "asctime": "2025-03-07 13:47:16,182", "exc_info": null}Requirements
Please read theContributing guidelines andCode of Conduct before creating this issue or pull request. By submitting, you are agreeing to those rules.