Any news on this? Ralph
> On Feb 13, 2017, at 5:00 PM, DiFrango, Ronald > <[email protected]> wrote: > > We’re going to try and pull that for you as we’re still working through was > is going on. > > One question, though what would you use in place of the > DefaultRolloverStrategy and max? > > Ron DiFrango > > On 2/13/17, 6:43 PM, "Remko Popma" <[email protected]> wrote: > > I've seen cases where the "max" in <DefaultRolloverStrategy > max="${maxLogFiles}"/> caused issues because the directory contained many > files that all needed to be scanned to see if they matched old log files to > delete. > > That said, it would be good if you can share the results of jstack and do > a run with Java Flight Recorder. > > Sent from my iPhone > >> On Feb 14, 2017, at 8:28, Apache <[email protected]> wrote: >> >> If you are seeing lots of threads can you do a jstack on the process so we >> can see what they are? >> >> Ralph >> >>> On Feb 13, 2017, at 3:50 PM, DiFrango, Ronald >>> <[email protected]> wrote: >>> >>> Our policy generally looks like the following where max log files is 2 and >>> size is 10MB and we 6 appenders configured for various use cases, though >>> the default is WARN so other than our performance logs, nothing is written >>> to at high volume: >>> >>> <RollingRandomAccessFile name="APPLOGFILE" >>> fileName="${base.log.dir}/app.log" >>> >>> filePattern="logs/$${date:yyyy-MM}/app-%d{MM-dd-yyyy}-%i.log.gz" >>> immediateFlush="false" append="true"> >>> <PatternLayout pattern="${appenderPatternLayout}"/> >>> <Policies> >>> <TimeBasedTriggeringPolicy/> >>> <SizeBasedTriggeringPolicy size="${maxLogFileSize}"/> >>> </Policies> >>> <DefaultRolloverStrategy max="${maxLogFiles}"/> >>> </RollingRandomAccessFile> >>> >>> Ron DiFrango >>> >>> On 2/13/17, 3:25 PM, "Matt Sicker" <[email protected]> wrote: >>> >>> If lots of data are being logged really quickly, then I could see that >>> happening. >>> >>>> On 13 February 2017 at 14:20, Apache <[email protected]> wrote: >>>> >>>> The only threads in Log4j that I can think of that are short lived are the >>>> threads that compress the files at rollover. That would only consume a lot >>>> of CPU if rollover is happening a lot. >>>> >>>> Ralph >>>> >>>>> On Feb 13, 2017, at 1:12 PM, Christopher Schultz < >>>> [email protected]> wrote: >>>>> >>>>> Ronald, >>>>> >>>>>> On 2/13/17 2:29 PM, DiFrango, Ronald wrote: >>>>>> Yeah, I’m aware and agreed, but this is done in the Apache HTTP Client >>>> Component’s Code, not ours and existed as-is with log4j2 in ALL the >>>> versions we’ve been using. >>>>>> >>>>>> That said, I think this is a red herring and it’s still true that at >>>> least for our application any version of log4j2 beyond 2.5 consumes more >>>> CPU that 2.5 this is a REST based APi using Tomcat+Jersey+Spring [again >>>> nothing has changed] and processing around 50 transactions per second with >>>> a guarantee of a minimum of 1 log record to request. >>>>>> >>>>>> We just haven’t identified WHERE its causing the issue. >>>>>> >>>>>> One additional data point, we are using the bridging JAR’s for the >>>> following as not all 3rd party libraries follow any standard on what they >>>> use: >>>>>> >>>>>> Classis log4j >>>>>> SLF4J >>>>>> commons-logging >>>>> >>>>> >>>>> You mentioned that lots of threads were being created and that they were >>>>> short-lived. What code is creating those threads? You never said... >>>>> >>>>> -chris >>>>> >>>>>> On 2/13/17, 2:11 PM, "Apache" <[email protected]> wrote: >>>>>> >>>>>> The log.debug call will exit quickly, but if it is constructing a >>>> large message that will happen anyway unless one of the standard techniques >>>> (like wrapping in a logger.isDebugEnabled call) is used to avoid it. >>>> Constructing debug Strings can be expensive. >>>>>> >>>>>> Ralph >>>>>> >>>>>>> On Feb 13, 2017, at 10:58 AM, DiFrango, Ronald < >>>> [email protected]> wrote: >>>>>>> >>>>>>> No we are not and since it’s a log.debug() it should just get dropped >>>> on the floor before any sort of copying occurs, right? >>>>>>> >>>>>>> Ron DiFrango >>>>>>> >>>>>>> On 2/13/17, 12:50 PM, "Matt Sicker" <[email protected]> wrote: >>>>>>> >>>>>>> Are you logging that info? >>>>>>> >>>>>>> On 13 February 2017 at 11:46, DiFrango, Ronald < >>>>>>> [email protected]> wrote: >>>>>>> >>>>>>>> All, >>>>>>>> >>>>>>>> One thing we just noticed is that we are using Apache’s HTTP >>>> connection >>>>>>>> pooling for our downstream calls and in our latest performance run is >>>> that >>>>>>>> the READ operation on org.apache.http.impl.conn.LoggingInputStream >>>> seems >>>>>>>> to be taking a bulk of the time. >>>>>>>> >>>>>>>> If I look at the code, once the HTTP client reads the byte stream it >>>>>>>> issues a log.debug which could be a large payload, I wonder if that’s >>>> what >>>>>>>> is causing the issue? >>>>>>>> >>>>>>>> Please note aware, the version of httpclient we’ve been using has also >>>>>>>> been constant: >>>>>>>> >>>>>>>> <dependency> >>>>>>>> <groupId>org.apache.httpcomponents</groupId> >>>>>>>> <artifactId>httpclient</artifactId> >>>>>>>> <version>4.5.2</version> >>>>>>>> </dependency> >>>>>>>> >>>>>>>> Ron DiFrango >>>>>>>> >>>>>>>> >>>>>>>> On 2/13/17, 11:44 AM, "DiFrango, Ronald" <Ronald.DiFrango@capitalone. >>>> com> >>>>>>>> wrote: >>>>>>>> >>>>>>>> This is running in Tomcat 8.0.33 in a Docker Container via AWS’s ECS >>>>>>>> which is identical to before with log4j2 2.5. >>>>>>>> >>>>>>>> We’ve run the application with Visual VM and the one thing for sure >>>>>>>> that we’ve seen is that in 2.6.2 it created tons of threads, >>>> something like >>>>>>>> 50+ but on 2.6 or 2.7 it was only 2. Now the threads were short >>>> lived, but >>>>>>>> they got created. >>>>>>>> >>>>>>>> We’re running another performance test today with Async loggers to >>>> see >>>>>>>> if that helps or exhibits the same thing though previous testing with >>>> Async >>>>>>>> had some of the same char >>>>>>>> >>>>>>>> Here’s our layout pattern: >>>>>>>> >>>>>>>> [%t] %d{DATE} %-5p %-15c{1} [%X]: %cm%n >>>>>>>> >>>>>>>> Please not the %cm is a custom message handler that we use to use to >>>>>>>> handle security filtering of the message payload aka we extend from >>>>>>>> LogEventPatternConverter. >>>>>>>> >>>>>>>> Thanks, >>>>>>>> >>>>>>>> Ron DiFrango >>>>>>>> >>>>>>>> On 2/13/17, 11:22 AM, "Matt Sicker" <[email protected]> wrote: >>>>>>>> >>>>>>>> What server environment are you running this in? >>>>>>>> >>>>>>>> On 13 February 2017 at 09:19, Remko Popma < >>>> [email protected]> >>>>>>>> wrote: >>>>>>>> >>>>>>>>> Ron, >>>>>>>>> >>>>>>>>> We haven't heard of any issues like you describe. >>>>>>>>> Have you tried running your application with Java Flight Recorder >>>>>>>>> <https://docs.oracle.com/javacomponents/jmc-5-4/jfr- >>>>>>>>> runtime-guide/run.htm#JFRUH176>? >>>>>>>>> This should help diagnose what is going on. >>>>>>>>> >>>>>>>>> Remko >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> On Mon, Feb 13, 2017 at 9:59 PM, DiFrango, Ronald < >>>>>>>>> [email protected]> wrote: >>>>>>>>> >>>>>>>>>> All, >>>>>>>>>> >>>>>>>>>> We recently upgrade to 2.6 and noticed a dramatic increase in >>>>>>>> CPU and >>>>>>>>>> Thread utilization that seems to be tied to the new “garbage >>>>>>>> free” mode >>>>>>>>> of >>>>>>>>>> log4j 2.6. Here’s some of the baseline numbers: >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> · Log4j 2.5: CPU typically ran around 25% >>>>>>>>>> >>>>>>>>>> · Log4j 2.6: CPU typically ran around 75% >>>>>>>>>> >>>>>>>>>> · Log4j 2.6.2+: CPU typically ran around 100% >>>>>>>>>> >>>>>>>>>> · We’ve also tried turning off garbage free mode and >>>>>>>> that made >>>>>>>>>> things worse as the CPU was around 120% and caused us to not >>>>>>>> meet our >>>>>>>>> SLA’s >>>>>>>>>> >>>>>>>>>> It important to note that this is a REST Api using Jersey and >>>>>>>> typically >>>>>>>>>> responds in about in under 50ms on a per request so its high >>>>>>>> volume, but >>>>>>>>>> the logging level is WARN or higher except for our single >>>>>>>> performance log >>>>>>>>>> record which is written once per request using the lambda base >>>>>>>> approach. >>>>>>>>>> >>>>>>>>>> Our next test is going to be switching to all ASYNC loggers >>>>>>>> and see what >>>>>>>>>> effect that has, but I guess the general question is, has >>>>>>>> anyone else >>>>>>>>> seen >>>>>>>>>> this? Any thoughts? >>>>>>>>>> >>>>>>>>>> Ron DiFrango >>>>>>>>>> ________________________________________________________ >>>>>>>>>> >>>>>>>>>> The information contained in this e-mail is confidential and/or >>>>>>>>>> proprietary to Capital One and/or its affiliates and may only >>>>>>>> be used >>>>>>>>>> solely in performance of work or services for Capital One. The >>>>>>>>> information >>>>>>>>>> transmitted herewith is intended only for use by the >>>>>>>> individual or entity >>>>>>>>>> to which it is addressed. If the reader of this message is not >>>>>>>> the >>>>>>>>> intended >>>>>>>>>> recipient, you are hereby notified that any review, >>>>>>>> retransmission, >>>>>>>>>> dissemination, distribution, copying or other use of, or >>>>>>>> taking of any >>>>>>>>>> action in reliance upon this information is strictly >>>>>>>> prohibited. If you >>>>>>>>>> have received this communication in error, please contact the >>>>>>>> sender and >>>>>>>>>> delete the material from your computer. >>>>>>>>>> >>>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> -- >>>>>>>> Matt Sicker <[email protected]> >>>>>>>> >>>>>>>> >>>>>>>> ________________________________________________________ >>>>>>>> >>>>>>>> The information contained in this e-mail is confidential and/or >>>>>>>> proprietary to Capital One and/or its affiliates and may only be used >>>>>>>> solely in performance of work or services for Capital One. The >>>> information >>>>>>>> transmitted herewith is intended only for use by the individual or >>>> entity >>>>>>>> to which it is addressed. If the reader of this message is not the >>>> intended >>>>>>>> recipient, you are hereby notified that any review, retransmission, >>>>>>>> dissemination, distribution, copying or other use of, or taking of any >>>>>>>> action in reliance upon this information is strictly prohibited. If >>>> you >>>>>>>> have received this communication in error, please contact the sender >>>> and >>>>>>>> delete the material from your computer. >>>>>>>> >>>>>>>> ------------------------------------------------------------ >>>> --------- >>>>>>>> To unsubscribe, e-mail: [email protected] >>>>>>>> For additional commands, e-mail: [email protected] >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> ________________________________________________________ >>>>>>>> >>>>>>>> The information contained in this e-mail is confidential and/or >>>>>>>> proprietary to Capital One and/or its affiliates and may only be used >>>>>>>> solely in performance of work or services for Capital One. The >>>> information >>>>>>>> transmitted herewith is intended only for use by the individual or >>>> entity >>>>>>>> to which it is addressed. If the reader of this message is not the >>>> intended >>>>>>>> recipient, you are hereby notified that any review, retransmission, >>>>>>>> dissemination, distribution, copying or other use of, or taking of any >>>>>>>> action in reliance upon this information is strictly prohibited. If >>>> you >>>>>>>> have received this communication in error, please contact the sender >>>> and >>>>>>>> delete the material from your computer. >>>>>>>> >>>>>>>> --------------------------------------------------------------------- >>>>>>>> To unsubscribe, e-mail: [email protected] >>>>>>>> For additional commands, e-mail: [email protected] >>>>>>>> >>>>>>>> >>>>>>> >>>>>>> >>>>>>> -- >>>>>>> Matt Sicker <[email protected]> >>>>>>> >>>>>>> >>>>>>> ________________________________________________________ >>>>>>> >>>>>>> The information contained in this e-mail is confidential and/or >>>> proprietary to Capital One and/or its affiliates and may only be used >>>> solely in performance of work or services for Capital One. The information >>>> transmitted herewith is intended only for use by the individual or entity >>>> to which it is addressed. If the reader of this message is not the intended >>>> recipient, you are hereby notified that any review, retransmission, >>>> dissemination, distribution, copying or other use of, or taking of any >>>> action in reliance upon this information is strictly prohibited. If you >>>> have received this communication in error, please contact the sender and >>>> delete the material from your computer. >>>>>>> >>>>>>> --------------------------------------------------------------------- >>>>>>> To unsubscribe, e-mail: [email protected] >>>>>>> For additional commands, e-mail: [email protected] >>>>>>> >>>>>> >>>>>> >>>>>> >>>>>> ------------------------------------------------------------ >>>> --------- >>>>>> To unsubscribe, e-mail: [email protected] >>>>>> For additional commands, e-mail: [email protected] >>>>>> >>>>>> >>>>>> >>>>>> ________________________________________________________ >>>>>> >>>>>> The information contained in this e-mail is confidential and/or >>>> proprietary to Capital One and/or its affiliates and may only be used >>>> solely in performance of work or services for Capital One. The information >>>> transmitted herewith is intended only for use by the individual or entity >>>> to which it is addressed. If the reader of this message is not the intended >>>> recipient, you are hereby notified that any review, retransmission, >>>> dissemination, distribution, copying or other use of, or taking of any >>>> action in reliance upon this information is strictly prohibited. If you >>>> have received this communication in error, please contact the sender and >>>> delete the material from your computer. >>>>>> >>>>>> --------------------------------------------------------------------- >>>>>> To unsubscribe, e-mail: [email protected] >>>>>> For additional commands, e-mail: [email protected] >>>>>> >>>>> >>>> >>>> >>>> >>>> --------------------------------------------------------------------- >>>> To unsubscribe, e-mail: [email protected] >>>> For additional commands, e-mail: [email protected] >>>> >>>> >>> >>> >>> -- >>> Matt Sicker <[email protected]> >>> >>> >>> ________________________________________________________ >>> >>> The information contained in this e-mail is confidential and/or proprietary >>> to Capital One and/or its affiliates and may only be used solely in >>> performance of work or services for Capital One. The information >>> transmitted herewith is intended only for use by the individual or entity >>> to which it is addressed. If the reader of this message is not the intended >>> recipient, you are hereby notified that any review, retransmission, >>> dissemination, distribution, copying or other use of, or taking of any >>> action in reliance upon this information is strictly prohibited. If you >>> have received this communication in error, please contact the sender and >>> delete the material from your computer. >>> >>> --------------------------------------------------------------------- >>> To unsubscribe, e-mail: [email protected] >>> For additional commands, e-mail: [email protected] >>> >> >> >> >> --------------------------------------------------------------------- >> To unsubscribe, e-mail: [email protected] >> For additional commands, e-mail: [email protected] >> > > --------------------------------------------------------------------- > To unsubscribe, e-mail: [email protected] > For additional commands, e-mail: [email protected] > > > > ________________________________________________________ > > The information contained in this e-mail is confidential and/or proprietary > to Capital One and/or its affiliates and may only be used solely in > performance of work or services for Capital One. The information transmitted > herewith is intended only for use by the individual or entity to which it is > addressed. If the reader of this message is not the intended recipient, you > are hereby notified that any review, retransmission, dissemination, > distribution, copying or other use of, or taking of any action in reliance > upon this information is strictly prohibited. If you have received this > communication in error, please contact the sender and delete the material > from your computer. > > --------------------------------------------------------------------- > To unsubscribe, e-mail: [email protected] > For additional commands, e-mail: [email protected] > --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
