I've noticed an odd logging behavior in Prefect 2 ...
# prefect-community
m
I've noticed an odd logging behavior in Prefect 2 where sometimes strings that contain brackets
[
]
aren't being logged correctly. Has anyone else noticed this? Details in ๐Ÿงต
โœ… 1
Here's an example flow:
Copy code
from prefect import flow, task, get_run_logger

@task
def execute_sql(sql: str):
    logger = get_run_logger()
    <http://logger.info|logger.info>(f"Executing: {sql}")
    <http://logger.info|logger.info>(sql)


@flow
def bracket_flow():
    execute_sql("DROP TABLE [dbo].[SomeTable];")
    execute_sql("EXEC [dbo].[usp_SomeProcedure];")


if __name__ == "__main__":
    bracket_flow()
The output I get is:
Copy code
18:30:31.900 | INFO    | prefect.engine - Created flow run 'impetuous-sheep' for flow 'bracket-flow'
18:30:32.506 | INFO    | Flow run 'impetuous-sheep' - Created task run 'execute_sql-df2a3f5c-0' for task 'execute_sql'
18:30:32.507 | INFO    | Flow run 'impetuous-sheep' - Executing 'execute_sql-df2a3f5c-0' immediately...
18:30:32.714 | INFO    | Task run 'execute_sql-df2a3f5c-0' - Executing: DROP TABLE .[SomeTable];
18:30:32.715 | INFO    | Task run 'execute_sql-df2a3f5c-0' - DROP TABLE .[SomeTable];
18:30:32.792 | INFO    | Task run 'execute_sql-df2a3f5c-0' - Finished in state Completed()
18:30:32.885 | INFO    | Flow run 'impetuous-sheep' - Created task run 'execute_sql-df2a3f5c-1' for task 'execute_sql'
18:30:32.886 | INFO    | Flow run 'impetuous-sheep' - Executing 'execute_sql-df2a3f5c-1' immediately...
18:30:33.090 | INFO    | Task run 'execute_sql-df2a3f5c-1' - Executing: EXEC .;
18:30:33.091 | INFO    | Task run 'execute_sql-df2a3f5c-1' - EXEC .;
18:30:33.166 | INFO    | Task run 'execute_sql-df2a3f5c-1' - Finished in state Completed()
18:30:33.247 | INFO    | Flow run 'impetuous-sheep' - Finished in state Completed('All states completed.')
The text inside the brackets is being removed in the logs. I thought at first it might be some weird interaction with f-strings, but its happening when I just directly log the variable too.
a
I think it might be a side effect of rich console https://rich.readthedocs.io/en/stable/markup.html#escaping to workaround:
Copy code
from prefect import flow, task, get_run_logger

@task
def execute_sql(sql: str):
    logger = get_run_logger()
    <http://logger.info|logger.info>(f"Executing: {sql}")
    <http://logger.info|logger.info>(sql)


@flow
def bracket_flow():
    execute_sql("DROP TABLE \[dbo].\[SomeTable];")
    execute_sql("EXEC \[dbo].\[usp_SomeProcedure];")


if __name__ == "__main__":
    bracket_flow()
let me see if I can disable that behavior by default
yeah Iโ€™ll make a PR to disable markup by default https://rich.readthedocs.io/en/stable/markup.html#rendering-markup
m
Ah, interesting. Looks like this could be the issue.
a
m
Well thank you for writing that up. I appreciate it
๐Ÿ™Œ 1
a
thanks for the minimal reproducible example!
m
@Andrew Huang, it kind of blows my mind that the PR to fix this was already merged + shipped in the latest release, and I can now deploy it in our production environment. Amazing!
๐Ÿš€ 1
a
Awesome that I was able to help!