If there’s enough duplication in the lambdas, or in the code around the lambdas, extracting the duplication into methods would reduce the number of lambdas.
> On Sep 10, 2018, at 11:03 AM, Kirk Lund <kl...@apache.org> wrote: > > Alright I'm more up-to-date on this thread. Some things to consider: > > The lambdas look great, but we'd have to start splitting the Geode clasess. > They're so big right now, that if you change a bunch of log statements to > use lambdas you'll hit the max number of lambdas on many of our classes. We > hit the lambda limit on a dunit test and it didn't really take that many > lambdas to hit the limit (see > https://issues.apache.org/jira/browse/GEODE-5485). > > We could change FastLogger to override every Logger method instead of > isDebugEnabled and isTraceEnabled. Then we could remove every single guard > clause from the Geode log statements. > > If Log4J2 changed their implementation of debug and trace to be comparable > with hitting a volatile for disabled statements then we could delete > FastLogger and every log statement guard clause. > > On Mon, Sep 10, 2018 at 10:12 AM, Kirk Lund <kl...@apache.org> wrote: > >> The reason we use these guards is that the Log4j2 implementation is more >> expensive than hitting a volatile. Please don't change anything unless you >> start writing lots of JMH benchmarks! The existing code went through lots >> of iterations of perf testing that isn't part of Geode. >> >> Every Log4j2 Logger used by Geode classes are wrapped inside a FastLogger >> which uses a single volatile for those "isDebugEnabled" checks. If you >> remove this, you will find that the performance of Geode will thank even at >> higher log levels such as INFO. Geode is currently optimized for INFO level >> logging. Without FastLogger, every log statement code path goes down into a >> hot mess of checking filters and performing file checking against >> log4j2.xml (based on a mod so that it only occurs every several log >> statements) to see if it has changed. >> >> Despite this, Log4J2 Core still out performs Logback for "disabled log >> statements" and by this I mean the huge # of debug/trace level statements >> in Geode when running at INFO level. >> >> Unwrapping those "isDebugEnabled" checks will eliminate the optimization >> provided by FastLogger. Without the guard clauses, FastLogger doesn't >> improve anything because the Log4j2 code skips the "isDebugEnabled" checks >> and goes into filter checking which also checks the log level but after >> much more work. My recommendation is to work with Log4j2 project to fix >> this performance problem when using log statements without the FastLogger >> optimizations. For example, Log4j1 used a dedicated async thread for the >> checking of the config file but for some reason they didn't go this route >> in Log4J2. >> >> PS: My Log4J2 code knowledge is a couple of years old so please feel free >> to dig into their code to see if the above issues were fixed. >> >> On Mon, Sep 10, 2018 at 9:35 AM, Galen O'Sullivan <gosulli...@pivotal.io> >> wrote: >> >>> I think that logging in hot paths/loops is probably something that should >>> be avoided. And if it is necessary, I suspect that the JIT will >>> short-circuit that call since debug levels don't generally change. >>> >>> There probably are a few hot paths that need to optimize logging, but >>> that's not the majority. >>> >>> Can we agree to avoid this pattern in new code, since it adversely affects >>> readability? >>> >>> Galen >>> >>> >>> On Fri, Sep 7, 2018 at 1:46 PM, Nicholas Vallely <nvall...@pivotal.io> >>> wrote: >>> >>>> I was just randomly looking into this a couple of days ago as a tangent >>> to >>>> 'observability' and came across this Stack Overflow: >>>> https://stackoverflow.com/questions/6504407/is-there-a-need- >>> to-do-a-iflog- >>>> isdebugenabled-check >>>> where the first answer is the most succinct in my opinion. >>>> >>>> In the geode code that I searched, we are not consistent with our use of >>>> the if(statement) wrapper for debug, though most do have the wrapper. >>>> >>>> Nick >>>> >>>> On Fri, Sep 7, 2018 at 11:35 AM Jacob Barrett <jbarr...@pivotal.io> >>> wrote: >>>> >>>>> Checking with logger.isDebugEnabled() it still a good practice for hot >>>>> paths to avoid the construction of intermediate object arrays to hold >>> the >>>>> var-args. Some logging libraries have fixed argument optimizations for >>>>> var-args up to a specific limit. In very hot paths it is nice to >>>>> check logger.isDebugEnabled() once into a temp boolean value and then >>>> check >>>>> that in all the subsequent debug logging statements in the hot path. >>>>> >>>>> -Jake >>>>> >>>>> >>>>> On Fri, Sep 7, 2018 at 11:18 AM Dan Smith <dsm...@pivotal.io> wrote: >>>>> >>>>>> I think this pattern is a holdover from using log4j 1. In that >>> version, >>>>> you >>>>>> added an if check to avoid unnecessary string concatenation if debug >>>> was >>>>>> enabled. >>>>>> >>>>>> >>>>>> 1. if (logger.isDebugEnabled()) { >>>>>> 2. logger.debug("Logging in user " + user.getName() + " with >>>>>> birthday " + user.getBirthdayCalendar()); >>>>>> 3. } >>>>>> >>>>>> >>>>>> Log4j2 lets you pass a format string, so you can just do this: >>>>>> >>>>>> logger.debug("Logging in user {} with birthday {}", user.getName(), >>>>>> user.getBirthdayCalendar()); >>>>>> >>>>>> >>>>>> These examples come from the log4j2 docs: >>>>>> >>>>>> https://logging.apache.org/log4j/2.0/manual/api.html >>>>>> >>>>>> -Dan >>>>>> >>>>>> On Fri, Sep 7, 2018 at 10:50 AM, Galen O'Sullivan < >>>> gosulli...@apache.org >>>>>> >>>>>> wrote: >>>>>> >>>>>>> Hi all, >>>>>>> >>>>>>> I've noticed a pattern in Geode where we wrap a log call in a >>> check >>>> at >>>>>> the >>>>>>> same level, such as: >>>>>>> >>>>>>> if (logger.isDebugEnabled()) { >>>>>>> logger.debug("cleaning up incompletely started >>>>>>> DistributionManager due to exception", r); >>>>>>> } >>>>>>> >>>>>>> Is there any reason to do this? To my mind, it's an extra >>> conditional >>>>>> that >>>>>>> should essentially be the first check inside `logger.debug(...)` >>>>> anyways, >>>>>>> and it complicates the code and makes it less readable. I've even >>>> seen >>>>>>> places in the code which have `if (logger.isDebugEnabled()) >>>>>>> logger.trace(...))` and such. >>>>>>> >>>>>>> I would like to propose that unless there is a compelling reason >>> to >>>> use >>>>>>> this pattern, we remove all extra checks entirely. >>>>>>> >>>>>>> Galen >>>>>>> >>>>>> >>>>> >>>> >>> >> >>
