Re: [Zope-dev] Logging of ConflictError
Dennis Allison wrote: Dieter's point about not includeing the traceback makes sense if all it does is report on the reporting code. Yeah, the traceback just shows where the ConflictError was raised, not what caused it, and theyr'e always in very different places... Wlorent, do you envision a single ConflicError or two -- one which succeeds on retry and another where the retry fails? Huh? ConflictErrors are ConflictErrors, it's a "server" level decision as to how they're handled. Zope chooses to retry the whole request up to 3 times when a ConflictError occurs. The new logging code I put in records exactly how many conflicts have occurrred, and how many remain unresolved even after 3 retries. I know you've been having fun with this type of error, so you might well want to grav the changes from svn and give them a spin... cheers, Chris -- Simplistix - Content Management, Zope & Python Consulting - http://www.simplistix.co.uk ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
Florent Guillaume wrote: If you look at the way their purpose is explained in zLOG, you'll see that level INFO is reserved for things like server startup and shutdown. You must be one of the few humans who's ever read that documentation ;-) recurring that can happen many times in the life of the server but does not pose any problems should *not* be visible at INFO. What part of "if enough conflicts are showing up in the logs that they're a hassle, then you have a problem" are you not understanding? ;-) On the other hand, that's exactly what BLATHER is for folks! Use it! Everyone and their dog gets logged at BLATHER. It's not reasonable to obscure everything in the logs by having to turn on BLATHER logging just to get critical information about the performance of your app server. Note that it's another reason for not using the default python loggers who have a stupidly small number of levels. They have as many levels as you want to set up. The python logging package is _extremely_ well thought out. You do know that zLOG is just a wrapper around the python loggers now, right? If you want to audit your server status to see if there are changes real errors will happen, INFO is *not* the level to use. urm? Chris -- Simplistix - Content Management, Zope & Python Consulting - http://www.simplistix.co.uk ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
Dieter's point about not includeing the traceback makes sense if all it does is report on the reporting code. Wlorent, do you envision a single ConflicError or two -- one which succeeds on retry and another where the retry fails? On Sun, 4 Dec 2005, Dieter Maurer wrote: > Florent Guillaume wrote at 2005-12-2 22:59 +0100: > > ... > >If you look at the way their purpose is explained in zLOG, you'll see > >that level INFO is reserved for things like server startup and > >shutdown. > >Or, as shown above, initial mounting of databases. Anything > >recurring that can happen many times in the life of the server but > >does not pose any problems should *not* be visible at INFO. > > Really? > > You infer that from the > > "INFO For things like startup and shutdown", do you? > > That's very weak reasoning... > > The level obviously has an importance association: > higher values indicate higher importance. > > > If fact, the "ConflictError" messages should not be reported > at "INFO" but at level "PROBLEM" because > >they are not causing any immediate problems, but >deserve attention. > > >On the other hand, that's exactly what BLATHER is for folks! Use it! > > You see it this way. I do not: > > "ConflictError"s are definitely as important as mount > messages and therefore should be reported on at least > the level of mount reports: i.e. at INFO or above. > > -- ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
Florent Guillaume wrote at 2005-12-2 22:59 +0100: > ... >If you look at the way their purpose is explained in zLOG, you'll see >that level INFO is reserved for things like server startup and >shutdown. >Or, as shown above, initial mounting of databases. Anything >recurring that can happen many times in the life of the server but >does not pose any problems should *not* be visible at INFO. Really? You infer that from the "INFO For things like startup and shutdown", do you? That's very weak reasoning... The level obviously has an importance association: higher values indicate higher importance. If fact, the "ConflictError" messages should not be reported at "INFO" but at level "PROBLEM" because they are not causing any immediate problems, but deserve attention. >On the other hand, that's exactly what BLATHER is for folks! Use it! You see it this way. I do not: "ConflictError"s are definitely as important as mount messages and therefore should be reported on at least the level of mount reports: i.e. at INFO or above. -- Dieter ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
Paul Winkler wrote: I'm +1 on having failed retries show up at level ERROR. With Florent's changes you get 'em twice, with mine, you get 'em once ;-) I'm neutral on having successful retries show up at level INFO, BLATHER, or in some other log handler entirely. Conflict errors are a pretty small part of my world and I don't really have a strong opinion on this part of the debate, and I don't have time to review either of your patches. Well, if you ever run into performance problems, you might care about them... Chris -- Simplistix - Content Management, Zope & Python Consulting - http://www.simplistix.co.uk ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
On 2 Dec 2005, at 20:50, Dieter Maurer wrote: Florent Guillaume wrote at 2005-12-2 13:33 +0100: ... Please no. Don't put anything at INFO. A conflict error is either something normal that should be at level BLATHER or below, or an ERROR that a sysadmin wants to see logged as such. I strongly disagree with you: "ConflictError"s are essential hints that your system might come into trouble (they can turn into real error). These hints are at least as important as e.g. 2005-12-02T07:17:59 INFO ZODB.Mount Opening database for mounting: '144160968_1010482273.050062' -- 2005-12-02T07:17:59 INFO ZODB.Mount Mounted database '144160968_1010482273.050062' at /temp_folder Looks like "INFO" is a better level than "BLATHER"... If you look at the way their purpose is explained in zLOG, you'll see that level INFO is reserved for things like server startup and shutdown. Or, as shown above, initial mounting of databases. Anything recurring that can happen many times in the life of the server but does not pose any problems should *not* be visible at INFO. On the other hand, that's exactly what BLATHER is for folks! Use it! Note that it's another reason for not using the default python loggers who have a stupidly small number of levels. If you want to audit your server status to see if there are changes real errors will happen, INFO is *not* the level to use. Anyway, there's sufficient disagreement here, I'll send another mail to ask for people's votes. Florent -- Florent Guillaume, Nuxeo (Paris, France) Director of R&D +33 1 40 33 71 59 http://nuxeo.com [EMAIL PROTECTED] ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
On 2 Dec 2005, at 20:40, Dieter Maurer wrote: Florent Guillaume wrote at 2005-12-1 19:49 +0100: I've improved the logging of ConflictError in Zope 2.9 and trunk. http://svn.zope.org/?rev=40454&view=rev Now you'll get two things: - logs at level BLATHER for each conflict, but it may be retried - log at level ERROR when the conflict can't be retried anymore and is returned to the browser as an error. Apparently, you stopped following our thread (you, Chris, me): In my view, a "ConflictError" observed by the user should be treated exactly like any other exception observed by the user: it should go through the "error_log" and "standard_error_message". That's what my patch did. It might be logged (when the user decides that exceptions seen by the user should be logged). I can agree with that. The approach to achieve this it to fix a bug in Zope's "zpublisher_exception_hook", not to add an explicit log when the final retry fails (though the extra log entry will not hurt significantly). The patch I did included the fix you proposed in the patch in the mailing list archives based on the collector entry. Florent -- Florent Guillaume, Nuxeo (Paris, France) Director of R&D +33 1 40 33 71 59 http://nuxeo.com [EMAIL PROTECTED] ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
Florent Guillaume wrote at 2005-12-2 13:33 +0100: > ... >Please no. Don't put anything at INFO. A conflict error is either >something normal that should be at level BLATHER or below, or an >ERROR that a sysadmin wants to see logged as such. I strongly disagree with you: "ConflictError"s are essential hints that your system might come into trouble (they can turn into real error). These hints are at least as important as e.g. 2005-12-02T07:17:59 INFO ZODB.Mount Opening database for mounting: '144160968_1010482273.050062' -- 2005-12-02T07:17:59 INFO ZODB.Mount Mounted database '144160968_1010482273.050062' at /temp_folder Looks like "INFO" is a better level than "BLATHER"... -- Dieter ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
Florent Guillaume wrote at 2005-12-1 19:49 +0100: >I've improved the logging of ConflictError in Zope 2.9 and trunk. > >http://svn.zope.org/?rev=40454&view=rev > >Now you'll get two things: >- logs at level BLATHER for each conflict, but it may be retried >- log at level ERROR when the conflict can't be retried anymore and is >returned to the browser as an error. Apparently, you stopped following our thread (you, Chris, me): In my view, a "ConflictError" observed by the user should be treated exactly like any other exception observed by the user: it should go through the "error_log" and "standard_error_message". It might be logged (when the user decides that exceptions seen by the user should be logged). The approach to achieve this it to fix a bug in Zope's "zpublisher_exception_hook", not to add an explicit log when the final retry fails (though the extra log entry will not hurt significantly). -- Dieter ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
On Fri, Dec 02, 2005 at 02:09:56PM +0100, Florent Guillaume wrote: > On 2 Dec 2005, at 11:09, Chris Withers wrote: > >I was planning on rolling my changes out to 2.8, 2.9 and the trunk. > >Unless anyone strenuously objects, I still intend to do that. I > >cleaned up a lot of the code and made a few other changes that > >generally improve logging. > > I strenuously object to you overwriting without consultation code I > just checked in and that was approved by at least 3 people. I'm +1 on having failed retries show up at level ERROR. I'm neutral on having successful retries show up at level INFO, BLATHER, or in some other log handler entirely. Conflict errors are a pretty small part of my world and I don't really have a strong opinion on this part of the debate, and I don't have time to review either of your patches. -- Paul Winkler http://www.slinkp.com ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
On 2 Dec 2005, at 14:16, Chris Withers wrote: Please no. Don't put anything at INFO. A conflict error is either something normal that should be at level BLATHER or below, or an ERROR that a sysadmin wants to see logged as such. Not so. If I'm getting 1,000 resolved conflict errors a day, that can be a big performance hit, and there are those of us who have hard performance targets to meet ;-) Turning on debug logging is, in itself, a performance hit, so I don't want to have to do that on a production service where I want to observe the number of conflict errors occurring over a long period of time, like, say, a month. I agree with this argumentation. It is true that conflicts are a normal part of operation, as we all like to tell people who are scared/confused by them, but if you see so many that it bothers you seeing it at INFO level you know you have a problem that needs fixing. Same is true for the panicking sysadmins that call up the developers. If they call because of that they should have gotten better training before starting to admin Zope setups, or they shouldn't be doing it at all. jens ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
Florent Guillaume wrote: Please no. Don't put anything at INFO. A conflict error is either something normal that should be at level BLATHER or below, or an ERROR that a sysadmin wants to see logged as such. INFO sucks for recurring stuff like that that in addition contain the word "error" which it isn't. I can't count the number of sysadmin/customers/ hosting providers that freak out when something like that appears in the log and call us and we have to explain that yes, it's not logical but... It just occurred to me, if you have these kind of problems, tell them to change their log level in Zope.conf to 'warn' and then they won't see anything unless they really have to deal with it... Chris -- Simplistix - Content Management, Zope & Python Consulting - http://www.simplistix.co.uk ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
Florent Guillaume wrote: Please no. Don't put anything at INFO. A conflict error is either something normal that should be at level BLATHER or below, or an ERROR that a sysadmin wants to see logged as such. Incidentally, your changes result in most users seeing two errors in their logs when they should just see one. I'm not aware of many serious users who don't copy the output of the error_log object to the event log, so with your changes, you'll end up with the error that ends up in the error_log, and your seperate LOG call's message. cheers, Chris -- Simplistix - Content Management, Zope & Python Consulting - http://www.simplistix.co.uk ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
Florent Guillaume wrote: It doesn't really matter, zLOG has a compatibility layer that ends up doing the same thing. python's logging module has a cleaner, nicer syntax. Please no. Don't put anything at INFO. A conflict error is either something normal that should be at level BLATHER or below, or an ERROR that a sysadmin wants to see logged as such. Not so. If I'm getting 1,000 resolved conflict errors a day, that can be a big performance hit, and there are those of us who have hard performance targets to meet ;-) Turning on debug logging is, in itself, a performance hit, so I don't want to have to do that on a production service where I want to observe the number of conflict errors occurring over a long period of time, like, say, a month. INFO sucks for recurring stuff like that that in addition contain the word "error" which it isn't. Well, that's a problem with the exception naming, and I agree with you, but I don't know how hard that is to change. I can't count the number of sysadmin/customers/ hosting providers that freak out when something like that appears in the log and call us and we have to explain that yes, it's not logical but... Stupid sysadmins can't be helped. It's being logged at INFO, not ERROR or WARNING. I agree, the exception should be renamed to just Conflict, but that's a totally different discussion. Well, I told you on the list that I was already working on this. You didn't pay attention I guess. You made a vague comment on the 21st Nov. I made a definite commitment on the 24th Nov. On the 25th, you said you were working on it in response to my question. Now, by yesterday, 6 days later, nothing had happened, so I fixed this and did some other work with stupid error messages along the way. Then, suddenly, yesterday you commit. *sigh* Anyway, I'm going to check in the changes because they're materially the same but the code is cleaner. Whether resolved conflict errors are logged at INFO or DEBUG is a seperate discussion and one which I'd like to see a lot more comments on than have been seen so far. The +1s from people yesterday were about the general merging of the fix to 2.8, which I would also +1 to ;-) However, changing from INFO to DEBUG is a change in functionality which _I_ strenuously object to. People _need_ to be aware that they are seeing conflict errors, even if they are resolved. I, for one, really really want to be able to look in the event log and see if _any_ conflict errors are occurring, resolved or not, and keep track of the number of them so I can spot any performance hotspots before they become critical. FWIW, the stuff I log at INFO makes it clearer as to which conflicts are resolved or not, so your sysadmin types should be happier. What do people other than Florent, whose view I think we know, feel about this? cheers, Chris -- Simplistix - Content Management, Zope & Python Consulting - http://www.simplistix.co.uk ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
On 2 Dec 2005, at 11:09, Chris Withers wrote: I was planning on rolling my changes out to 2.8, 2.9 and the trunk. Unless anyone strenuously objects, I still intend to do that. I cleaned up a lot of the code and made a few other changes that generally improve logging. I strenuously object to you overwriting without consultation code I just checked in and that was approved by at least 3 people. And I'm totally -1 on any logging at level INFO or above about retriable conflict errors. Florent -- Florent Guillaume, Nuxeo (Paris, France) Director of R&D +33 1 40 33 71 59 http://nuxeo.com [EMAIL PROTECTED] ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
On 2 Dec 2005, at 11:09, Chris Withers wrote: Damn, I was working on this at the same time :-S Florent Guillaume wrote: I've improved the logging of ConflictError in Zope 2.9 and trunk. http://svn.zope.org/?rev=40454&view=rev Now you'll get two things: - logs at level BLATHER for each conflict, but it may be retried - log at level ERROR when the conflict can't be retried anymore and is returned to the browser as an error. In my work, I've actually changed this to use the new, proper logging calls. I'll be comitting later this morning. It doesn't really matter, zLOG has a compatibility layer that ends up doing the same thing. I removed the log at level INFO because it is very misleading for system administrators in my experience. I don't think so, I've actually changed and enhanced this in my work. You now get a log at INFO whenever a conflict occurs. It includes more information than the old version, as you'll see... Please no. Don't put anything at INFO. A conflict error is either something normal that should be at level BLATHER or below, or an ERROR that a sysadmin wants to see logged as such. INFO sucks for recurring stuff like that that in addition contain the word "error" which it isn't. I can't count the number of sysadmin/customers/ hosting providers that freak out when something like that appears in the log and call us and we have to explain that yes, it's not logical but... Do people want this also for 2.8? Note that it changes the log format, so may break third party tools that parse logs. I was planning on rolling my changes out to 2.8, 2.9 and the trunk. Unless anyone strenuously objects, I still intend to do that. I cleaned up a lot of the code and made a few other changes that generally improve logging. It's a shame Florent and I were genuinely working on this at the same time without the other knowing... Well, I told you on the list that I was already working on this. You didn't pay attention I guess. Florent -- Florent Guillaume, Nuxeo (Paris, France) Director of R&D +33 1 40 33 71 59 http://nuxeo.com [EMAIL PROTECTED] ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
Hi Florent, Damn, I was working on this at the same time :-S Florent Guillaume wrote: I've improved the logging of ConflictError in Zope 2.9 and trunk. http://svn.zope.org/?rev=40454&view=rev Now you'll get two things: - logs at level BLATHER for each conflict, but it may be retried - log at level ERROR when the conflict can't be retried anymore and is returned to the browser as an error. In my work, I've actually changed this to use the new, proper logging calls. I'll be comitting later this morning. I removed the log at level INFO because it is very misleading for system administrators in my experience. I don't think so, I've actually changed and enhanced this in my work. You now get a log at INFO whenever a conflict occurs. It includes more information than the old version, as you'll see... Do people want this also for 2.8? Note that it changes the log format, so may break third party tools that parse logs. I was planning on rolling my changes out to 2.8, 2.9 and the trunk. Unless anyone strenuously objects, I still intend to do that. I cleaned up a lot of the code and made a few other changes that generally improve logging. It's a shame Florent and I were genuinely working on this at the same time without the other knowing... cheers, Chris -- Simplistix - Content Management, Zope & Python Consulting - http://www.simplistix.co.uk ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Re: [Zope-dev] Logging of ConflictError
+1 On Dec 1, 2005, at 1:49 PM, Florent Guillaume wrote: I've improved the logging of ConflictError in Zope 2.9 and trunk. http://svn.zope.org/?rev=40454&view=rev Now you'll get two things: - logs at level BLATHER for each conflict, but it may be retried - log at level ERROR when the conflict can't be retried anymore and is returned to the browser as an error. I removed the log at level INFO because it is very misleading for system administrators in my experience. Do people want this also for 2.8? Note that it changes the log format, so may break third party tools that parse logs. Florent -- Florent Guillaume, Nuxeo (Paris, France) CTO, Director of R&D +33 1 40 33 71 59 http://nuxeo.com [EMAIL PROTECTED] ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope ) ___ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )