Leverage mypy to check str.format expressions

[ThibaultLemaire]

from loguru import logger

class Foo:
bar = "baz"

foo = Foo()

logger.debug('The bar is "{my_foo.bar}"', my_foo=foo)  # ✓
logger.debug('The bar is "{my_foo.bar}"', my_foo="not foo")  # error: "str" has no attribute "bar"

For the record, this has been developed and tested against mypy==0.782.

Closes #42

[ThibaultLemaire]

@kornicameister How do you track which versions of mypy are compatible? Since I am tapping into mypy's internals I am worried it will break with upcoming versions, so I think we should have a way of making that visible.

[kornicameister]

@ThibaultLemaire thx for pull request. It looks really nice, I'd like to hear more about that visit_expr you came up with and how did you that. mypy is magical and that's a magic I am seeing :D.

Anyway,I really like your job on error messages although I wonder if having them more accurate wasn't better. Could you elaborate why did you change those?

PS. sorry for being so lazy about reviewing, I had my evenings filed with either micro-management on 2 children or overtime from work :/

[Delgan]

Well, I probably don't understand half of the magic of mypy, but the result looks great! Thanks for your work. :)

[ThibaultLemaire]

Hey, looks like it's my turn to apologize for the delay, last week was crazy at work.

Thank you @Delgan, I have been focusing precisely on keeping the magic on mypy's side with this PR and not having to understand it 😉 Hopefully we can make that work in a satisfying way

[kornicameister]

@ThibaultLemaire would you mind checking #31 ? Would you change invalid that PR?

[ThibaultLemaire]

Hm, I can imagine why my work would conflict with this PR, but I'm not sure how exactly the two would interact.

Also, what exactly do you mean by "invalid[ate]" ? If you mean make obsolete, I don't think so: my changes have no way of knowing if record=True has been passed, but if you mean conflict in a way that would require to update #31, I'm afraid so, yes.

I only glanced at it though, so I'll take the time to investigate properly.

[ThibaultLemaire]

Okay, so, after further investigation, I reckon you could adapt your work on #31 to make it work side by side, but then you'd have a bit of an overlap.

To take your example code from #18, and compare the (theoretical) results of #31 and #43 (this PR):

logger.info('{record["msg"]}') # loguru -> ❌, #31 -> ❌, #43 -> ❌
logger.opt(record=True).info('{record["msg"]}') # loguru -> ✔, #31 -> ✔, #43 -> ❌

As you can see, there would be duplicate error messages, as well as contradicting messages where my work has shortcomings and can't understand that record is a valid keyword argument.

The issue is that I rely entirely on mypy's internals and have no control over them, so I couldn't silence that error even if I wanted to.

What we could do, though, -- and, to me, that would be the best solution -- would be to pass the record argument to mypy to validate it as well. In the same spirit to what I've done here, this would mean making mypy validate

logger.opt(record=True).info('{record["msg"]}')

as if it were something like

logger.info('{record["msg"]}'.format(record={}))

Unfortunately, I don't know how much of your work we could reuse if we go down that path.

[ThibaultLemaire]

Also related to that, I have noticed that you store the loggers the plugin has previously encountered in the self._known_loggers dict, to deal with .opt() configuration, but this is discouraged by the mypy documentation (emphasis mine):

Plugin developers should ensure that their plugins work well in incremental and daemon modes. In particular, plugins should not hold global state due to caching of plugin hook results.

I wonder if we could rather play on the type we return from the plugin to store that configuration, which should save us a lot of trouble in the future as well.

To illustrate, I was wondering if we could make things work a bit like this:

from loguru import logger  # type is inferred by mypy to be Logger

with_record: LoggerWithRecord = logger.opt(record=True) 
# Those would be custom types that we return, in order to know what to do next time we encounter it
lazy: LazyLogger = logger.opt(lazy=True)
with_ip: BoundLogger = logger.bind(ip="192.168.0.1")
with_ip_in_record: BoundLoggerWithRecord = with_ip.opt(record=True)

# And here mypy should pass us all the info we need to validate it properly
with_ip_in_record.info("Your local ip is {record["ip"]}")

[kornicameister]

@ThibaultLemaire for the global state, I was not aware of that. If could drop the issue for that matter, I'd appreciate. Just put a link to your comment.

As for the #31 I think I'd prefer to have mypy deal with string formatting if possible. I imagine them doing far better job.
This is rather interesting glitch, I certainly need time to even get my head around. I mean, don't get it wrong, your idea is far nicer compared to mine but this record thingy makes it hard to just accept.
As you fairly pointed out it simply won't work now.

Unless, we can get our hands on record=True and somehow push into kwarg arguments of formatting call a type containing all fields from a record loguru defines. Anyway, record=True is not a point of interest on this PR. It is for #18 to resolve.
I will play around with your solution and I believe in the end of the week, unless something pops out, we can merge that.

@Delgan do you have any interesting cases we could use to challenge this PR? If you do, please put a comment :)

[Delgan]

I tried hard but could not generate a error specific to the _check_str_format_call function. Congrats for mastering mypy internals!

However, some tests led me to open #49. :p

[kornicameister]

@thx @Delgan , I will try to look at this if possible..or rather if I find time...it is horrible how little of that I have :D

[kornicameister]

Ok, lets proceed with it.
As I said before, for me it is better to reuse mypy because it might help with both making it work more predictable and more compliant with different mypy versions.
Also, given that @Delgan did not exactly raise incompatibility between logoru and this PR on runtime, I don't see anything that would prevent us from doing so.
Errors reported earlier are actually related to us using StrExpr all the time.

[kornicameister]

@ThibaultLemaire I am merging this. Thanks a lot for patience and waiting for me here :)