https://prefect.io logo
Title
j

Jacques

04/30/2020, 2:51 PM
Hi all, I have a question about logging. we provide a trace_id Parameter to flows, and I'd like to include that trace_id in all log events inside tasks. Is this possible?
👀 1
d

Dylan

04/30/2020, 2:55 PM
Hi @Jacques! Just to make sure I understand what you’re asking, you want all logs emitted by Prefect to include your
trace_id
, or all logs emitted by your task code with:
@task
def my_task():
    logger = prefect.context.get("logger")

    <http://logger.info|logger.info>("An info message.")
    logger.warning("A warning message.")
j

Jacques

04/30/2020, 2:56 PM
task code
trace_id is an upstream value that we use to link debug and metrics
I've tried adding a new handler in the start of the run() but that just creates two log events.
d

Dylan

04/30/2020, 2:58 PM
hmmm
j

Jacques

04/30/2020, 2:59 PM
I've read about logadapter, but that would end with me doing self.logger = log_adapter which doesn't seem right
d

Dylan

04/30/2020, 2:59 PM
So a sort of brute-force way to do this would be to make sure all tasks pass the
trace_id
in dependencies and then write a small custom logger that accepted the
trace_id
as a parameter
But that feels inelegant
j

Jacques

04/30/2020, 3:01 PM
Yup, and additional concern is that we use various SDKs in tasks which we'd like to have trace_id included as well
d

Dylan

04/30/2020, 3:01 PM
Let me ask the team for their input, I’ll get back to you in just a moment
j

Jacques

04/30/2020, 3:01 PM
cool, thanks!
d

Dylan

04/30/2020, 3:09 PM
Hi @Jacques, If you added the
trace_id
to your flow context, it would be accessible in all of your tasks and you’d be able to add it to all of your logs. Here’s some documentation that should be helpful: https://docs.prefect.io/api/latest/utilities/context.html#context https://docs.prefect.io/core/advanced_tutorials/custom-logs.html#an-example Here’s where we make context available to loggers: https://github.com/PrefectHQ/prefect/blob/master/src/prefect/utilities/logging.py#L170 Let me know if this helps!
j

Jacques

04/30/2020, 3:13 PM
Thanks so much, looking now!
Ok, I think I'm wrapping my head around this, so to get the trace_id into the logs I think I need to 1) put it into context 2) somehow add "trace_id" to PREFECT_LOG_RECORD_ATTRIBUTES in that src file you sent, and 3) add a new handler with a format that includes trace_id
I've done 1 already, and 2 I'm not sure what to do. For 3 adding a handler doesn't seem to work like the docs indicate.
d

Dylan

04/30/2020, 3:57 PM
hmm
j

Jacques

04/30/2020, 3:57 PM
I'm adding the following just before the flow:
task_logger = get_logger("Task")
test_handler = logging.StreamHandler()
formatter = logging.Formatter("#############%(message)s")
test_handler.setFormatter(formatter)
task_logger.addHandler(test_handler)
This is just a test, but it seems to have no impact
d

Dylan

04/30/2020, 3:58 PM
Just for reference, what version of Prefect are you using?
j

Jacques

04/30/2020, 4:03 PM
0.10.4
Updated to 0.10.5 and same
I think I solved 2 by doing
prefect.utilities.prefect.utilities.logging.PREFECT_LOG_RECORD_ATTRIBUTES = (
            PREFECT_LOG_RECORD_ATTRIBUTES + ("trace_id",)
        )
Seems very hacky though 🙂
d

Dylan

04/30/2020, 4:14 PM
That does seem hacky
I’m trying to reproduce #3 now
Is changing your log message format from either your
.prefect/config.toml
file or by environment variable with
PREFECT__LOGGING__FORMAT="[%(asctime)s] %(levelname)s - %(name)s | %(message)s"
working for you?
j

Jacques

04/30/2020, 4:21 PM
it does work, but the problem is that it changes for all prefect logs - so if I put trace_id in the format it errors because it only (hopefully now with my patches) exists in Tasks
d

Dylan

04/30/2020, 4:21 PM
Ahh right
j

Jacques

04/30/2020, 4:21 PM
So I sort of need a PREFECT__TASKS__LOGGING__FORMAT
d

Dylan

04/30/2020, 4:21 PM
I agree
I think this is definitely something we could improve
Would you mind opening an issue describing what you’re trying to do and your suggestions?
j

Jacques

04/30/2020, 4:23 PM
Yup will do
But in the meantime it just started working 😂
No idea why
d

Dylan

04/30/2020, 4:24 PM
Hooray!
😄
j

Jacques

04/30/2020, 4:26 PM
Ok, so the added handler doesn't work
Its just that all prefect logs now contain my injected trace_id
But that is fine, it seems to work - thanks a million dude! 3 times I've come here with a problem, and 3 times I've walked away with a solution, you guys rock!
I will open an issue as you asked, not sure this is long-term stable way to do it!
Yup, will include that in the issue
d

Dylan

04/30/2020, 4:28 PM
Thank you!
and cool 👍 I want to make sure the added handler is working
j

Jacques

04/30/2020, 4:30 PM
oh right - so that is a separate thing I think, will open two issues
d

Dylan

04/30/2020, 4:31 PM
That would be perfect
Thanks!