[DISCUSSION] Checking debug levels in Java and Groovy files

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
10 messages Options
Reply | Threaded
Open this post in threaded view
|

[DISCUSSION] Checking debug levels in Java and Groovy files

Jacques Le Roux
Administrator
Hi,

After OFBIZ-10052, OFBIZ-10448, and OFBIZ-10697 I think it's time to have another discussion following https://markmail.org/message/mplvusuqn7oshl4v 
which was one year ago.

In OFBIZ-10697 I wrote:

    <<OK let me explain my point.

    By default OOTB debug.properties sets all debug levels to be used but verbose. So there is no point checking other levels than verbose to see if
    they are used, they are anyway. So OOTB only checking verbose is needed. That's what developers need.

    Now you invoked production where a different debug.properties setting would be used. Sincerely I'd never, never, remove the other levels than
    verbose from a production setting (as it's OOTB). I'd even be quite reluctant to remove any of those levels from a production site running for
    years! *You never know what can happen*, and those debug levels are your only lifebelt in case of issues, small and big ones.

    That's my point, and that's why I see checking if a level is used as premature optimisation but for verbose. We need them anyway and IMO setting
    false for any but verbose in debug.properties in production would be conceited if not "suicidal" . But maybe you have use cases I ignore?

    Anway, I'll start a discussion in dev ML about this point. Like I said above and in OFBIZ-10448 <https://issues.apache.org/jira/browse/OFBIZ-10448>:

        I'd be all for removing the 312 useless cases but not the "if (Debug.verboseOn())">>

To what Michael answered

    <<We have several projects with huge traffic and you certainly won't run them on debug level info, verbose or debug.
    In my view, at least these 3 debug levels should be checked. At least, existing checks should not be removed.>>

I think Michael's point is perfectly valid. So I answered:

    <<I had not the same experience, you are lucky to not cross any issue in production needing an info or debug level.
    OK then we need to see things otherwise and rather enforce the checks to these 2 levels at least in all the source (Java and Groovy). That's what
    I'll ask in the convo to come in dev ML.>>

So what are your opinion about that? Should we enforce as suggest Michael or should we remove for the reasons I wrote.

I'd prefer to be consistent. So either we enforce the checks to the info, verbose and debug levels. Either we only keep the verbose checks.

Finally Mathieu has added a grain of salt:

    <<Hello Michael Brohl <https://issues.apache.org/jira/secure/ViewProfile.jspa?name=mbrohl>,

    If you care about the impact of loggers on performance you should take a look at the Beautiful Logger <https://github.com/forax/beautiful_logger>
    library by Remi Forax which implements a truly transparent logger. In a recent Devoxx talk <https://www.youtube.com/watch?v=z5UkoLaW6ME> (in
    french) he showed that even doing if (Debug.logXXX()) has a 3x slowdown compared to a no-op.>>

So maybe we should have a closer look at  Beautiful Logger before taking any decision? Note that it uses JitPack, hence seems to need "Java 11 to build".

Thanks

Jacques

Reply | Threaded
Open this post in threaded view
|

Re: [DISCUSSION] Checking debug levels in Java and Groovy files

taher
I didn't understand the exact decision required? To do what vs what?
On Mon, Dec 10, 2018 at 7:43 PM Jacques Le Roux
<[hidden email]> wrote:

>
> Hi,
>
> After OFBIZ-10052, OFBIZ-10448, and OFBIZ-10697 I think it's time to have another discussion following https://markmail.org/message/mplvusuqn7oshl4v
> which was one year ago.
>
> In OFBIZ-10697 I wrote:
>
>     <<OK let me explain my point.
>
>     By default OOTB debug.properties sets all debug levels to be used but verbose. So there is no point checking other levels than verbose to see if
>     they are used, they are anyway. So OOTB only checking verbose is needed. That's what developers need.
>
>     Now you invoked production where a different debug.properties setting would be used. Sincerely I'd never, never, remove the other levels than
>     verbose from a production setting (as it's OOTB). I'd even be quite reluctant to remove any of those levels from a production site running for
>     years! *You never know what can happen*, and those debug levels are your only lifebelt in case of issues, small and big ones.
>
>     That's my point, and that's why I see checking if a level is used as premature optimisation but for verbose. We need them anyway and IMO setting
>     false for any but verbose in debug.properties in production would be conceited if not "suicidal" . But maybe you have use cases I ignore?
>
>     Anway, I'll start a discussion in dev ML about this point. Like I said above and in OFBIZ-10448 <https://issues.apache.org/jira/browse/OFBIZ-10448>:
>
>         I'd be all for removing the 312 useless cases but not the "if (Debug.verboseOn())">>
>
> To what Michael answered
>
>     <<We have several projects with huge traffic and you certainly won't run them on debug level info, verbose or debug.
>     In my view, at least these 3 debug levels should be checked. At least, existing checks should not be removed.>>
>
> I think Michael's point is perfectly valid. So I answered:
>
>     <<I had not the same experience, you are lucky to not cross any issue in production needing an info or debug level.
>     OK then we need to see things otherwise and rather enforce the checks to these 2 levels at least in all the source (Java and Groovy). That's what
>     I'll ask in the convo to come in dev ML.>>
>
> So what are your opinion about that? Should we enforce as suggest Michael or should we remove for the reasons I wrote.
>
> I'd prefer to be consistent. So either we enforce the checks to the info, verbose and debug levels. Either we only keep the verbose checks.
>
> Finally Mathieu has added a grain of salt:
>
>     <<Hello Michael Brohl <https://issues.apache.org/jira/secure/ViewProfile.jspa?name=mbrohl>,
>
>     If you care about the impact of loggers on performance you should take a look at the Beautiful Logger <https://github.com/forax/beautiful_logger>
>     library by Remi Forax which implements a truly transparent logger. In a recent Devoxx talk <https://www.youtube.com/watch?v=z5UkoLaW6ME> (in
>     french) he showed that even doing if (Debug.logXXX()) has a 3x slowdown compared to a no-op.>>
>
> So maybe we should have a closer look at  Beautiful Logger before taking any decision? Note that it uses JitPack, hence seems to need "Java 11 to build".
>
> Thanks
>
> Jacques
>
Reply | Threaded
Open this post in threaded view
|

Re: [DISCUSSION] Checking debug levels in Java and Groovy files

Jacques Le Roux
Administrator
The question is quite simple. It's about always using or not the /if (Debug.levelOn()) {/ expression for the info and debug level as suggests Michael.

Or only using /if/ /(Debug.verboseOn()) { /expression as I recommend for the reasons explained.

I think we all agree the /if/ /(Debug.verboseOn()) { /should always be used and enforced when missing.

I put all the details/arguments to easily refer to them if needed.

Also Mathieu suggested to Michael to have a look at "Beautiful Logger" because he is concerned by the logging performance. We could also have a look
at it, to see if it could be integrated OOTB.

HTH

Jacques

Le 10/12/2018 à 18:02, Taher Alkhateeb a écrit :

> I didn't understand the exact decision required? To do what vs what?
> On Mon, Dec 10, 2018 at 7:43 PM Jacques Le Roux
> <[hidden email]> wrote:
>> Hi,
>>
>> After OFBIZ-10052, OFBIZ-10448, and OFBIZ-10697 I think it's time to have another discussion following https://markmail.org/message/mplvusuqn7oshl4v
>> which was one year ago.
>>
>> In OFBIZ-10697 I wrote:
>>
>>      <<OK let me explain my point.
>>
>>      By default OOTB debug.properties sets all debug levels to be used but verbose. So there is no point checking other levels than verbose to see if
>>      they are used, they are anyway. So OOTB only checking verbose is needed. That's what developers need.
>>
>>      Now you invoked production where a different debug.properties setting would be used. Sincerely I'd never, never, remove the other levels than
>>      verbose from a production setting (as it's OOTB). I'd even be quite reluctant to remove any of those levels from a production site running for
>>      years! *You never know what can happen*, and those debug levels are your only lifebelt in case of issues, small and big ones.
>>
>>      That's my point, and that's why I see checking if a level is used as premature optimisation but for verbose. We need them anyway and IMO setting
>>      false for any but verbose in debug.properties in production would be conceited if not "suicidal" . But maybe you have use cases I ignore?
>>
>>      Anway, I'll start a discussion in dev ML about this point. Like I said above and in OFBIZ-10448 <https://issues.apache.org/jira/browse/OFBIZ-10448>:
>>
>>          I'd be all for removing the 312 useless cases but not the "if (Debug.verboseOn())">>
>>
>> To what Michael answered
>>
>>      <<We have several projects with huge traffic and you certainly won't run them on debug level info, verbose or debug.
>>      In my view, at least these 3 debug levels should be checked. At least, existing checks should not be removed.>>
>>
>> I think Michael's point is perfectly valid. So I answered:
>>
>>      <<I had not the same experience, you are lucky to not cross any issue in production needing an info or debug level.
>>      OK then we need to see things otherwise and rather enforce the checks to these 2 levels at least in all the source (Java and Groovy). That's what
>>      I'll ask in the convo to come in dev ML.>>
>>
>> So what are your opinion about that? Should we enforce as suggest Michael or should we remove for the reasons I wrote.
>>
>> I'd prefer to be consistent. So either we enforce the checks to the info, verbose and debug levels. Either we only keep the verbose checks.
>>
>> Finally Mathieu has added a grain of salt:
>>
>>      <<Hello Michael Brohl <https://issues.apache.org/jira/secure/ViewProfile.jspa?name=mbrohl>,
>>
>>      If you care about the impact of loggers on performance you should take a look at the Beautiful Logger <https://github.com/forax/beautiful_logger>
>>      library by Remi Forax which implements a truly transparent logger. In a recent Devoxx talk <https://www.youtube.com/watch?v=z5UkoLaW6ME> (in
>>      french) he showed that even doing if (Debug.logXXX()) has a 3x slowdown compared to a no-op.>>
>>
>> So maybe we should have a closer look at  Beautiful Logger before taking any decision? Note that it uses JitPack, hence seems to need "Java 11 to build".
>>
>> Thanks
>>
>> Jacques
>>
Reply | Threaded
Open this post in threaded view
|

Re: [DISCUSSION] Checking debug levels in Java and Groovy files

taher
We already agreed and decided to keep the if condition. I'm not sure
why this subject is being reopened.
On Mon, Dec 10, 2018 at 9:49 PM Jacques Le Roux
<[hidden email]> wrote:

>
> The question is quite simple. It's about always using or not the /if (Debug.levelOn()) {/ expression for the info and debug level as suggests Michael.
>
> Or only using /if/ /(Debug.verboseOn()) { /expression as I recommend for the reasons explained.
>
> I think we all agree the /if/ /(Debug.verboseOn()) { /should always be used and enforced when missing.
>
> I put all the details/arguments to easily refer to them if needed.
>
> Also Mathieu suggested to Michael to have a look at "Beautiful Logger" because he is concerned by the logging performance. We could also have a look
> at it, to see if it could be integrated OOTB.
>
> HTH
>
> Jacques
>
> Le 10/12/2018 à 18:02, Taher Alkhateeb a écrit :
> > I didn't understand the exact decision required? To do what vs what?
> > On Mon, Dec 10, 2018 at 7:43 PM Jacques Le Roux
> > <[hidden email]> wrote:
> >> Hi,
> >>
> >> After OFBIZ-10052, OFBIZ-10448, and OFBIZ-10697 I think it's time to have another discussion following https://markmail.org/message/mplvusuqn7oshl4v
> >> which was one year ago.
> >>
> >> In OFBIZ-10697 I wrote:
> >>
> >>      <<OK let me explain my point.
> >>
> >>      By default OOTB debug.properties sets all debug levels to be used but verbose. So there is no point checking other levels than verbose to see if
> >>      they are used, they are anyway. So OOTB only checking verbose is needed. That's what developers need.
> >>
> >>      Now you invoked production where a different debug.properties setting would be used. Sincerely I'd never, never, remove the other levels than
> >>      verbose from a production setting (as it's OOTB). I'd even be quite reluctant to remove any of those levels from a production site running for
> >>      years! *You never know what can happen*, and those debug levels are your only lifebelt in case of issues, small and big ones.
> >>
> >>      That's my point, and that's why I see checking if a level is used as premature optimisation but for verbose. We need them anyway and IMO setting
> >>      false for any but verbose in debug.properties in production would be conceited if not "suicidal" . But maybe you have use cases I ignore?
> >>
> >>      Anway, I'll start a discussion in dev ML about this point. Like I said above and in OFBIZ-10448 <https://issues.apache.org/jira/browse/OFBIZ-10448>:
> >>
> >>          I'd be all for removing the 312 useless cases but not the "if (Debug.verboseOn())">>
> >>
> >> To what Michael answered
> >>
> >>      <<We have several projects with huge traffic and you certainly won't run them on debug level info, verbose or debug.
> >>      In my view, at least these 3 debug levels should be checked. At least, existing checks should not be removed.>>
> >>
> >> I think Michael's point is perfectly valid. So I answered:
> >>
> >>      <<I had not the same experience, you are lucky to not cross any issue in production needing an info or debug level.
> >>      OK then we need to see things otherwise and rather enforce the checks to these 2 levels at least in all the source (Java and Groovy). That's what
> >>      I'll ask in the convo to come in dev ML.>>
> >>
> >> So what are your opinion about that? Should we enforce as suggest Michael or should we remove for the reasons I wrote.
> >>
> >> I'd prefer to be consistent. So either we enforce the checks to the info, verbose and debug levels. Either we only keep the verbose checks.
> >>
> >> Finally Mathieu has added a grain of salt:
> >>
> >>      <<Hello Michael Brohl <https://issues.apache.org/jira/secure/ViewProfile.jspa?name=mbrohl>,
> >>
> >>      If you care about the impact of loggers on performance you should take a look at the Beautiful Logger <https://github.com/forax/beautiful_logger>
> >>      library by Remi Forax which implements a truly transparent logger. In a recent Devoxx talk <https://www.youtube.com/watch?v=z5UkoLaW6ME> (in
> >>      french) he showed that even doing if (Debug.logXXX()) has a 3x slowdown compared to a no-op.>>
> >>
> >> So maybe we should have a closer look at  Beautiful Logger before taking any decision? Note that it uses JitPack, hence seems to need "Java 11 to build".
> >>
> >> Thanks
> >>
> >> Jacques
> >>
Reply | Threaded
Open this post in threaded view
|

Re: [DISCUSSION] Checking debug levels in Java and Groovy files

Jacques Le Roux
Administrator
Because

 1. The if condition has a cost (3 times more than nothing according to Mathieu's reference[1])
 2. and is not consistently used.
 3. Using "Beautiful Logger" could be a better solution: https://github.com/forax/beautiful_logger
    drawbacks:
      *   needs Java 11 to build. But will we use Java 8 forever? Can run with Java 8.
      * "put more pressure to the JITs so it may lengthen the time to steady state of an application."

[1] https://www.youtube.com/watch?v=z5UkoLaW6ME (French)

Jacques

Le 11/12/2018 à 12:15, Taher Alkhateeb a écrit :

> We already agreed and decided to keep the if condition. I'm not sure
> why this subject is being reopened.
> On Mon, Dec 10, 2018 at 9:49 PM Jacques Le Roux
> <[hidden email]> wrote:
>> The question is quite simple. It's about always using or not the /if (Debug.levelOn()) {/ expression for the info and debug level as suggests Michael.
>>
>> Or only using /if/ /(Debug.verboseOn()) { /expression as I recommend for the reasons explained.
>>
>> I think we all agree the /if/ /(Debug.verboseOn()) { /should always be used and enforced when missing.
>>
>> I put all the details/arguments to easily refer to them if needed.
>>
>> Also Mathieu suggested to Michael to have a look at "Beautiful Logger" because he is concerned by the logging performance. We could also have a look
>> at it, to see if it could be integrated OOTB.
>>
>> HTH
>>
>> Jacques
>>
>> Le 10/12/2018 à 18:02, Taher Alkhateeb a écrit :
>>> I didn't understand the exact decision required? To do what vs what?
>>> On Mon, Dec 10, 2018 at 7:43 PM Jacques Le Roux
>>> <[hidden email]> wrote:
>>>> Hi,
>>>>
>>>> After OFBIZ-10052, OFBIZ-10448, and OFBIZ-10697 I think it's time to have another discussion following https://markmail.org/message/mplvusuqn7oshl4v
>>>> which was one year ago.
>>>>
>>>> In OFBIZ-10697 I wrote:
>>>>
>>>>       <<OK let me explain my point.
>>>>
>>>>       By default OOTB debug.properties sets all debug levels to be used but verbose. So there is no point checking other levels than verbose to see if
>>>>       they are used, they are anyway. So OOTB only checking verbose is needed. That's what developers need.
>>>>
>>>>       Now you invoked production where a different debug.properties setting would be used. Sincerely I'd never, never, remove the other levels than
>>>>       verbose from a production setting (as it's OOTB). I'd even be quite reluctant to remove any of those levels from a production site running for
>>>>       years! *You never know what can happen*, and those debug levels are your only lifebelt in case of issues, small and big ones.
>>>>
>>>>       That's my point, and that's why I see checking if a level is used as premature optimisation but for verbose. We need them anyway and IMO setting
>>>>       false for any but verbose in debug.properties in production would be conceited if not "suicidal" . But maybe you have use cases I ignore?
>>>>
>>>>       Anway, I'll start a discussion in dev ML about this point. Like I said above and in OFBIZ-10448 <https://issues.apache.org/jira/browse/OFBIZ-10448>:
>>>>
>>>>           I'd be all for removing the 312 useless cases but not the "if (Debug.verboseOn())">>
>>>>
>>>> To what Michael answered
>>>>
>>>>       <<We have several projects with huge traffic and you certainly won't run them on debug level info, verbose or debug.
>>>>       In my view, at least these 3 debug levels should be checked. At least, existing checks should not be removed.>>
>>>>
>>>> I think Michael's point is perfectly valid. So I answered:
>>>>
>>>>       <<I had not the same experience, you are lucky to not cross any issue in production needing an info or debug level.
>>>>       OK then we need to see things otherwise and rather enforce the checks to these 2 levels at least in all the source (Java and Groovy). That's what
>>>>       I'll ask in the convo to come in dev ML.>>
>>>>
>>>> So what are your opinion about that? Should we enforce as suggest Michael or should we remove for the reasons I wrote.
>>>>
>>>> I'd prefer to be consistent. So either we enforce the checks to the info, verbose and debug levels. Either we only keep the verbose checks.
>>>>
>>>> Finally Mathieu has added a grain of salt:
>>>>
>>>>       <<Hello Michael Brohl <https://issues.apache.org/jira/secure/ViewProfile.jspa?name=mbrohl>,
>>>>
>>>>       If you care about the impact of loggers on performance you should take a look at the Beautiful Logger <https://github.com/forax/beautiful_logger>
>>>>       library by Remi Forax which implements a truly transparent logger. In a recent Devoxx talk <https://www.youtube.com/watch?v=z5UkoLaW6ME> (in
>>>>       french) he showed that even doing if (Debug.logXXX()) has a 3x slowdown compared to a no-op.>>
>>>>
>>>> So maybe we should have a closer look at  Beautiful Logger before taking any decision? Note that it uses JitPack, hence seems to need "Java 11 to build".
>>>>
>>>> Thanks
>>>>
>>>> Jacques
>>>>
Reply | Threaded
Open this post in threaded view
|

Re: [DISCUSSION] Checking debug levels in Java and Groovy files

Michael Brohl-3
Hi Jacques,

inline...


Am 11.12.18 um 13:42 schrieb Jacques Le Roux:
> Because
>
> 1. The if condition has a cost (3 times more than nothing according to
> Mathieu's reference[1])

Yes, right, but it's certainly less costly than the direct execution of
Debug.logXxxx... And that's the point. You don't want to run these
statments thousands of times within a minute (in production systems),
which is the case in central functionality like the controller.

You can only leave out the if conditions if you are sure that the
correpsonding debug level is always on.

As I said earlier, this is not the case for verbose, debug and info on
production systems.

> 2. and is not consistently used.

Who cares? Each improvement is a gain and if we only introduce these
conditions in the hotspot functionality, it's an improvement.

It's not only black and white...

> 3. Using "Beautiful Logger" could be a better solution:
> https://github.com/forax/beautiful_logger
>    drawbacks:
>      *   needs Java 11 to build. But will we use Java 8 forever? Can
> run with Java 8.
>      * "put more pressure to the JITs so it may lengthen the time to
> steady state of an application."
>
> [1] https://www.youtube.com/watch?v=z5UkoLaW6ME (French)

Although this seems interesting, it is fairly new with the first release
early this year. I won't recommend to introduce it until it's field
tested (in production).

Thanks,
Michael


>
> Jacques
>
> Le 11/12/2018 à 12:15, Taher Alkhateeb a écrit :
>> We already agreed and decided to keep the if condition. I'm not sure
>> why this subject is being reopened.
>> On Mon, Dec 10, 2018 at 9:49 PM Jacques Le Roux
>> <[hidden email]> wrote:
>>> The question is quite simple. It's about always using or not the /if
>>> (Debug.levelOn()) {/ expression for the info and debug level as
>>> suggests Michael.
>>>
>>> Or only using /if/ /(Debug.verboseOn()) { /expression as I recommend
>>> for the reasons explained.
>>>
>>> I think we all agree the /if/ /(Debug.verboseOn()) { /should always
>>> be used and enforced when missing.
>>>
>>> I put all the details/arguments to easily refer to them if needed.
>>>
>>> Also Mathieu suggested to Michael to have a look at "Beautiful
>>> Logger" because he is concerned by the logging performance. We could
>>> also have a look
>>> at it, to see if it could be integrated OOTB.
>>>
>>> HTH
>>>
>>> Jacques
>>>
>>> Le 10/12/2018 à 18:02, Taher Alkhateeb a écrit :
>>>> I didn't understand the exact decision required? To do what vs what?
>>>> On Mon, Dec 10, 2018 at 7:43 PM Jacques Le Roux
>>>> <[hidden email]> wrote:
>>>>> Hi,
>>>>>
>>>>> After OFBIZ-10052, OFBIZ-10448, and OFBIZ-10697 I think it's time
>>>>> to have another discussion following
>>>>> https://markmail.org/message/mplvusuqn7oshl4v
>>>>> which was one year ago.
>>>>>
>>>>> In OFBIZ-10697 I wrote:
>>>>>
>>>>>       <<OK let me explain my point.
>>>>>
>>>>>       By default OOTB debug.properties sets all debug levels to be
>>>>> used but verbose. So there is no point checking other levels than
>>>>> verbose to see if
>>>>>       they are used, they are anyway. So OOTB only checking
>>>>> verbose is needed. That's what developers need.
>>>>>
>>>>>       Now you invoked production where a different
>>>>> debug.properties setting would be used. Sincerely I'd never,
>>>>> never, remove the other levels than
>>>>>       verbose from a production setting (as it's OOTB). I'd even
>>>>> be quite reluctant to remove any of those levels from a production
>>>>> site running for
>>>>>       years! *You never know what can happen*, and those debug
>>>>> levels are your only lifebelt in case of issues, small and big ones.
>>>>>
>>>>>       That's my point, and that's why I see checking if a level is
>>>>> used as premature optimisation but for verbose. We need them
>>>>> anyway and IMO setting
>>>>>       false for any but verbose in debug.properties in production
>>>>> would be conceited if not "suicidal" . But maybe you have use
>>>>> cases I ignore?
>>>>>
>>>>>       Anway, I'll start a discussion in dev ML about this point.
>>>>> Like I said above and in OFBIZ-10448
>>>>> <https://issues.apache.org/jira/browse/OFBIZ-10448>:
>>>>>
>>>>>           I'd be all for removing the 312 useless cases but not
>>>>> the "if (Debug.verboseOn())">>
>>>>>
>>>>> To what Michael answered
>>>>>
>>>>>       <<We have several projects with huge traffic and you
>>>>> certainly won't run them on debug level info, verbose or debug.
>>>>>       In my view, at least these 3 debug levels should be checked.
>>>>> At least, existing checks should not be removed.>>
>>>>>
>>>>> I think Michael's point is perfectly valid. So I answered:
>>>>>
>>>>>       <<I had not the same experience, you are lucky to not cross
>>>>> any issue in production needing an info or debug level.
>>>>>       OK then we need to see things otherwise and rather enforce
>>>>> the checks to these 2 levels at least in all the source (Java and
>>>>> Groovy). That's what
>>>>>       I'll ask in the convo to come in dev ML.>>
>>>>>
>>>>> So what are your opinion about that? Should we enforce as suggest
>>>>> Michael or should we remove for the reasons I wrote.
>>>>>
>>>>> I'd prefer to be consistent. So either we enforce the checks to
>>>>> the info, verbose and debug levels. Either we only keep the
>>>>> verbose checks.
>>>>>
>>>>> Finally Mathieu has added a grain of salt:
>>>>>
>>>>>       <<Hello Michael Brohl
>>>>> <https://issues.apache.org/jira/secure/ViewProfile.jspa?name=mbrohl>,
>>>>>
>>>>>       If you care about the impact of loggers on performance you
>>>>> should take a look at the Beautiful Logger
>>>>> <https://github.com/forax/beautiful_logger>
>>>>>       library by Remi Forax which implements a truly transparent
>>>>> logger. In a recent Devoxx talk
>>>>> <https://www.youtube.com/watch?v=z5UkoLaW6ME> (in
>>>>>       french) he showed that even doing if (Debug.logXXX()) has a
>>>>> 3x slowdown compared to a no-op.>>
>>>>>
>>>>> So maybe we should have a closer look at  Beautiful Logger before
>>>>> taking any decision? Note that it uses JitPack, hence seems to
>>>>> need "Java 11 to build".
>>>>>
>>>>> Thanks
>>>>>
>>>>> Jacques
>>>>>
>


smime.p7s (5K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: [DISCUSSION] Checking debug levels in Java and Groovy files

Jacques Le Roux
Administrator
Hi Michael,

Le 11/12/2018 à 15:57, Michael Brohl a écrit :

> Am 11.12.18 um 13:42 schrieb Jacques Le Roux:
>> Because
>>
>> 1. The if condition has a cost (3 times more than nothing according to Mathieu's reference[1])
>
> Yes, right, but it's certainly less costly than the direct execution of Debug.logXxxx... And that's the point. You don't want to run these statments
> thousands of times within a minute (in production systems), which is the case in central functionality like the controller.
>
> You can only leave out the if conditions if you are sure that the correpsonding debug level is always on.
>
> As I said earlier, this is not the case for verbose, debug and info on production systems.

I see no problems with that


>
>> 2. and is not consistently used.
>
> Who cares? Each improvement is a gain and if we only introduce these conditions in the hotspot functionality, it's an improvement.
>
> It's not only black and white...

Yes you are right, custom projects can hopefully adapt and contribute.


>
>> 3. Using "Beautiful Logger" could be a better solution: https://github.com/forax/beautiful_logger
>>    drawbacks:
>>      *   needs Java 11 to build. But will we use Java 8 forever? Can run with Java 8.
>>      * "put more pressure to the JITs so it may lengthen the time to steady state of an application."
>>
>> [1] https://www.youtube.com/watch?v=z5UkoLaW6ME (French)
>
> Although this seems interesting, it is fairly new with the first release early this year. I won't recommend to introduce it until it's field tested
> (in production).

*That's the most important point of this discussion*

I agree, but if nobody test it it will not fly soon ;)

Actually I'm not worried Rémi is very well know in the French and global Java community. And we need to use Java 11...

I  have created OFBIZ-10704 to not forget to check what embedding it in OFBiz would mean.

Thanks


Jacques


>
> Thanks,
> Michael
>
>
>>
>> Jacques
>>
>> Le 11/12/2018 à 12:15, Taher Alkhateeb a écrit :
>>> We already agreed and decided to keep the if condition. I'm not sure
>>> why this subject is being reopened.
>>> On Mon, Dec 10, 2018 at 9:49 PM Jacques Le Roux
>>> <[hidden email]> wrote:
>>>> The question is quite simple. It's about always using or not the /if (Debug.levelOn()) {/ expression for the info and debug level as suggests
>>>> Michael.
>>>>
>>>> Or only using /if/ /(Debug.verboseOn()) { /expression as I recommend for the reasons explained.
>>>>
>>>> I think we all agree the /if/ /(Debug.verboseOn()) { /should always be used and enforced when missing.
>>>>
>>>> I put all the details/arguments to easily refer to them if needed.
>>>>
>>>> Also Mathieu suggested to Michael to have a look at "Beautiful Logger" because he is concerned by the logging performance. We could also have a look
>>>> at it, to see if it could be integrated OOTB.
>>>>
>>>> HTH
>>>>
>>>> Jacques
>>>>
>>>> Le 10/12/2018 à 18:02, Taher Alkhateeb a écrit :
>>>>> I didn't understand the exact decision required? To do what vs what?
>>>>> On Mon, Dec 10, 2018 at 7:43 PM Jacques Le Roux
>>>>> <[hidden email]> wrote:
>>>>>> Hi,
>>>>>>
>>>>>> After OFBIZ-10052, OFBIZ-10448, and OFBIZ-10697 I think it's time to have another discussion following
>>>>>> https://markmail.org/message/mplvusuqn7oshl4v
>>>>>> which was one year ago.
>>>>>>
>>>>>> In OFBIZ-10697 I wrote:
>>>>>>
>>>>>>       <<OK let me explain my point.
>>>>>>
>>>>>>       By default OOTB debug.properties sets all debug levels to be used but verbose. So there is no point checking other levels than verbose to
>>>>>> see if
>>>>>>       they are used, they are anyway. So OOTB only checking verbose is needed. That's what developers need.
>>>>>>
>>>>>>       Now you invoked production where a different debug.properties setting would be used. Sincerely I'd never, never, remove the other levels
>>>>>> than
>>>>>>       verbose from a production setting (as it's OOTB). I'd even be quite reluctant to remove any of those levels from a production site
>>>>>> running for
>>>>>>       years! *You never know what can happen*, and those debug levels are your only lifebelt in case of issues, small and big ones.
>>>>>>
>>>>>>       That's my point, and that's why I see checking if a level is used as premature optimisation but for verbose. We need them anyway and IMO
>>>>>> setting
>>>>>>       false for any but verbose in debug.properties in production would be conceited if not "suicidal" . But maybe you have use cases I ignore?
>>>>>>
>>>>>>       Anway, I'll start a discussion in dev ML about this point. Like I said above and in OFBIZ-10448
>>>>>> <https://issues.apache.org/jira/browse/OFBIZ-10448>:
>>>>>>
>>>>>>           I'd be all for removing the 312 useless cases but not the "if (Debug.verboseOn())">>
>>>>>>
>>>>>> To what Michael answered
>>>>>>
>>>>>>       <<We have several projects with huge traffic and you certainly won't run them on debug level info, verbose or debug.
>>>>>>       In my view, at least these 3 debug levels should be checked. At least, existing checks should not be removed.>>
>>>>>>
>>>>>> I think Michael's point is perfectly valid. So I answered:
>>>>>>
>>>>>>       <<I had not the same experience, you are lucky to not cross any issue in production needing an info or debug level.
>>>>>>       OK then we need to see things otherwise and rather enforce the checks to these 2 levels at least in all the source (Java and Groovy).
>>>>>> That's what
>>>>>>       I'll ask in the convo to come in dev ML.>>
>>>>>>
>>>>>> So what are your opinion about that? Should we enforce as suggest Michael or should we remove for the reasons I wrote.
>>>>>>
>>>>>> I'd prefer to be consistent. So either we enforce the checks to the info, verbose and debug levels. Either we only keep the verbose checks.
>>>>>>
>>>>>> Finally Mathieu has added a grain of salt:
>>>>>>
>>>>>>       <<Hello Michael Brohl <https://issues.apache.org/jira/secure/ViewProfile.jspa?name=mbrohl>,
>>>>>>
>>>>>>       If you care about the impact of loggers on performance you should take a look at the Beautiful Logger
>>>>>> <https://github.com/forax/beautiful_logger>
>>>>>>       library by Remi Forax which implements a truly transparent logger. In a recent Devoxx talk <https://www.youtube.com/watch?v=z5UkoLaW6ME> (in
>>>>>>       french) he showed that even doing if (Debug.logXXX()) has a 3x slowdown compared to a no-op.>>
>>>>>>
>>>>>> So maybe we should have a closer look at  Beautiful Logger before taking any decision? Note that it uses JitPack, hence seems to need "Java 11
>>>>>> to build".
>>>>>>
>>>>>> Thanks
>>>>>>
>>>>>> Jacques
>>>>>>
>>
>
>
Reply | Threaded
Open this post in threaded view
|

Re: [DISCUSSION] Checking debug levels in Java and Groovy files

Mathieu Lirzin
In reply to this post by Michael Brohl-3
Hello Michael,

Michael Brohl <[hidden email]> writes:

> Yes, right, but it's certainly less costly than the direct execution
> of Debug.logXxxx... And that's the point. You don't want to run these
> statments thousands of times within a minute (in production systems),
> which is the case in central functionality like the controller.

According to Rémi Forax's numbers this assumption is *not* verified! [1]

He gets exactly the same performance results (1.08× ns/op) with either
of the following options:

   1) Debug.log("...")
   2) if (Debug.isEnabled()) { Debug.log("...") }
   3) Debug.log(() -> "...")

> Who cares? Each improvement is a gain and if we only introduce these
> conditions in the hotspot functionality, it's an improvement.
>
> It's not only black and white...

I think that any claim of performance gain/loss must be backed by an
actual measurement, and this has not been the case in this discussion.

Personnally I care about the readability of the code and choosing the
option 2 is not helping in that regard.

[1] https://youtu.be/z5UkoLaW6ME?t=213

--
Mathieu Lirzin
GPG: F2A3 8D7E EB2B 6640 5761  070D 0ADE E100 9460 4D37
Reply | Threaded
Open this post in threaded view
|

Re: [DISCUSSION] Checking debug levels in Java and Groovy files

taher
The official documentation mentions that performance is hit [1] with metrics.

[1] https://logging.apache.org/log4j/2.x/performance.html#asyncLoggingWithParams
On Tue, Dec 11, 2018 at 7:19 PM Mathieu Lirzin
<[hidden email]> wrote:

>
> Hello Michael,
>
> Michael Brohl <[hidden email]> writes:
>
> > Yes, right, but it's certainly less costly than the direct execution
> > of Debug.logXxxx... And that's the point. You don't want to run these
> > statments thousands of times within a minute (in production systems),
> > which is the case in central functionality like the controller.
>
> According to Rémi Forax's numbers this assumption is *not* verified! [1]
>
> He gets exactly the same performance results (1.08× ns/op) with either
> of the following options:
>
>    1) Debug.log("...")
>    2) if (Debug.isEnabled()) { Debug.log("...") }
>    3) Debug.log(() -> "...")
>
> > Who cares? Each improvement is a gain and if we only introduce these
> > conditions in the hotspot functionality, it's an improvement.
> >
> > It's not only black and white...
>
> I think that any claim of performance gain/loss must be backed by an
> actual measurement, and this has not been the case in this discussion.
>
> Personnally I care about the readability of the code and choosing the
> option 2 is not helping in that regard.
>
> [1] https://youtu.be/z5UkoLaW6ME?t=213
>
> --
> Mathieu Lirzin
> GPG: F2A3 8D7E EB2B 6640 5761  070D 0ADE E100 9460 4D37
Reply | Threaded
Open this post in threaded view
|

Re: [DISCUSSION] Checking debug levels in Java and Groovy files

Gil Portenseigne
Hello,

The difference with the documentation and Mathieu's example is the
presence of String concatenation. Here lies the performance improvment.

If there a simple String is used, the if is uneeded :)

Regards

Gil

Le 19:58 - mardi 11 déc., Taher Alkhateeb a écrit :

> The official documentation mentions that performance is hit [1] with metrics.
>
> [1] https://logging.apache.org/log4j/2.x/performance.html#asyncLoggingWithParams
> On Tue, Dec 11, 2018 at 7:19 PM Mathieu Lirzin
> <[hidden email]> wrote:
> >
> > He gets exactly the same performance results (1.08× ns/op) with either
> > of the following options:
> >
> >    1) Debug.log("...")
> >    2) if (Debug.isEnabled()) { Debug.log("...") }
> >    3) Debug.log(() -> "...")
> >