You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@ofbiz.apache.org by Jacques Le Roux <ja...@les7arts.com> on 2013/04/06 13:00:30 UTC
Re: Service Engine Logging (was: svn commit: r1463863 -
/ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java
)
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" <ad...@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: <ad...@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.
>
Re: Service Engine Logging
Posted by Adrian Crum <ad...@sandglass-software.com>.
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" <ad...@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" <ad...@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: <ad...@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.
Re: Service Engine Logging
Posted by Jacques Le Roux <ja...@les7arts.com>.
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" <ad...@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" <ad...@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: <ad...@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.
>
Re: Service Engine Logging
Posted by Adrian Crum <ad...@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" <ad...@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: <ad...@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.