I am using PREFECT_LOGGING_EXTRA_LOGGERS to set an...
# ask-community
j
I am using PREFECT_LOGGING_EXTRA_LOGGERS to set an extra logger from one of my libraries to show up in my flow logs. I want to set the log level of that extra logger. mylib's logger has level set to DEBUG because that is needed by one of the two handlers mylib.logger's FileHandler has level set to DEBUG mylib.logger's RichHandler has level set to INFO I want the output of the logger in PrefectUI to also be INFO but I'm not sure how to set that. I'm currently seeing all the DEBUG messages, which is too much
c
Hey Janet! You should be able to set that with a setting:
Copy code
PREFECT_LOGGING_LOGGERS_PREFECT_EXTRA_LEVEL="INFO"
long name, but that should do the trick -- let me know if that doesn't meet your needs
j
Is there a typo?
Copy code
$ prefect config set PREFECT_LOGGING_LOGGERS_PREFECT_EXTRA_LEVEL="INFO"
Unknown setting name 'PREFECT_LOGGING_LOGGERS_PREFECT_EXTRA_LEVEL'.
c
eek that's annoying; it's not a pre-registered setting so you'll need to set it as an environment variable unfortunately:
Copy code
export PREFECT_LOGGING_LOGGERS_PREFECT_EXTRA_LEVEL="INFO"
j
Didn't fix it. But, stopping for the day and will try to track it down tomorrow.
🫡 1
I am running the deployment from the command line and I want to put a breakpoint in my flow to try to understand what's going on with my loggers, but it seems that doesn't work because the flow is in a subprocess - what is the right way to do this?
Wait... let me try uploading latest file again
@Chris White would love a code review on this Settings are: PREFECT_LOGGING_EXTRA_LOGGERS=jds PREFECT_LOGGING_LEVEL=INFO PREFECT_LOGGING_LOGGERS_PREFECT_EXTRA_LEVEL=INFO PREFECT_LOGGING_TO_API_WHEN_MISSING_FLOW='ignore' Observed behavior: terminal: validator messages showed up twice, once before serving and once after (can live with this for now until I fix my validators to be able to figure out if they're really flowing) Info and warning levels as desired. main and flow_main messages showed up once, info and warning as desired. logfile: info, warning and debug messages showed up in the log file from all three locations, but validator message only showed up once. UI: info, warning, debug messages showed up from "flow_main" but nothing from the validator (need to figure out how to fix that part for when the validator ran after serving). And, did not want anything from "debug" level here.
c
this is a little too tricky for me to debug in slack - would you mind opening a github issue for this and we can migrate the convo there?
j
Yeah, will be later, because I have a couple of meetings now
👍 1
c
thank you!!
j
@Chris White it looks like setting PREFECT_LOGGING_HANDLERS_API_LEVEL=INFO makes the debug messages go away from my flow run output -- but since that setting is not just for my "extra" logger, I'm wondering if there are any unintended consequences of setting that? Well, some combination of tweaking all the level args I could find temporarily turned it off but I need to do more testing to find the one(s) that actually did the trick
Also, is there any way to change the settings before calling a flow or subflow? I'm especially interested in the ones I can't pre-set using
prefect config set
c
Hey Janet! Sorry for the delay on that issue, I'm speaking / attending Big Data London all week - right now the best way to configure settings at runtime is through environment variables but we are working on improving that experience / functionality as documented in our recent milestone here: https://github.com/PrefectHQ/prefect/milestone/25
j
I really like that! I am trying to use the profile stuff because you can just set it up once and forget it, but the vision of storing required settings right next to the flow code so that it doesn't matter what environment variables are set in the user's shell. For fixing my logs, I just added another filter to prefect's logger and called it good enough for now!
🙌 1
Copy code
logger = logging.getLogger(LOGGER_NAME)
    logger.setLevel(logging.DEBUG)
    logger.propagate = False

    # Hack the prefect filters to not emit debug level messages
    if logger.hasHandlers():
        for handler in logger.handlers:
            handler.addFilter(no_emit_jds_debug)
        
def no_emit_jds_debug(record: logging.LogRecord) -> bool:
    """A hook to make sure that prefect.extra does not emit jds messages
    above the level that I want to store in Prefect
    
    Returns
    -------
    bool:
        True: continue processing this record, False: kill it
    """
    name = record.name
    level = record.levelno
    if (name == LOGGER_NAME) and (level < <http://logging.INFO|logging.INFO>):
        return False
    return True
💯 1
@Chris White If I am spawning tasks do I need to set up my loggers again for each new thread or is it supposed to be inherited?
I think what's happening is that they're being buffered and not shown right away.
Yeah, the last task completion messages from
prefect.task_runs
logger were at 95930 but the my task-statistics log messages were from 95955 to 10:01. I am logging them from a task.add_done_callback callback. Should that cause a 30 second delay? I could shift the log messages to the body of the task function instead.
@Chris White I've been chasing yet another logging issue and finally discovered that if I set PREFECT_LOGGING_EXTRA_LOGGERS in my environment, it works. If I set it in my profile (with prefect profile set), it doesn't. Does that make any kind of sense to you???
c
it really depends. Are you executing the workflow on the same machine as your profile?
j
There was a bug that was fixed! It works vs the main github branch now
🙌 1
The only problem I still have is having to manually filter the log level since none of the settings can reliably change it
c
so you want to be able to explicitly set the log level of the extra logger, right?
j
I set the log level of the "extra" logger, but I want the API handler to be at a different level - i.e. my file handler collects debug and above, but the API handler should only send info and above to the API. PREFECT_LOGGING_LOGGERS_PREFECT_EXTRA_LEVEL=INFO does not work so I'm hacking it.
c
gotcha, we can look into enabling that
j