More lenient handling of loguru message mismatch and better warnings #338
Conversation
Codecov ReportAll modified and coverable lines are covered by tests ✅
Additional details and impacted files@@ Coverage Diff @@
## main #338 +/- ##
========================================
Coverage ? 100.00%
========================================
Files ? 119
Lines ? 8887
Branches ? 1157
========================================
Hits ? 8887
Misses ? 0
Partials ? 0 ☔ View full report in Codecov by Sentry. |
Deploying logfire-docs with
|
| Latest commit: |
16daad2
|
| Status: | ✅ Deploy successful! |
| Preview URL: | https://3c73c3ca.logfire-docs.pages.dev |
| Branch Preview URL: | https://alex-loguru-message-warnings.logfire-docs.pages.dev |
|
We have a lot of pragmas on loguru, should we add more tests there? |
|
No because I don't know if/how it's possible to actually trigger these failures. The warnings are there for users to alert us to things we didn't think of or know about, or changes in loguru. If we know about an edge case we should be implementing a fix for it. |
| if ( | ||
| isinstance(original_record, dict) | ||
| and isinstance(message := original_record.get('message'), str) | ||
| and message in record.msg | ||
| ): # pragma: no branch |
There was a problem hiding this comment.
@alexmojaki Hi, This piece of code will drop the loguru's format, I'm wondering if this is intentional. Because the replace it with the original message only worked when the record has exc_info, but now it always does the replacement.
# example.py
import logfire
from loguru import logger
log_format = "{level: <8} | {time:YYYY-MM-DD HH:mm:ss.SSS} | {message}"
logger.remove()
logfire.configure(
send_to_logfire='if-token-present',
service_name='xxx',
console=logfire.ConsoleOptions(include_timestamps=False) # remove timestamp prefix
)
logger.add(
logfire.loguru_handler()['sink'],
# sink=sys.stderr,
format=log_format,
level="INFO",
)
logger.info('hello world')with logfire==0.48.0, output INFO | 2024-08-13 14:15:37.811 | hello world
with logfire==0.48.1, output hello world
There was a problem hiding this comment.
Yes this is intentional. The integration is not designed for a loguru format. The message must be plain because it's also displayed in the UI:
It should just be:
How are you using logfire+loguru? Do you use the UI, or only the console? Does logfire log other non-loguru things to the console without timestamps?
The structlog integration has a console_log parameter which should probably be added to the loguru integration, so that logfire just doesn't log loguru logs to the console at all. Then timestamps don't need to be removed from other logs.
There was a problem hiding this comment.
Thank you. Currently, we use the loguru to print JSON logs to console, and then they will be collected to aws.cloudwatch, so we can do some filterings in cloudwatch, i.e., $record.extra.xxx = xxx. It's structured and easy to filter. We are still experimenting with Logfire, it's a great project, thanks. So, both systems are running in parallel, and we don't want any breaking changes on cloudwatch yet, as there is a lot of predefined filtering in it.
# example.py
import logfire
from loguru import logger
log_format = "{level: <8} | {time:YYYY-MM-DD HH:mm:ss.SSS} | {message}"
logger.remove()
logfire.configure(
send_to_logfire='if-token-present',
service_name='xxx',
console=logfire.ConsoleOptions(include_timestamps=False) # remove timestamp prefix
)
logger.add(
logfire.loguru_handler()['sink'],
# sink=sys.stderr,
format=log_format,
level="INFO",
serialize=True, # so it will print the logs in JSON format
)with logfire==0.48.0, it will print the JSON logs to stderr.
{"text": "INFO | 2024-08-14 09:25:58.212 | hello world", "record": {"elapsed": {"repr": "0:00:00.228754", "seconds": 0.228754}, "exception": null, "extra": {}, "file": {"name": "example.py", "path": "/Users/toddzhang/test/fastapi-test/tests/example.py"}, "function": "<module>", "level": {"icon": "ℹ️", "name": "INFO", "no": 20}, "line": 21, "message": "hello world", "module": "example", "name": "__main__", "process": {"id": 47410, "name": "MainProcess"}, "thread": {"id": 8462629568, "name": "MainThread"}, "time": {"repr": "2024-08-14 09:25:58.212465+08:00", "timestamp": 1723598758.212465}}}
with logfire==0.48.1, just plain text hello world
There was a problem hiding this comment.
if there's a way, we print the JSON logs to console/stderr for collection by AWS, and only display plain text on the Logfire UI?
There was a problem hiding this comment.
There was a problem hiding this comment.
I don't have permission to visit this Slack thread. But I found that I can add two sinks for loguru
- one is
sys.stderr, and we can print JSON messages to the console. - another is the
logfire.loguru_handler()['sink'], and configure logfire withconsole=False
So, the log messages sent to logfire are pure text, and the messages printed to the console are in JSON format.
Thanks for your help.😊
There was a problem hiding this comment.
See https://docs.pydantic.dev/logfire/help/ for the link to join the slack.
Are you not creating any logfire logs/spans outside of integrating with loguru? You're not using any other integrations?
Looking at corcel's logs, I could see cases where a loguru log contained a traceback. I could see that the
record.msg.startswith(message + '\nTraceback (most recent call last):')check would have just barely failed, although I don't know what loguru configuration could lead to this. In any case it was clear from a closer look at the loguru code thatrecord.msgcould differ frommessagein lots of ways and it seemed safest to just be extra lenient.I also made the warnings more detailed because I've been doing way too much guesswork when one gets reported.