dagster-io / dagster

An orchestration platform for the development, production, and observation of data assets.
https://dagster.io
Apache License 2.0
11.15k stars 1.4k forks source link

Dagster CLI `--log-level` behavior to match dagster.yaml `python_log_level` #22333

Open cmpadden opened 3 months ago

cmpadden commented 3 months ago

Dagster version

dagster, version 1.7.3

What's the issue?

Setting the --log-level and --code-server-log-level flags does not suppress logging in context.log messages.

"""
USAGE
    dagster dev -f dagster-logging-example.py --code-server-log-level warning --log-level warning
"""

from dagster import AssetExecutionContext, Definitions, asset

@asset
def example_asset(context: AssetExecutionContext):
    context.log.info(":wave:")

defs = Definitions(assets=[example_asset])
2024-06-06 12:57:33 -0400 - dagster - DEBUG - __ASSET_JOB - 4f851bde-ef71-4ae9-8994-92d08d3147bb - 79853 - LOGS_CAPTURED - Started capturing logs in process (pid: 79853).
2024-06-06 12:57:33 -0400 - dagster - DEBUG - __ASSET_JOB - 4f851bde-ef71-4ae9-8994-92d08d3147bb - 79853 - example_asset - STEP_START - Started execution of step "example_asset".
2024-06-06 12:57:33 -0400 - dagster - INFO - __ASSET_JOB - 4f851bde-ef71-4ae9-8994-92d08d3147bb - example_asset - :wave:
2024-06-06 12:57:33 -0400 - dagster - DEBUG - __ASSET_JOB - 4f851bde-ef71-4ae9-8994-92d08d3147bb - 79853 - example_asset - STEP_OUTPUT - Yielded output "result" of type "Any". (Type check passed).

However, setting python_log_level in dagster.yaml works as expected.

$ cat dagster.yaml
python_logs:
  python_log_level: WARNING

$ export DAGSTER_HOME=$(pwd)

$ echo $DAGSTER_HOME
/Users/colton/src/example_project

$ dagster dev -f dagster-logging-example.py

Is this intended behavior, or a possible bug?

What did you expect to happen?

I would expect setting --log-level warning on the CLI would suppress INFO level statements.

How to reproduce?

No response

Deployment type

Local

Deployment details

No response

Additional information

See Slack conversation here: https://dagster.slack.com/archives/C01U954MEER/p1717678439716179

Message from the maintainers

Impacted by this issue? Give it a 👍! We factor engagement into prioritization.

cmpadden commented 3 months ago

It's very possible that this is a simple misunderstanding on how --log-level should function, but I wanted to get clarification. Thanks.

https://docs.dagster.io/_apidocs/cli#cmdoption-dagster-dev-log-level

mattjmcelroy commented 2 days ago

According to what I'm seeing in the code base, it's likely this is intended behavior when logging step, job, and resource events. I reproduced this behavior during asset materialization.

The log_step_event(), log_job_event(), and log_resource() functions each log using the log_dagster_event() function in the DagsterLogManager class.

DagsterLogManager inherits from Python's logging.Logger class and overrides the log() function.

Within this overridden function, we see that the previous authors intended to log Dagster events regardless of level by adding the "or" clause to what is usually a simple check to determine whether the log level is enabled for the logger.

From line 421 in python_modules/dagster/dagster/_core/log_manager.py:

        # log DagsterEvents regardless of level
        if self.isEnabledFor(level) or (
            "extra" in kwargs and LOG_RECORD_EVENT_ATTR in kwargs["extra"]
        ):
            self._log(level, msg, args, **kwargs)

Based on this observation, I recommend this ticket be closed if this is, in fact, the intended behavior.