Any plan to add `taskName` logging attribute as `CallsiteParameter`

[PrieJos]

Hello,

As of Python 3.12, the standard library logging added a new attribute taskName (see here). Is there any plan to add this attribute as well to structlog at some point?

Thanks Jose M. Prieto

[hynek]

Not immediately, but open to PRs. Shouldn't be too difficult, but my focus is elsewhere right now.

[PrieJos]

Not immediately, but open to PRs. Shouldn't be too difficult, but my focus is elsewhere right now.

Thanks. I’ll try to come out with a proposal.

Cheers José M. Prieto

[PrieJos]

Hi,

I have come out with this PR 698 which add a new member TASK_NAME to the enumeration CallsiteParameter and the respective handlers to the CallsiteParameterAdder processor so that a mew field task_name is added to the event dict upon processing. The compute of this new field is quite easy and looks like this (this helper function is added to the module structlog._utils):

def get_taskname() -> Optional[str]:
    """
    Get the current asynchronous task if applicable.

    Returns:
        Optional[str]: asynchronous task name.
    """
    task_name = None
    with suppress(Exception):
        task = asyncio.current_task()
        if task:
            task_name = task.get_name()
    return task_name

So task_name will become None if no event loop is running or whatever the asyncio.Task.get_name() method returns otherwise.

I also added into the PR a few test cases which are all passed.

However, what I noticed was that it doesn't work as expected when running async. I wrote the attach small Python script a.py that you can execute sync (w/ option --sync) or async (no options or --async). The idea of such a script is to compare the callsite information as displayed by structlog and the standard logging module.

a.zip

If executed synchronously, then no issues. Callsite parameters are equal on both sides:

🟢 python a.py --sync
~~~ Synchrnous Mode ~~~
2025-02-01T21:36:31 [info     ] structlog -> Start of async task (sleep: 0.40) filename=a.py func_name=routine lineno=95 module=a process=407380 process_name=n/a task_name=None thread_name=MainThread
2025-02-01T21:36:31 [info     ] structlog -> End of async task filename=a.py func_name=routine lineno=100 module=a process=407380 process_name=n/a task_name=None thread_name=MainThread
2025-02-01T21:36:31 INFO 407380 MainProcess a a.py:routine:93 MainThread None logging -> Start of async task (sleep: 0.78)
2025-02-01T21:36:32 INFO 407380 MainProcess a a.py:routine:98 MainThread None logging -> End of async task

The differences can be seen if executed asynchrnously:

🟢 python tmp/a.py --async
~~~ Asynchrnous Mode ~~~
2025-02-01T21:36:55 [info     ] structlog -> Start of async task (sleep: 0.55) filename=a.py func_name=aroutine lineno=66 module=a process=407651 process_name=n/a task_name=None thread_name=asyncio_0
2025-02-01T21:36:55 [info     ] structlog -> End of async task filename=a.py func_name=aroutine lineno=74 module=a process=407651 process_name=n/a task_name=None thread_name=asyncio_0
2025-02-01T21:36:55 INFO 407651 MainProcess a a.py:aroutine:64 MainThread AsyncRoutine logging -> Start of async task (sleep: 0.63)
2025-02-01T21:36:56 INFO 407651 MainProcess a a.py:aroutine:72 MainThread AsyncRoutine logging -> End of async task

• The callsite parameter TASK_NAME I added isn't working the same. While logging shows the right task name AsyncRoutine, structlog shows None.
• However, neither the callsite parameters PROCESS_NAME nor THREAD_NAME aren't working either. logging shows them as MainProcess and MainThread resp., while structlog shows them as n/a and asyncio_0 which are not correct by the way.

As far as I could see, the reason I think is the way structlog calls out the async version of the logger method ainfo, awarning, etc. They are eventually proxied to the respective sync versions and executed in another thread using asyncio.get_running_loop().run_in_executor by the corresponding bound logger. That explains the difference in the output respect the standard logging module. To see this visually, see the attached structlog.png that shows the call stack on a breakpoint on structlog._utils.get_taskname when executing the test tests/processors/test_processors.py::TestCallsiteParameterAdder::test_async[BoundLogger-ainfo].

So, in short, assuming my analysis is right, there way to add "task name" as another callsite parameter is not feasible. Indeed, neither the "process name" nor "thread name" seems to work. Do you have any other suggestion/idea how it can be added (if any)?

Thanks!

PS: Sorry for the long post.

Cheers, Jose M. Prieto