From: "Adrian Crum" <adrian.c...@sandglass-software.com> > From my perspective, you are the one complicating things. If you don't > want to slow down the system with logging I/O, then turn logging off.
When you are continously developping a system, removing all log info/timing from production can be problematic. It's sometimes the only way you have to understand why and how a random issue appears. > "We've always done it that way" is not a valid argument. I was just saying that personally I did not have problems whith how it was before your change. I was easy to adapt to my need. I have also no problems with your change, it's sill easy to adapt. > You still haven't given us any requirements that demonstrate the need to > put complicated decision making around a single log entry. My solution is not complicated at all 2 properties for 2 thresholds. Why do you feel it as complicated? Actually I'm not stuck with this solution. If you want, comment it out or even revert and the chapter is closed. Jacques > -Adrian > > On 4/7/2013 9:18 AM, Jacques Le Roux wrote: >> This seems over complicated to me. Don't arbitrarily slow OFBiz by storing >> (IOs) services durations at each service call. Let's keep it simple and easy >> tunable. >> >> The way it was before ( >50 => slow; > 200 => very slow) was there for >> years. I did not code it, and after a decade we want to change it, OK. >> >> Most of the time you don't care about that. When you do, you simply want to >> separate slow services from others. >> >> I believe OOTB 2 properties are enough. I set them to allow to see all >> services durations and to specifically mark slow services. I picked 1 sec, >> why? It would be terribly slow services internally, but externals ones can >> vary much more. >> If you need more thresholds/separations it's easy from what is coded now to >> add suiting your needs. >> >> From my experience, when looking at logs on a system you quickly know which >> are these values, when you are interested by them >> >> The most important point here is not slow the system and to follow >> KISS/YAGNI ways. >> >> Please don't complicate things, thanks! >> >> Jacques >> >> >> From: "Atul Vani" <atul.v...@hotwaxmedia.com> >>> Here's what I think, it's all raw though :) >>> * As suggested by Jacopo, we maintain stats in some kind of entity. Let's >>> say average running time. >>> * We use this average running time to decide if a timing log should be >>> printed. The thing is, not all services are same, some are complex and are >>> supposed to take longer than others, so a static number would never >>> suffice. We do not have any means to calculate the complexity of a service >>> (by looking at the mini-lang code) to decide this number, so either a user >>> will tell it or we can compute it on the basis of past run times. >>> * There can come cases when user would want to tell the number (all past >>> experiences were bad ones, or he just optimized), so we can add some >>> attribute to the service definition. There is something like metric >>> already present, not sure how that works. >>> * A single number for all services does not make sense to me, because (as >>> mentioned above) not all services are same. >>> >>> On Sun, 07 Apr 2013 04:14:58 +0530, Adrian Crum >>> <adrian.c...@sandglass-software.com> wrote: >>> >>>> No, a commit is NOT a reply to an email. >>>> >>>> Please, let's discuss this. You seem to be forcing your perception of >>>> how logging should be done on the rest of the community. I would prefer >>>> that we all participate in a discussion and come up with a design that >>>> works for everyone. >>>> >>>> -Adrian >>>> >>>> On 4/6/2013 5:32 PM, Jacques Le Roux wrote: >>>>> I thought the commit comment answered your question >>>>> >>>>> OOTB, there is only 1 change from what you committed: now services >>>>> longer than 1 sec will also show as slow in log >>>>> >>>>> Jacques >>>>> >>>>> From: "Adrian Crum" <adrian.c...@sandglass-software.com> >>>>>> Please don't change the timing logging - there should not be any >>>>>> conditions placed on it. >>>>>> >>>>>> You didn't answer my question. I was hoping we could avoid a commit war >>>>>> by discussing your requirements and designing a solution that makes >>>>>> everyone happy. >>>>>> >>>>>> -Adrian >>>>>> >>>>>> On 4/6/2013 12:00 PM, Jacques Le Roux wrote: >>>>>>> Hi Adrian, >>>>>>> >>>>>>> Thanks for asking, I committed and commented at revision: 1465223 >>>>>>> >>>>>>> Atul, >>>>>>> >>>>>>> It was not easy to read your patch in the email (cut at 80 chars). >>>>>>> Please open a Jira if you want to improve my commit. >>>>>>> >>>>>>> Thanks >>>>>>> >>>>>>> Jacques >>>>>>> >>>>>>> >>>>>>> From: "Adrian Crum" <adrian.c...@sandglass-software.com> >>>>>>>> Jacques, >>>>>>>> >>>>>>>> What are your requirements? What are you looking for in the logs? >>>>>>>> >>>>>>>> -Adrian >>>>>>>> >>>>>>>> On 4/4/2013 10:54 PM, Jacques Le Roux wrote: >>>>>>>>> These numbers are from experience of hours and hours staring at >>>>>>>>> clusters logs, but yes it's arbitrary and depend on context (as I >>>>>>>>> guess were picked the initial numbers which are there for years >>>>>>>>> Then why not the obvious solution Jacopo proposed of properties, >>>>>>>>> easy to change even dynamically... >>>>>>>>> I can't see anything more flexible, at least at 23:43 after days of >>>>>>>>> works. >>>>>>>>> AS you said, once you spot one such line in log it's not a biggie >>>>>>>>> to get there (you have the class line in log) and adapt suiting >>>>>>>>> your needs. >>>>>>>>> So maybe "like you proposed" we could indeed put a very low value >>>>>>>>> (I mean 0) as property. >>>>>>>>> >>>>>>>>> For Atul's proposition, sorry not the courage to check tonight >>>>>>>>> (maybe a patch in a Jira would help to read) >>>>>>>>> >>>>>>>>> Jacques >>>>>>>>> PS: I guessed "fuss around", knew tinker, not fidget :D >>>>>>>>> >>>>>>>>> >>>>>>>>> Adrian Crum wrote: >>>>>>>>>> Why not 20 or 30 or 40? >>>>>>>>>> >>>>>>>>>> That's the problem with arbitrary values - they don't mean >>>>>>>>>> anything. >>>>>>>>>> >>>>>>>>>> From my perspective, if anyone has timing enabled, then they >>>>>>>>>> want to >>>>>>>>>> see what's going on in the system. >>>>>>>>>> >>>>>>>>>> Feel free to change it. >>>>>>>>>> >>>>>>>>>> -Adrian >>>>>>>>>> >>>>>>>>>> On 4/3/2013 9:22 AM, Jacques Le Roux wrote: >>>>>>>>>>> Hi Adrian, All, >>>>>>>>>>> >>>>>>>>>>> Should we really show the timing for all services? >>>>>>>>>>> Maybe increasing from 50 to 75 or even 100 for the 1st case would >>>>>>>>>>> be enough? >>>>>>>>>>> >>>>>>>>>>> Jacques >>>>>>>>>>> >>>>>>>>>>> From: <adri...@apache.org> >>>>>>>>>>>> Author: adrianc >>>>>>>>>>>> Date: Wed Apr 3 07:57:24 2013 >>>>>>>>>>>> New Revision: 1463863 >>>>>>>>>>>> >>>>>>>>>>>> URL: http://svn.apache.org/r1463863 >>>>>>>>>>>> Log: >>>>>>>>>>>> Log message cleanup in ServiceDispatcher.java. Removed confusing >>>>>>>>>>>> text about services taking too long. >>>>>>>>>>>> >>>>>>>>>>>> Modified: >>>>>>>>>>>> >>>>>>>>>>>> ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java >>>>>>>>>>>> >>>>>>>>>>>> Modified: >>>>>>>>>>>> ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java >>>>>>>>>>>> URL: >>>>>>>>>>>> http://svn.apache.org/viewvc/ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java?rev=1463863&r1=1463862&r2=1463863&view=diff >>>>>>>>>>>> ============================================================================== >>>>>>>>>>>> --- >>>>>>>>>>>> ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java >>>>>>>>>>>> (original) +++ >>>>>>>>>>>> ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java >>>>>>>>>>>> Wed Apr 3 07:57:24 2013 @@ -571,10 +571,8 @@ public >>>>>>>>>>>> class ServiceDispatcher { rs.setEndStamp(); >>>>>>>>>>>> >>>>>>>>>>>> long timeToRun = System.currentTimeMillis() - >>>>>>>>>>>> serviceStartTime; >>>>>>>>>>>> - if (Debug.timingOn() && timeToRun > 50) { >>>>>>>>>>>> - Debug.logTiming("Slow sync service execution >>>>>>>>>>>> detected: service [" + localName + "/" + modelService.name + "] >>>>>>>>>>>> finished in [" + timeToRun + "] milliseconds", module); >>>>>>>>>>>> - } else if (Debug.infoOn() && timeToRun > 200) { >>>>>>>>>>>> - Debug.logInfo("Very slow sync service execution >>>>>>>>>>>> detected: service [" + localName + "/" + modelService.name + "] >>>>>>>>>>>> finished in [" + timeToRun + "] milliseconds", module); + >>>>>>>>>>>> if (Debug.timingOn()) { >>>>>>>>>>>> + Debug.logTiming("Sync service [" + localName + "/" >>>>>>>>>>>> + modelService.name + "] finished in [" + timeToRun + "] >>>>>>>>>>>> milliseconds", module); } >>>>>>>>>>>> if ((Debug.verboseOn() || modelService.debug) && >>>>>>>>>>>> timeToRun > 50 && !modelService.hideResultInLog) { >>>>>>>>>>>> // Sanity check - some service results can be >>>>>>>>>>>> multiple MB in size. Limit message size to 10K. >>> >>> -- >>> Using Opera's revolutionary email client: http://www.opera.com/mail/ >
