Logging: add handlers

[stlehmann]

So far I have been missing the possibility to add different handlers to a logger in Micropython. Especially the RotatingFileHandler is a very useful tool to collect errors and warnings during runtime on a system with limited filespace.

This PR adds StreamHandler, FileHandler and RotatingFileHandler according to CPythons logging.handlers module. I tried to stay as close to the CPython origin as possible.

A logging.Logger object now has a addHandler() method to add multiple handlers to a logger. It is not yet possible to add separate logging levels for each handler. I would like to add this functionality in the future.

I tried to keep dependencies to a minimum, however this package depends now on the os package because of the advanced file-handling functionality needed. There might be a work-around to omit this dependency but I couldn' t find any on my own. I'm open to any suggestions.

I tried to follow the contribution guidelines as far as possible and hope that this PR will find its way into the upstream repository.

[pfalcon]

Thanks for the patchset! Adding more functionality is definitely good. There're a number of things to discuss here though, and I guess, we should start at the top-level:

Adding more functionality is definitely good, but more functionality means more bytecode (which can be put in ROM, but won't be all the time), and more data (which is always in RAM). logging is an important module, which is useful for any MicroPython port, even the smallest ones, like esp8266, microbit, etc. Do you have any feedback/comments regarding that?

[pfalcon]

Now something completely different: "" is the preferred string style in micropython-lib. https://github.com/pfalcon/micropython-lib/wiki/ContributorGuidelines was updated to make that more obvious. Also see https://github.com/pfalcon/micropython-lib/issues/14. This is not request to change this PR, feel free to argue why you wouldn't. (But the argument would work only once ;-) ).

[stlehmann]

Adding more functionality is definitely good, but more functionality means more bytecode (which can be put in ROM, but won't be all the time), and more data (which is always in RAM). logging is an important module, which is useful for any MicroPython port, even the smallest ones, like esp8266, microbit, etc. Do you have any feedback/comments regarding that?

I share your concerns about code size. I could think of adding just the addHandler() function to the existing logger module and shipping the handlers in a separate package called logging.handlers (same as os.path). This way there will be a still very slim logging package with the option to add advanced logging functionality from the logging.handlers module or even custom handlers. What do you think about this?

[pfalcon]

shipping the handlers in a separate package called logging.handlers

That would be a baseline pattern for solving such cases indeed, thanks for being in loop on it.

But I think that we have even more barebones case here: it's just the current logging module is perfect for many usages already. And well, we have a pattern for solving that too: that's why we have "urequests" - so someone can write (or port) the full "requests" if they want.

So, the solution would be to fork the current "logging" as "ulogging", and then let you pump up "logging" as you like. But! We actually have another pattern emerging: https://github.com/pfalcon/micropython-lib/commit/7a31c299c2c694621b412598414193b72c5cda79 . So, we now have even "uurequests", because "urequest" is growing bigger than initially conceived.

So I actually wonder if I should fork the current logging as "uulogging"?

Any comments?

[stlehmann]

I think that uulogging would be to many u's ;)

I like the idea of forking "logging" as "ulogging". However one drawback is that existing codebase would require a namechange. But it could be worth it as it allows to keep a minimalistic "ulogging" module and a "logging" module for more advanced logging use-cases which tries to implement the CPython logging-interface at least as far as it makes sense on micropython.

[pfalcon]

I think that uulogging would be to many u's ;)

That's true, but a precedent was already made ;-).

I like the idea of forking "logging" as "ulogging". However one drawback is that existing codebase would require a namechange.

Exactly, and that's why I bring a question of "ulogging" vs "uulogging". Just consider that later we'll decide to port full CPython's "logging" module. We'll not want to lose your great work, so will need to have another rename logging -> ulogging, ulogging -> uulogging. But ok, let's not fetch too far, and let's address concern as they become real (as long as we anticipate that all that may happen).

So, decided, I'll fork "ulogging" to clear the path for changes in this and possibly later PRs.

[pfalcon]

Well, next question then is dependence on the "os" module. As you know, one in the micropython-lib works only on Unix systems. At the same time, my quick scan thru your patch showed that all functions which you use also available in "uos". If we use that, compliant bare metal ports will be able to enjoy log rotation, etc. too. Caveat is a goof on the Unix port side: https://github.com/micropython/micropython/pull/4308. Well, patch for it is submitted.

Again, asking for your opinion what to do here.

[stlehmann]

Yes, I would very much like to omit the "os" module dependency.

I used the "os" module only for rename, remove and stat. I know the "stat" function exists in "uos" so I can easily replace this one. I didn't know that "unlink" was equal to "remove". Anyway if https://github.com/micropython/micropython/pull/4308 wil be applied I will gladly use uos.remove.

The last function is a bit trickier. There is no rename function in "uos". I could imagine implementing this bit by just reading and writing the file and afterwards deleting the original. I don't know how efficient that is compared to "os.rename", though. What do you think?

[pfalcon]

There is no rename function in "uos".

Ah, I see, there's no rename() in unix port. Well... I guess we can add it in the name of "finishing MicroPython"...

I could imagine implementing this bit by just reading and writing the file and afterwards deleting the original.

Fairly speaking, I don't like workarounds you added in the latest commits. The idea behind micropython-lib is to stay clean. I guess, it's better to stick with "os" for now then, while make a ticket to switch to "uos" after some time-out.

Anyway if micropython/micropython#4308 wil be applied I will gladly use uos.remove.

Lately, there was pretty low response to patches submitted to mainline, but we'll see.

[pfalcon]

ulogging module is made: https://github.com/pfalcon/micropython-lib/commit/87e7271220c9369bd025a888478126366a81bada

[stlehmann]

I guess, it's better to stick with "os" for now then, while make a ticket to switch to "uos" after some time-out

Hm it's hard for me to tell which option is the better one. You are right it needed some hacky workarounds to get rid of the "os" dependency. You pointed out that the "os" package only works on Unix. I was not aware of that before. But considering it this would mean a massive drawback for the "logging" package.

[pfalcon]

You pointed out that the "os" package only works on Unix.

To elaborate on that, I thought it would cause error if imported on a port which doens't provide "ffi" module. But turned out, I already took measures some time ago to alleviate that. And in 7af606cdedcf16a80da0c9bd2cbde2384df9700d I made changes to prefer uos' remove() and rename(), if those are available.

I didn't test it on a baremetal port though, if you're interested in that scenario, please test it.

[pfalcon]

You are right it needed some hacky workarounds to get rid of the "os" dependency.

And to elaborate on that, I'm not thrilled with that. When a bunch of such workarounds accumulate, one starts to feel aversion to doing much for such a project, because it becomes augean stables an requires herculean efforts to do anything. So, I'm not keen to even start in that way (and arguably, micropython-lib has enough stuff already which needs cleanup).

The whole idea is that micropython and micropython-lib go together, and issues are fixed, not worked around. And actually I do all that in my fork, like previously I did all that in the mainline.

[stlehmann]

I didn't test it on a baremetal port though, if you're interested in that scenario, please test it. I just tried it on an ESP32 port. It turns out there is already an 'os' module installed on it which provides all the needed functions.

The whole idea is that micropython and micropython-lib go together, and issues are fixed, not worked around.

I get the idea. So I will rewind the last commits to provide a more straight-forward implementation.

One more thing. This could be a new issue actually. If I install the 'os' module on ESP32 via upip.install('micropython-os') this will break my REPL. It will give me a traceback everytime I try to connect:

Traceback (most recent call last):\r\n File "", line 1, in \r\n File "/lib/os/init.py", line 77, in getcwd\r\nNameError: name \'getcwd_\' isn\'t defined\r\n'

This should definetely not happen. Shall I open a new issue for it?

[pfalcon]

Shall I open a new issue for it?

Sure. Please don't forget to explain how you connect. Because it looks that something which connects you issues os.getcwd(), which cannot be right on its own.

[pfalcon]

It turns out there is already an 'os' module installed on it which provides all the needed functions.

Missed this earlier.

Please make sure you understand the MicroPython module architecture well: http://docs.micropython.org/en/latest/library/index.html (all the intro paragraphs there, yeah).

[stlehmann]

So I rewinded the last commits but removed the os dependency. We don't want the os library to overwrite the uos module on 'bare-metal' as this would not work due to the missing libc.

[pfalcon]

So I rewinded the last commits but removed the os dependency.

So, how will it work at all then?

We don't want the os library to overwrite the uos module on 'bare-metal' as this would not work due to the missing libc.

It's impossible for "os" to overwrite "uos", those are 2 different modules (and MicroPython was specifically designed to keep them distinct, though yeah, those "weak links" for modules in baremetal ports to confuse the matter). And what we're doing here lately is actually making possible for micropython-lib's "os" module to be installed on bare-metal targets, and available baremetal functionality to be accessible thru it.

Sorry about these diversions - but that's exactly the kind of work a maintainer does all the time, and I need help with it.

[stlehmann]

It's impossible for "os" to overwrite "uos", those are 2 different modules

Yeah, I didnt' mean "overwrite" per se more like replace the link to uos.

I think with the fix for https://github.com/pfalcon/micropython-lib/issues/15 it there will be clearance to include "os" dependency in this package. I already wrote the fix, just needs testing on bar-metal board. Will push soon.

[stlehmann]

With PR https://github.com/pfalcon/micropython-lib/pull/16 the problem should be solved. I returned "os" in the dependencies.

[pfalcon]

Ok, so my approach to review non-simple patches (and any patch beyond 5 lines is non-simple) is commit by commit, merging whatever is ok.

• logging: make logging a package - ok, merged
• logging: add handlers module with RotatingFileHandler - merged with noticeable changes, see inline comments.

[pfalcon]

This shows the complexity of the task. On one hand, it's trivial. On the other, there're so many things to get wrong. And there're hundreds of packages. Nobody will ever fix them if they're wrong from the beginning. The only way to deal with that is not getting things wrong.

Please rebase. You'll get conflicts, you should git rebase --skip you version of "logging: add handlers module with RotatingFileHandler" completely.

[stlehmann]

Thanks for fixing and for the comments.

[stlehmann]

OK, I did the rebase. Hopefully I did this right.

[pfalcon]

Thanks. I took freedom to apply some optimizations - for a lot of people, this will replace ulogging module, so makes sense to be as close to it in memory usage as possible in the default config.

Also, had to convert string delims in the test myself. The saddest things is that the test doesn't run on CPython - but I understand we're currently still far away from it in terms of internal design, so ok.

Thanks for great work, it definitely was in good shape for the first submission, the key is that changes were split by commits just right. And I hope that this reviewed elaborated on code guidelines/approach of micropython-lib, so next time it will be only smoother ;-).

Pushed/released.

[pfalcon]

Btw, I should have mentioned that the presence of the test in the first place is awesome - I really should add that to contrib guidelines, because w/o tests, bigger changes like this are hard to review/maintain.

[stlehmann]

I'm happy that I could contribute to this great project. And thanks for taking the time to review / optimize my contributions. I will keep your suggestions in mind and will try to consider them in my next contributions. It is definetely a learning process ;)