Logging2 with default NullHandler
Badly need `logging2` module that has NullHandler assigned by default for all loggers. http://packages.python.org/Logbook/api/handlers.html#logbook.NullHandler Why? Because logging fails to play well with libraries: import logging log = logging.getLogger(__name__) log.warn("WARN") No handlers could be found for logger "spyderlib.utils.bsdsocket" What do I want from library logging as a Python application developer? Nothing until I explicitly setup default behaviour. logging can not be changed, and leaving everything as-is is a PITA, that's why I am proposing for logging2 as the only viable solution. -- anatoly t.
On Thu, Mar 15, 2012 at 3:24 PM, Niki Spahiev <niki.spahiev@gmail.com> wrote:
I don't know - there are questions. The function is used to get logger with NullHandler() if application did not provide configuration for root logger. So.. 1. How will logging know that application provided root logger configuration? 2. How will logging know that it should use root logger handler instead of more specific handler for __name__ module? This comes to the second part - what if logging.getLibLogger(__name__) is called after the application root handler is configured? 1. Will a new, more specific NullHandler() override the active root configuration? There is one more concern. If anything in the code base (including 3rd party modules) calls logging.log() or friends before root logger is configured by application, the root logger becomes automatically configured making everything above useless. -- anatoly t.
On 14Mar2012 21:28, anatoly techtonik <techtonik@gmail.com> wrote: | Badly need `logging2` module that has NullHandler assigned by default | for all loggers. | http://packages.python.org/Logbook/api/handlers.html#logbook.NullHandler | | Why? Because logging fails to play well with libraries: | | import logging | log = logging.getLogger(__name__) | log.warn("WARN") | | No handlers could be found for logger "spyderlib.utils.bsdsocket" | | What do I want from library logging as a Python application developer? | Nothing until I explicitly setup default behaviour. Fair point. Conversely, almost every app I write commences thus: from cs.logutils import setup_logging def main(argv): setup_logging() ... main code ... That sends to stderr with frills. Finer grained setup can come later. I _think_ I prefer logging's current behaviour: - I do want a big fat warning if I forget to configure logging at all - I don't want lobraries doing sufficient work at import time to warrant logging anything Cheers, -- Cameron Simpson <cs@zip.com.au> DoD#743 http://www.cskk.ezoshosting.com/cs/ Silicon chips with a cardboard substrate? That's not a good marriage! - overhead by WIRED at the Intelligent Printing conference Oct2006
On Fri, Mar 16, 2012 at 12:32 AM, Cameron Simpson <cs@zip.com.au> wrote:
But that makes all such libraries dependent on cs.logutils, which is not an option. In my case these libraries are self-contained PySide widgets that can be used standalone or from an IDE. Adding dependency on cs.logutils makes them too tied to application.
I _think_ I prefer logging's current behaviour:
- I do want a big fat warning if I forget to configure logging at all
Unless your application uses alternative logging means and doesn't use logging at all (unlike 3rd party libraries it uses).
- I don't want lobraries doing sufficient work at import time to warrant logging anything
I do not want libraries doing any logging setup work at import either. They should just need to contain 'extension points' for plugging log handlers in case I need to debug these modules. -- anatoly t.
On 16Mar2012 00:39, anatoly techtonik <techtonik@gmail.com> wrote: | > | What do I want from library logging as a Python application developer? | > | Nothing until I explicitly setup default behaviour. | > | > Fair point. | > | > Conversely, almost every app I write commences thus: | > from cs.logutils import setup_logging | > def main(argv): | > setup_logging() | > ... main code ... | > | > That sends to stderr with frills. Finer grained setup can come later. | | But that makes all such libraries dependent on cs.logutils, which is | not an option. No, it doesn't. setup_logging just sets up the root logger somewhat. Your apps need some kind of convenience routine like it, is all. It can be very small. All the libraries have unchanged vanilla logging calls. For example, I use SQLalchemy et al under this scheme. The libraries don't know about cs.logutils at all. | In my case these libraries are self-contained PySide | widgets that can be used standalone or from an IDE. Adding dependency | on cs.logutils makes them too tied to application. The libraries don't use my convenience module. My module just makes a whole bunch of setup I happen to like reduce to just two lines of code in my app, import and setup call. | > I _think_ I prefer logging's current behaviour: | > - I do want a big fat warning if I forget to configure logging at all | | Unless your application uses alternative logging means and doesn't use | logging at all (unlike 3rd party libraries it uses). If the 3rd party libraries use the logging module and you don't want logging happening, just configure logging to throw stuff away. | > - I don't want lobraries doing sufficient work at import time to | > warrant logging anything | | I do not want libraries doing any logging setup work at import either. | They should just need to contain 'extension points' for plugging log | handlers in case I need to debug these modules. Well, they do. Via logging. Supply an adapter handler to hook their calls to logging to your alternative logging means. Logging doesn't have to log to files/syslog/smtp etc - you can sent it anywhere. I'm sure you know that, so I think I'm missing some subtlety in your use case. Cheers, -- Cameron Simpson <cs@zip.com.au> DoD#743 http://www.cskk.ezoshosting.com/cs/ ERROR 155 - You can't do that. - Data General S200 Fortran error code list
On Fri, Mar 16, 2012 at 5:10 AM, Cameron Simpson <cs@zip.com.au> wrote:
So, your scenario is clear. You have an application where you configure logging and none of your libraries are used without this configuration. This is a doable scenario for logging module. But logging2 is needed for the opposite user story - when you have a bunch of independent libraries that are used from scripts, from application or standalone, and you need to make them silent by default. Doing this requires inserting a logging configuration into the header of every library. Things are dim, because 3rd party libraries don't come with these headers. Moreover - it is unclear if this configuration won't break the logging when you finally have to turn it on for this particular lib from an application.
The problem that I don't know and probably don't want to think about logging schemes used by those libs. When the time comes to troubleshoot these libs then sure - the logging will be the first thing I'll look into.
Yes, the argument in not about API for 'extension points' (logging does that). The argument that logging does implicit extra work, and it requires even more extra work to cancel the produced effects. More over, the effects of this default implicit work are non-deterministic - that means they depend on execution flow in you program. The effects will be different if you toss these events in random order: - root config is set by application - logging.log() or friends called - getLogger('some.dotted.name').warn() called Basically, proper logging setup also requires to care about import order of you application. It's not a problem if you have a single entry point, but becomes a PITA with multiple entrypoints or in exploratory programming (IPython?) sessions. "Don't let me think" is the greatest usability principle of all times, and logging module, unfortunately fails to comply. Backward compatibility won't let it to be fixed. And that's why a predictable logging2 module is needed. -- anatoly t.
On 16 March 2012 08:33, anatoly techtonik <techtonik@gmail.com> wrote:
Your original example was wrong:
Logging reports to stderr by default. So if I don't think, I get any output that code using logging thinks is worth drawing to my attention. Having seen that, if I want to do something about it (i.e. I think a *tiny* amount) I can set the log level to critical and suppress anything else:
log.setLevel(logging.CRITICAL) log.warn("WARN")
And if I prefer something more complex, I can do that. But by then, I've reached the point where expecting me not to read the documentation and think a little is unreasonable. The examples above are in 2.7, btw. They also work in 3.2 and 3.3a0. Paul.
On Fri, Mar 16, 2012 at 11:53 AM, Paul Moore <p.f.moore@gmail.com> wrote:
The example is actually right, and the preceding string explains that example code should be run from the library.
Restart the interpreter to clear the state and execute only the last part:
Now without restarting execute the following:
log = logging.getLogger('spyderlib.utils.bsdsocket') log.warn("WARN")
Does the original example look correct now? I guess, Paul, that you've overlooked the reference to library, so I skipped the rest of the quote, because you should agree that library should not set logging level for itself as it will cancel logging config may have already occurred at application level. -- anatoly t.
On 16 March 2012 09:19, anatoly techtonik <techtonik@gmail.com> wrote:
PS D:\Data> py -3.2 Python 3.2.2 (default, Sep 4 2011, 09:51:08) [MSC v.1500 32 bit (Intel)] on win32 Type "help", "copyright", "credits" or "license" for more information.
Does the original example look correct now?
No.
I have no library spyderlib.utils.bsdsocket. If you are saying that library has a bug, then I can't comment (other than to say that blaming the logging module for that is something of an over-reaction, to be polite). Paul.
On Thu, Mar 15, 2012 at 5:28 AM, anatoly techtonik <techtonik@gmail.com> wrote:
Logging *can* be changed, and indeed *was* changed for 3.2 (to behave as Paul describes elsewhere in the thread). Anatoly, when you have complaints like this, *please* check that the behaviour you dislike can be reproduced on the latest version of Python. Regards, Nick. -- Nick Coghlan | ncoghlan@gmail.com | Brisbane, Australia
On Fri, Mar 16, 2012 at 2:39 PM, Nick Coghlan <ncoghlan@gmail.com> wrote:
Even though Paul described 2.7 version too, it is good to know that at least this inconsistency was fixed in 3.x. Sorry for not being clear about Python 2.x from the start. Seeing that Paul resorted to protect only `py` 3.2 in the last comment I may assume that we are all agree that using logging from libraries with scenarios I've described in Python 2.x is a PITA and all my arguments are valid against this version.
It is hard to propose something for the thing I don't use daily. I couldn't reproduce this stuff, because getting to the root of the problem required a lot of effort alone. If there was a list for known misbehaviours like this in Python 2.x the things could be much easier. I guess the question can be closed, but I am still dissatisfied with the current state of things. If Python 3.x is developed using the same process, there is a risk of UX problems like this too. -- anatoly t.
On 16 March 2012 16:03, anatoly techtonik <techtonik@gmail.com> wrote:
Nope, I checked 2.7 too. I just didn't paste both cases. You should at a minimum, state the version you are using when you make these comments. And anyway, Python 2.x behaviour isn't really an appropriate topic for python-ideas, as there won't be a new 2.x version. Paul.
On Sat, Mar 17, 2012 at 1:03 AM, anatoly techtonik <techtonik@gmail.com> wrote:
problem required a lot of effort alone. If there was a list for known misbehaviours like this in Python 2.x the things could be much easier.
If you don't find it on the tracker (including closed issues), for the purpose of actually getting it changed, it's unknown.
I guess the question can be closed, but I am still dissatisfied with the current state of things.
So fix it. If you didn't find an open issue on the tracker, that means either few people (== 0) care enough to post an issue at all, or, as far as those who care are concerned, it's already fixed in the relevant branch(es) and the issue has been closed. Either way, you're going to have to do it yourself.
If Python 3.x is developed using the same process, there is a risk of UX problems like this too.
There's always a risk of problems. Do you have a specific proposal for improving process?
On Sun, Mar 18, 2012 at 10:54 AM, Stephen J. Turnbull <stephen@xemacs.org> wrote:
The problem that it is almost impossible to find anything on tracker related to specific component like logging. The issue description doesn't always correspond to the actual content and it is really hard to get through all the comments. Proposal - add modules field, allow comment rating, issue and commend edits (Trac). Why won't I do anything? Because my time is limited to 15 minutes slots and getting developer instance takes more time, so I never pass through this barrier (and TAL is not my language).
The first step is to gather a critical mass of people who acknowledge the problem, who have their own ideas summarized and can share them at the right moment. So, the specific proposal is to have a history that can be analyzed by anyone. Right now it is extremely hard to summarize problems - no custom tags on tracker, no way to organize email threads - these are just two technical proposals to improve the process. One more idea is the use case DB to collect API uses cases and detect conflicts at early stage to draw attention to them. Every problem and use case should have a number, should be clearly defined (much better than tracker issue summaries) and should have a rating/star system. That should be enough for now. -- anatoly t.
On Mon, Mar 19, 2012 at 3:09 AM, anatoly techtonik <techtonik@gmail.com> wrote:
Of course it would. But ... You remind me of Dave Hayes, who suggested that spam wasn't a problem. You just need sufficiently smart MUAs that never allow spam through, and after a while the spammers will stop trying. The problem here is that like you, people generally only get time in 15 minute increments, and very few are able to clearly define things ("much better than tracker issue summaries") without more time than that. OTOH, we don't have an automatic way to do it. So your proposal AFAICS is DOA. But I'm willing to put a little time into self-education. The only Trac system I use regularly is MacPorts, and it frankly sucks by the standards you put forward. Specifically, although I always search the system for applicable existing bugs, I miss about 2/3 of them (possibly more; only about 1 in 5 bugs show up in my search, but about half of my reports end up getting closed as dupes of existing bugs by the maintainers, and I wouldn't be surprised if some fraction of relevant bugs are unknown to the maintainers, too.) Getting to the current, mostly usable, level of suckitude took about five years. Since that's only one example, you can help me out by pointing me to an example of a well-managed, highly useful, tracker that has the features you propose!
On Thu, Mar 15, 2012 at 3:24 PM, Niki Spahiev <niki.spahiev@gmail.com> wrote:
I don't know - there are questions. The function is used to get logger with NullHandler() if application did not provide configuration for root logger. So.. 1. How will logging know that application provided root logger configuration? 2. How will logging know that it should use root logger handler instead of more specific handler for __name__ module? This comes to the second part - what if logging.getLibLogger(__name__) is called after the application root handler is configured? 1. Will a new, more specific NullHandler() override the active root configuration? There is one more concern. If anything in the code base (including 3rd party modules) calls logging.log() or friends before root logger is configured by application, the root logger becomes automatically configured making everything above useless. -- anatoly t.
On 14Mar2012 21:28, anatoly techtonik <techtonik@gmail.com> wrote: | Badly need `logging2` module that has NullHandler assigned by default | for all loggers. | http://packages.python.org/Logbook/api/handlers.html#logbook.NullHandler | | Why? Because logging fails to play well with libraries: | | import logging | log = logging.getLogger(__name__) | log.warn("WARN") | | No handlers could be found for logger "spyderlib.utils.bsdsocket" | | What do I want from library logging as a Python application developer? | Nothing until I explicitly setup default behaviour. Fair point. Conversely, almost every app I write commences thus: from cs.logutils import setup_logging def main(argv): setup_logging() ... main code ... That sends to stderr with frills. Finer grained setup can come later. I _think_ I prefer logging's current behaviour: - I do want a big fat warning if I forget to configure logging at all - I don't want lobraries doing sufficient work at import time to warrant logging anything Cheers, -- Cameron Simpson <cs@zip.com.au> DoD#743 http://www.cskk.ezoshosting.com/cs/ Silicon chips with a cardboard substrate? That's not a good marriage! - overhead by WIRED at the Intelligent Printing conference Oct2006
On Fri, Mar 16, 2012 at 12:32 AM, Cameron Simpson <cs@zip.com.au> wrote:
But that makes all such libraries dependent on cs.logutils, which is not an option. In my case these libraries are self-contained PySide widgets that can be used standalone or from an IDE. Adding dependency on cs.logutils makes them too tied to application.
I _think_ I prefer logging's current behaviour:
- I do want a big fat warning if I forget to configure logging at all
Unless your application uses alternative logging means and doesn't use logging at all (unlike 3rd party libraries it uses).
- I don't want lobraries doing sufficient work at import time to warrant logging anything
I do not want libraries doing any logging setup work at import either. They should just need to contain 'extension points' for plugging log handlers in case I need to debug these modules. -- anatoly t.
On 16Mar2012 00:39, anatoly techtonik <techtonik@gmail.com> wrote: | > | What do I want from library logging as a Python application developer? | > | Nothing until I explicitly setup default behaviour. | > | > Fair point. | > | > Conversely, almost every app I write commences thus: | > from cs.logutils import setup_logging | > def main(argv): | > setup_logging() | > ... main code ... | > | > That sends to stderr with frills. Finer grained setup can come later. | | But that makes all such libraries dependent on cs.logutils, which is | not an option. No, it doesn't. setup_logging just sets up the root logger somewhat. Your apps need some kind of convenience routine like it, is all. It can be very small. All the libraries have unchanged vanilla logging calls. For example, I use SQLalchemy et al under this scheme. The libraries don't know about cs.logutils at all. | In my case these libraries are self-contained PySide | widgets that can be used standalone or from an IDE. Adding dependency | on cs.logutils makes them too tied to application. The libraries don't use my convenience module. My module just makes a whole bunch of setup I happen to like reduce to just two lines of code in my app, import and setup call. | > I _think_ I prefer logging's current behaviour: | > - I do want a big fat warning if I forget to configure logging at all | | Unless your application uses alternative logging means and doesn't use | logging at all (unlike 3rd party libraries it uses). If the 3rd party libraries use the logging module and you don't want logging happening, just configure logging to throw stuff away. | > - I don't want lobraries doing sufficient work at import time to | > warrant logging anything | | I do not want libraries doing any logging setup work at import either. | They should just need to contain 'extension points' for plugging log | handlers in case I need to debug these modules. Well, they do. Via logging. Supply an adapter handler to hook their calls to logging to your alternative logging means. Logging doesn't have to log to files/syslog/smtp etc - you can sent it anywhere. I'm sure you know that, so I think I'm missing some subtlety in your use case. Cheers, -- Cameron Simpson <cs@zip.com.au> DoD#743 http://www.cskk.ezoshosting.com/cs/ ERROR 155 - You can't do that. - Data General S200 Fortran error code list
On Fri, Mar 16, 2012 at 5:10 AM, Cameron Simpson <cs@zip.com.au> wrote:
So, your scenario is clear. You have an application where you configure logging and none of your libraries are used without this configuration. This is a doable scenario for logging module. But logging2 is needed for the opposite user story - when you have a bunch of independent libraries that are used from scripts, from application or standalone, and you need to make them silent by default. Doing this requires inserting a logging configuration into the header of every library. Things are dim, because 3rd party libraries don't come with these headers. Moreover - it is unclear if this configuration won't break the logging when you finally have to turn it on for this particular lib from an application.
The problem that I don't know and probably don't want to think about logging schemes used by those libs. When the time comes to troubleshoot these libs then sure - the logging will be the first thing I'll look into.
Yes, the argument in not about API for 'extension points' (logging does that). The argument that logging does implicit extra work, and it requires even more extra work to cancel the produced effects. More over, the effects of this default implicit work are non-deterministic - that means they depend on execution flow in you program. The effects will be different if you toss these events in random order: - root config is set by application - logging.log() or friends called - getLogger('some.dotted.name').warn() called Basically, proper logging setup also requires to care about import order of you application. It's not a problem if you have a single entry point, but becomes a PITA with multiple entrypoints or in exploratory programming (IPython?) sessions. "Don't let me think" is the greatest usability principle of all times, and logging module, unfortunately fails to comply. Backward compatibility won't let it to be fixed. And that's why a predictable logging2 module is needed. -- anatoly t.
On 16 March 2012 08:33, anatoly techtonik <techtonik@gmail.com> wrote:
Your original example was wrong:
Logging reports to stderr by default. So if I don't think, I get any output that code using logging thinks is worth drawing to my attention. Having seen that, if I want to do something about it (i.e. I think a *tiny* amount) I can set the log level to critical and suppress anything else:
log.setLevel(logging.CRITICAL) log.warn("WARN")
And if I prefer something more complex, I can do that. But by then, I've reached the point where expecting me not to read the documentation and think a little is unreasonable. The examples above are in 2.7, btw. They also work in 3.2 and 3.3a0. Paul.
On Fri, Mar 16, 2012 at 11:53 AM, Paul Moore <p.f.moore@gmail.com> wrote:
The example is actually right, and the preceding string explains that example code should be run from the library.
Restart the interpreter to clear the state and execute only the last part:
Now without restarting execute the following:
log = logging.getLogger('spyderlib.utils.bsdsocket') log.warn("WARN")
Does the original example look correct now? I guess, Paul, that you've overlooked the reference to library, so I skipped the rest of the quote, because you should agree that library should not set logging level for itself as it will cancel logging config may have already occurred at application level. -- anatoly t.
On 16 March 2012 09:19, anatoly techtonik <techtonik@gmail.com> wrote:
PS D:\Data> py -3.2 Python 3.2.2 (default, Sep 4 2011, 09:51:08) [MSC v.1500 32 bit (Intel)] on win32 Type "help", "copyright", "credits" or "license" for more information.
Does the original example look correct now?
No.
I have no library spyderlib.utils.bsdsocket. If you are saying that library has a bug, then I can't comment (other than to say that blaming the logging module for that is something of an over-reaction, to be polite). Paul.
On Thu, Mar 15, 2012 at 5:28 AM, anatoly techtonik <techtonik@gmail.com> wrote:
Logging *can* be changed, and indeed *was* changed for 3.2 (to behave as Paul describes elsewhere in the thread). Anatoly, when you have complaints like this, *please* check that the behaviour you dislike can be reproduced on the latest version of Python. Regards, Nick. -- Nick Coghlan | ncoghlan@gmail.com | Brisbane, Australia
On Fri, Mar 16, 2012 at 2:39 PM, Nick Coghlan <ncoghlan@gmail.com> wrote:
Even though Paul described 2.7 version too, it is good to know that at least this inconsistency was fixed in 3.x. Sorry for not being clear about Python 2.x from the start. Seeing that Paul resorted to protect only `py` 3.2 in the last comment I may assume that we are all agree that using logging from libraries with scenarios I've described in Python 2.x is a PITA and all my arguments are valid against this version.
It is hard to propose something for the thing I don't use daily. I couldn't reproduce this stuff, because getting to the root of the problem required a lot of effort alone. If there was a list for known misbehaviours like this in Python 2.x the things could be much easier. I guess the question can be closed, but I am still dissatisfied with the current state of things. If Python 3.x is developed using the same process, there is a risk of UX problems like this too. -- anatoly t.
On 16 March 2012 16:03, anatoly techtonik <techtonik@gmail.com> wrote:
Nope, I checked 2.7 too. I just didn't paste both cases. You should at a minimum, state the version you are using when you make these comments. And anyway, Python 2.x behaviour isn't really an appropriate topic for python-ideas, as there won't be a new 2.x version. Paul.
On Sat, Mar 17, 2012 at 1:03 AM, anatoly techtonik <techtonik@gmail.com> wrote:
problem required a lot of effort alone. If there was a list for known misbehaviours like this in Python 2.x the things could be much easier.
If you don't find it on the tracker (including closed issues), for the purpose of actually getting it changed, it's unknown.
I guess the question can be closed, but I am still dissatisfied with the current state of things.
So fix it. If you didn't find an open issue on the tracker, that means either few people (== 0) care enough to post an issue at all, or, as far as those who care are concerned, it's already fixed in the relevant branch(es) and the issue has been closed. Either way, you're going to have to do it yourself.
If Python 3.x is developed using the same process, there is a risk of UX problems like this too.
There's always a risk of problems. Do you have a specific proposal for improving process?
On Sun, Mar 18, 2012 at 10:54 AM, Stephen J. Turnbull <stephen@xemacs.org> wrote:
The problem that it is almost impossible to find anything on tracker related to specific component like logging. The issue description doesn't always correspond to the actual content and it is really hard to get through all the comments. Proposal - add modules field, allow comment rating, issue and commend edits (Trac). Why won't I do anything? Because my time is limited to 15 minutes slots and getting developer instance takes more time, so I never pass through this barrier (and TAL is not my language).
The first step is to gather a critical mass of people who acknowledge the problem, who have their own ideas summarized and can share them at the right moment. So, the specific proposal is to have a history that can be analyzed by anyone. Right now it is extremely hard to summarize problems - no custom tags on tracker, no way to organize email threads - these are just two technical proposals to improve the process. One more idea is the use case DB to collect API uses cases and detect conflicts at early stage to draw attention to them. Every problem and use case should have a number, should be clearly defined (much better than tracker issue summaries) and should have a rating/star system. That should be enough for now. -- anatoly t.
On Mon, Mar 19, 2012 at 3:09 AM, anatoly techtonik <techtonik@gmail.com> wrote:
Of course it would. But ... You remind me of Dave Hayes, who suggested that spam wasn't a problem. You just need sufficiently smart MUAs that never allow spam through, and after a while the spammers will stop trying. The problem here is that like you, people generally only get time in 15 minute increments, and very few are able to clearly define things ("much better than tracker issue summaries") without more time than that. OTOH, we don't have an automatic way to do it. So your proposal AFAICS is DOA. But I'm willing to put a little time into self-education. The only Trac system I use regularly is MacPorts, and it frankly sucks by the standards you put forward. Specifically, although I always search the system for applicable existing bugs, I miss about 2/3 of them (possibly more; only about 1 in 5 bugs show up in my search, but about half of my reports end up getting closed as dupes of existing bugs by the maintainers, and I wouldn't be surprised if some fraction of relevant bugs are unknown to the maintainers, too.) Getting to the current, mostly usable, level of suckitude took about five years. Since that's only one example, you can help me out by pointing me to an example of a well-managed, highly useful, tracker that has the features you propose!
participants (6)
-
anatoly techtonik -
Cameron Simpson -
Nick Coghlan -
Niki Spahiev -
Paul Moore -
Stephen J. Turnbull