You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@ofbiz.apache.org by ad...@apache.org on 2013/04/03 09:57:25 UTC

svn commit: r1463863 - /ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java

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: svn commit: r1463863 - /ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java

Posted by Jacopo Cappellato <ja...@hotwaxmedia.com>.
On Apr 4, 2013, at 12:25 PM, Adrian Crum <ad...@sandglass-software.com> wrote:

> No, please don't think I'm being adversarial or dismissive. This is a good discussion, and I appreciate your input.

That's great Adrian, thank you... and thanks to you I am also learning a lot of new English words :-)

Jacopo

Re: svn commit: r1463863 - /ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java

Posted by Adrian Crum <ad...@sandglass-software.com>.
On 4/4/2013 11:18 AM, Jacopo Cappellato wrote:
> On Apr 4, 2013, at 11:27 AM, Adrian Crum <ad...@sandglass-software.com> wrote:
>
>> Isn't that what the next block of code does? If you want to have a message that appears based on a set of conditions, then you can fuss around with the if statement that follows the timing message.
> Yeah, of course everyone can easily add log messages to get the information required (at the moment that block doesn't show time related information); in fact it is not a big deal for me, this is not the kind of commit that concerns me.
>
> By the way, I had to check in the dictionary the meaning of "to fuss" and I found:
>
> "show unnecessary or excessive concern about something"


Unfortunately, that is not the correct interpretation. Look up the words 
"tinker" or "fidget" to get a better understanding of what I meant. 
Basically I was saying you can modify/adjust the following if statement 
to get the results you want.


>
> In light of this, if you think that I am wasting your time with unrealistic use cases then you can ignore me :-) I don't care much about this commit and you don't have to try to convince me; as I said I am not asking you to revert your commit, I simply added some information to the context because I felt it was missing from your arguments.


No, please don't think I'm being adversarial or dismissive. This is a 
good discussion, and I appreciate your input.


>
> Jacopo
>
>> -Adrian
>>
>> On 4/4/2013 9:58 AM, Jacopo Cappellato wrote:
>>> This would be resolved by changing the message into something that clarifies that the service took longer than a given threshold X; in this case the message would be clear and could be useful to the new user (even if of course a message based on a threshold is kind of arbitrary and doesn't tell you enough about performance) and may be ignored or not based on the nature of the service.
>>>
>>> Jacopo
>>>
>>> On Apr 4, 2013, at 10:17 AM, Adrian Crum <ad...@sandglass-software.com> wrote:
>>>
>>>> Having a condition like that is unfair to end users.
>>>>
>>>> Let's say I'm a new OFBiz user. I just wrote my first service and I try it out. I run the service, and check the logs. Weird - the service engine says my service didn't run. I check my data - it appears the service ran. I put some logging messages inside my service and run it again. Cool - my log messages appear, but the service engine still says my service didn't run. So I dig deep into the service engine source code and discover that someone decided my service wasn't important enough to log. That would be very frustrating.
>>>>
>>>> If you don't want to see timing messages, then turn them off.
>>>>
>>>> Simple.
>>>>
>>>> -Adrian
>>>>
>>>> On 4/4/2013 8:57 AM, Jacopo Cappellato wrote:
>>>>> I agree it is arbitrary and sub-optimal solution but maybe I still liked it more before the last commit: the risk now is that we have too much information and no one will ever look at it.
>>>>> The obvious workaround could be to set the threshold in a property file but there are probably better solutions that will require more work and design: for example it would be nice to enable usage statistical collections on services and entities (e.g. how many times a service was executed, the average time of execution, max time etc...) and then show this data in a screen; we could store this data in an entity or a file or, maybe better, keep it in memory (in a cache or similar) and let an admin enable/disable/reset this while the system is running (similarly to cache entries).
>>>>>
>>>>> Just my 2 cents,
>>>>>
>>>>> Jacopo
>>>>>
>>>>>
>>>>> On Apr 4, 2013, at 9:22 AM, Adrian Crum <ad...@sandglass-software.com> 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: svn commit: r1463863 - /ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java

Posted by Jacopo Cappellato <ja...@hotwaxmedia.com>.
On Apr 4, 2013, at 11:27 AM, Adrian Crum <ad...@sandglass-software.com> wrote:

> Isn't that what the next block of code does? If you want to have a message that appears based on a set of conditions, then you can fuss around with the if statement that follows the timing message.

Yeah, of course everyone can easily add log messages to get the information required (at the moment that block doesn't show time related information); in fact it is not a big deal for me, this is not the kind of commit that concerns me.

By the way, I had to check in the dictionary the meaning of "to fuss" and I found:

"show unnecessary or excessive concern about something"

In light of this, if you think that I am wasting your time with unrealistic use cases then you can ignore me :-) I don't care much about this commit and you don't have to try to convince me; as I said I am not asking you to revert your commit, I simply added some information to the context because I felt it was missing from your arguments.

Jacopo

> 
> -Adrian
> 
> On 4/4/2013 9:58 AM, Jacopo Cappellato wrote:
>> This would be resolved by changing the message into something that clarifies that the service took longer than a given threshold X; in this case the message would be clear and could be useful to the new user (even if of course a message based on a threshold is kind of arbitrary and doesn't tell you enough about performance) and may be ignored or not based on the nature of the service.
>> 
>> Jacopo
>> 
>> On Apr 4, 2013, at 10:17 AM, Adrian Crum <ad...@sandglass-software.com> wrote:
>> 
>>> Having a condition like that is unfair to end users.
>>> 
>>> Let's say I'm a new OFBiz user. I just wrote my first service and I try it out. I run the service, and check the logs. Weird - the service engine says my service didn't run. I check my data - it appears the service ran. I put some logging messages inside my service and run it again. Cool - my log messages appear, but the service engine still says my service didn't run. So I dig deep into the service engine source code and discover that someone decided my service wasn't important enough to log. That would be very frustrating.
>>> 
>>> If you don't want to see timing messages, then turn them off.
>>> 
>>> Simple.
>>> 
>>> -Adrian
>>> 
>>> On 4/4/2013 8:57 AM, Jacopo Cappellato wrote:
>>>> I agree it is arbitrary and sub-optimal solution but maybe I still liked it more before the last commit: the risk now is that we have too much information and no one will ever look at it.
>>>> The obvious workaround could be to set the threshold in a property file but there are probably better solutions that will require more work and design: for example it would be nice to enable usage statistical collections on services and entities (e.g. how many times a service was executed, the average time of execution, max time etc...) and then show this data in a screen; we could store this data in an entity or a file or, maybe better, keep it in memory (in a cache or similar) and let an admin enable/disable/reset this while the system is running (similarly to cache entries).
>>>> 
>>>> Just my 2 cents,
>>>> 
>>>> Jacopo
>>>> 
>>>> 
>>>> On Apr 4, 2013, at 9:22 AM, Adrian Crum <ad...@sandglass-software.com> 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: svn commit: r1463863 - /ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java

Posted by Adrian Crum <ad...@sandglass-software.com>.
Isn't that what the next block of code does? If you want to have a 
message that appears based on a set of conditions, then you can fuss 
around with the if statement that follows the timing message.

-Adrian

On 4/4/2013 9:58 AM, Jacopo Cappellato wrote:
> This would be resolved by changing the message into something that clarifies that the service took longer than a given threshold X; in this case the message would be clear and could be useful to the new user (even if of course a message based on a threshold is kind of arbitrary and doesn't tell you enough about performance) and may be ignored or not based on the nature of the service.
>
> Jacopo
>
> On Apr 4, 2013, at 10:17 AM, Adrian Crum <ad...@sandglass-software.com> wrote:
>
>> Having a condition like that is unfair to end users.
>>
>> Let's say I'm a new OFBiz user. I just wrote my first service and I try it out. I run the service, and check the logs. Weird - the service engine says my service didn't run. I check my data - it appears the service ran. I put some logging messages inside my service and run it again. Cool - my log messages appear, but the service engine still says my service didn't run. So I dig deep into the service engine source code and discover that someone decided my service wasn't important enough to log. That would be very frustrating.
>>
>> If you don't want to see timing messages, then turn them off.
>>
>> Simple.
>>
>> -Adrian
>>
>> On 4/4/2013 8:57 AM, Jacopo Cappellato wrote:
>>> I agree it is arbitrary and sub-optimal solution but maybe I still liked it more before the last commit: the risk now is that we have too much information and no one will ever look at it.
>>> The obvious workaround could be to set the threshold in a property file but there are probably better solutions that will require more work and design: for example it would be nice to enable usage statistical collections on services and entities (e.g. how many times a service was executed, the average time of execution, max time etc...) and then show this data in a screen; we could store this data in an entity or a file or, maybe better, keep it in memory (in a cache or similar) and let an admin enable/disable/reset this while the system is running (similarly to cache entries).
>>>
>>> Just my 2 cents,
>>>
>>> Jacopo
>>>
>>>
>>> On Apr 4, 2013, at 9:22 AM, Adrian Crum <ad...@sandglass-software.com> 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: svn commit: r1463863 - /ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java

Posted by Jacopo Cappellato <ja...@hotwaxmedia.com>.
This would be resolved by changing the message into something that clarifies that the service took longer than a given threshold X; in this case the message would be clear and could be useful to the new user (even if of course a message based on a threshold is kind of arbitrary and doesn't tell you enough about performance) and may be ignored or not based on the nature of the service.

Jacopo

On Apr 4, 2013, at 10:17 AM, Adrian Crum <ad...@sandglass-software.com> wrote:

> Having a condition like that is unfair to end users.
> 
> Let's say I'm a new OFBiz user. I just wrote my first service and I try it out. I run the service, and check the logs. Weird - the service engine says my service didn't run. I check my data - it appears the service ran. I put some logging messages inside my service and run it again. Cool - my log messages appear, but the service engine still says my service didn't run. So I dig deep into the service engine source code and discover that someone decided my service wasn't important enough to log. That would be very frustrating.
> 
> If you don't want to see timing messages, then turn them off.
> 
> Simple.
> 
> -Adrian
> 
> On 4/4/2013 8:57 AM, Jacopo Cappellato wrote:
>> I agree it is arbitrary and sub-optimal solution but maybe I still liked it more before the last commit: the risk now is that we have too much information and no one will ever look at it.
>> The obvious workaround could be to set the threshold in a property file but there are probably better solutions that will require more work and design: for example it would be nice to enable usage statistical collections on services and entities (e.g. how many times a service was executed, the average time of execution, max time etc...) and then show this data in a screen; we could store this data in an entity or a file or, maybe better, keep it in memory (in a cache or similar) and let an admin enable/disable/reset this while the system is running (similarly to cache entries).
>> 
>> Just my 2 cents,
>> 
>> Jacopo
>> 
>> 
>> On Apr 4, 2013, at 9:22 AM, Adrian Crum <ad...@sandglass-software.com> 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: svn commit: r1463863 - /ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java

Posted by Adrian Crum <ad...@sandglass-software.com>.
Having a condition like that is unfair to end users.

Let's say I'm a new OFBiz user. I just wrote my first service and I try 
it out. I run the service, and check the logs. Weird - the service 
engine says my service didn't run. I check my data - it appears the 
service ran. I put some logging messages inside my service and run it 
again. Cool - my log messages appear, but the service engine still says 
my service didn't run. So I dig deep into the service engine source code 
and discover that someone decided my service wasn't important enough to 
log. That would be very frustrating.

If you don't want to see timing messages, then turn them off.

Simple.

-Adrian

On 4/4/2013 8:57 AM, Jacopo Cappellato wrote:
> I agree it is arbitrary and sub-optimal solution but maybe I still liked it more before the last commit: the risk now is that we have too much information and no one will ever look at it.
> The obvious workaround could be to set the threshold in a property file but there are probably better solutions that will require more work and design: for example it would be nice to enable usage statistical collections on services and entities (e.g. how many times a service was executed, the average time of execution, max time etc...) and then show this data in a screen; we could store this data in an entity or a file or, maybe better, keep it in memory (in a cache or similar) and let an admin enable/disable/reset this while the system is running (similarly to cache entries).
>
> Just my 2 cents,
>
> Jacopo
>
>
> On Apr 4, 2013, at 9:22 AM, Adrian Crum <ad...@sandglass-software.com> 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: svn commit: r1463863 - /ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java

Posted by Jacopo Cappellato <ja...@hotwaxmedia.com>.
I agree it is arbitrary and sub-optimal solution but maybe I still liked it more before the last commit: the risk now is that we have too much information and no one will ever look at it.
The obvious workaround could be to set the threshold in a property file but there are probably better solutions that will require more work and design: for example it would be nice to enable usage statistical collections on services and entities (e.g. how many times a service was executed, the average time of execution, max time etc...) and then show this data in a screen; we could store this data in an entity or a file or, maybe better, keep it in memory (in a cache or similar) and let an admin enable/disable/reset this while the system is running (similarly to cache entries).

Just my 2 cents,

Jacopo


On Apr 4, 2013, at 9:22 AM, Adrian Crum <ad...@sandglass-software.com> 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.


Re: Service Engine Logging (was: svn commit: r1463863 - /ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java )

Posted by Jacques Le Roux <ja...@les7arts.com>.
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.
>

Service Engine Logging (was: svn commit: r1463863 - /ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java)

Posted by 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: svn commit: r1463863 - /ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java

Posted by Jacques Le Roux <ja...@les7arts.com>.
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: svn commit: r1463863 - /ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java

Posted by Adrian Crum <ad...@sandglass-software.com>.
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: svn commit: r1463863 - /ofbiz/trunk/framework/service/src/org/ofbiz/service/ServiceDispatcher.java

Posted by Jacques Le Roux <ja...@les7arts.com>.
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.
> 
>