perf4j / perf4j Goto Github PK

View Code? Open in Web Editor NEW

293.0 293.0 95.0 700 KB

Performance Monitoring and Statistics for Java Code

Home Page: perf4j.codehaus.org

License: Other

Java 100.00%

perf4j's People

Contributors

Stargazers

Watchers

Forkers

tbuckel javabrett ggrossetie rlamarche jcoder2012 cronik nickman lant zen0wu dcobb ck1125 jameswei caiodangelo fdescamps maciekr achun2080 wenjixin sbert yangfei2012 sovaa hao0111 grahamhorn jiangaimin peidachang snifferhu cheffu jaydusara zeq9069 bsed s12345sk cedricjacquet majiajue davidbate angelbot fengqiao678 jdevhari lanen rgbwoo aakoch tangtangsara hardiku libs4j sobolsigizmund cacling commondwang jerrik123 k0sky xushjie1987 goodsmile guoqp1 mslivonja shaleenmishra appsecai-test cdljsj itgroupcn sun363587351 tqangxl zhouyinyan wangjuntytl tathaibinh peterxiao yanghongkjxy jiangrongbo rbachu leexuehan yajie vanarchi endlessc jlleitschuh chenzujun itstack-org josetesan canismailicoz seustones regapple myakubouski frank4600 krystal-my fengfengsff wilsenwish eliie58 kevinluan anthonydelhelle guanqiao gaoopeng kd23243 chinagui iq-scm zhoufudun javalibrary bulksecuritygeneratorprojectv2

perf4j's Issues

Is this project still alive?

codehaus.org closed, no documentation accessible.

GenericAsyncCoalescingStatisticsAppender.stopDrainingThread may block forever if draining thread is already done

Hello,

we've been stressing perf4j a bit and, sadly, encountered a deadlock where the log4j-config would not finish re-loading, which also meant regular logging calls to log4j were blocked. Here's the stacktrace:

"Timer-Log4jService" daemon prio=6 tid=0x0000000011224000 nid=0x1dfc waiting on condition [0x000000000eebe000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000007ad8f3048> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
        at java.util.concurrent.ArrayBlockingQueue.put(ArrayBlockingQueue.java:324)
        at org.perf4j.helpers.GenericAsyncCoalescingStatisticsAppender.stopDrainingThread(GenericAsyncCoalescingStatisticsAppender.java:279)
        at org.perf4j.helpers.GenericAsyncCoalescingStatisticsAppender.stop(GenericAsyncCoalescingStatisticsAppender.java:269)
        at org.perf4j.log4j.AsyncCoalescingStatisticsAppender.close(AsyncCoalescingStatisticsAppender.java:293)
        at org.apache.log4j.helpers.AppenderAttachableImpl.removeAllAppenders(AppenderAttachableImpl.java:140)
        at org.apache.log4j.Category.removeAllAppenders(Category.java:868)
        - locked <0x0000000784fa5af0> (a org.apache.log4j.Logger)
        at org.apache.log4j.xml.DOMConfigurator.parseChildrenOfLoggerElement(DOMConfigurator.java:410)
        at org.apache.log4j.xml.DOMConfigurator.parseCategory(DOMConfigurator.java:345)
        - locked <0x0000000784fa5af0> (a org.apache.log4j.Logger)
        at org.apache.log4j.xml.DOMConfigurator.parse(DOMConfigurator.java:827)
        at org.apache.log4j.xml.DOMConfigurator.doConfigure(DOMConfigurator.java:712)
        at org.apache.log4j.xml.DOMConfigurator.doConfigure(DOMConfigurator.java:618)
        at org.apache.log4j.xml.DOMConfigurator.configure(DOMConfigurator.java:743)
        at org.jboss.logging.Log4jService$URLWatchTimerTask.reconfigure(Log4jService.java:697)
        at org.jboss.logging.Log4jService$URLWatchTimerTask.run(Log4jService.java:636)
        at java.util.TimerThread.mainLoop(Timer.java:555)
        at java.util.TimerThread.run(Timer.java:505)

   Locked ownable synchronizers:
        - None

Here's such a blocked call, waiting for log4j:

"WorkerThread#1[127.0.0.1:59645]" prio=6 tid=0x0000000022fdf800 nid=0xae0 waiting for monitor entry [0x00000000318bd000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.apache.log4j.Category.callAppenders(Category.java:201)
        - waiting to lock <0x0000000784fa5af0> (a org.apache.log4j.Logger)
        at org.apache.log4j.Category.forcedLog(Category.java:388)
        at org.apache.log4j.Category.log(Category.java:853)
        at org.jboss.logging.log4j.Log4jLoggerPlugin.info(Log4jLoggerPlugin.java:193)
        at org.jboss.logging.Logger.info(Logger.java:307)
        at org.jboss.slf4j.JBossLoggerAdapter.info(JBossLoggerAdapter.java:180)
        at org.perf4j.slf4j.Slf4JStopWatch.log(Slf4JStopWatch.java:407)
        at org.perf4j.slf4j.Slf4JStopWatch.log(Slf4JStopWatch.java:359)
        at org.perf4j.LoggingStopWatch.doLogInternal(LoggingStopWatch.java:238)
        at org.perf4j.LoggingStopWatch.stop(LoggingStopWatch.java:130)
        at org.perf4j.StopWatch.stop(StopWatch.java:209)
        at my.company.PerformanceTestICI.stressPerf4j(PerformanceTestICI.java:37)
        ...

And yes, it's executing a method called stressPerf4j ;)

Which brings us to what I think happened:
We've been stressing perf4j, producing and stopping log4j-stopwatches as fast as possible within our JBoss 5.1. The production of stopwatches is faster than the async thread can process them. Therefore, the queue is full most of the time, and events get dropped. So far this works as designed.

However, we then refreshed the log4j-config a few times. And I think we got into a situation where the old draining thread was already shut down (or had an exception or what do I know) but GenericAsyncCoalescingStatisticsAppender.stopDrainingThread still or again tried to shut it down. However, the queue is full (as there was still a worker thread trying to write to it at full speed), the draining thread already shut down, so the stopDraininingThread-method will block forever when delivering the stopping message "" to the full queue:

private void stopDrainingThread() {
        try {
            //pushing an empty string on the queue tells the draining thread that we're closing
            loggedMessages.put(""); // <---- BLOCKED because the queue was full
            //wait for the draining thread to finish
            drainingThread.join(shutdownWaitMillis); // <---- this would have been more careful, but we never get here
            drainingThread.interrupt();

So this method never gets anywhere.

For completeness sake, there is an active draining thread, but I think it's not the one the stopDrainingMethod is trying to talk to, as it seems to wait on a presumably empty queue:

"perf4j-async-stats-appender-sink-PERF_STATS_AGGREGATOR" daemon prio=6 tid=0x0000000011a9b800 nid=0xf18 waiting on condition [0x000000003124f000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000007de5b1470> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389)
        at org.perf4j.helpers.GenericAsyncCoalescingStatisticsAppender$StopWatchesFromQueueIterator.getNext(GenericAsyncCoalescingStatisticsAppender.java:388)
        at org.perf4j.helpers.GenericAsyncCoalescingStatisticsAppender$StopWatchesFromQueueIterator.hasNext(GenericAsyncCoalescingStatisticsAppender.java:349)
        at org.perf4j.helpers.GroupingStatisticsIterator.getNext(GroupingStatisticsIterator.java:149)
        at org.perf4j.helpers.GroupingStatisticsIterator.hasNext(GroupingStatisticsIterator.java:102)
        at org.perf4j.helpers.GenericAsyncCoalescingStatisticsAppender$Dispatcher.run(GenericAsyncCoalescingStatisticsAppender.java:314)
        at java.lang.Thread.run(Thread.java:744)

   Locked ownable synchronizers:
        - None

I admit, the scenario might have been caused by some wonky reload of the log4j-configuration, but that stopDrainingThread method should not block forever if the thread is not working anymore as intended and the queue has filled up because of that. If I understand things correctly, if there ever is any reason for the draining thread to die, the queue would fill up even under slow load and the next log4j-reload would effectively stop all worker threads indefinitely.

So ... what's a good way to handle this situation and stop the thread reliably?

Regards
Daniel

PS: I'm posting this to perf4j so that people can see this, but the code looks the same in the jperf fork.

AsyncCoalescingStatisticsAppender is not compatible with log4j2

AsyncCoalescingStatisticsAppender is not compatible with log4j2.

This feature works only with logback and log4j (1).

AsyncCoalescingStatisticsAppender causes memory leak

Hi, this could have had a well known work around or is not strictly related to perf4j, but I'm facing a weird issue running a SpringMVC application: whenever I deploy a new version of the WAR, my Tomcat 7 instance prints the following log line and after a while goes into OutOfMemoryError: PermGen space.

SEVERE: The web application [/rest] appears to have started a thread named [perf4j-async-stats-appender-sink-CoalescingStatistics] but has failed to stop it. This is very likely to create a memory leak. ago 31, 2015 6:14:56 PM org.apache.catalina.core.ApplicationContext log

Now, I know I can bump up the PermGen space, but that would be just a temporary workaround and it might work for one or two redeployements.

Is there something I am missing or doing wrong?

Clearly my setup is plain: perf4j and slf4j libraries are hosted within the web application, no specific reference from Spring context to perf4j or slf4j, an AspectJ aspect is used to invoke the StopWatch.

I can publish configuration files if needed, but they are pretty standard ones...

Recommend Projects

React

A declarative, efficient, and flexible JavaScript library for building user interfaces.
Vue.js

🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
Typescript

TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
TensorFlow

An Open Source Machine Learning Framework for Everyone
Django

The Web framework for perfectionists with deadlines.
Laravel

A PHP framework for web artisans
D3

Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

javascript

JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
web

Some thing interesting about web. New door for the world.
server

A server is a program made to process requests and deliver data to clients.
Machine learning

Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
Visualization

Some thing interesting about visualization, use data art
Game

Some thing interesting about game, make everyone happy.

Recommend Org

Facebook

We are working to build community through open source technology. NB: members must have two-factor auth.
Microsoft

Open source projects and samples from Microsoft.
Google

Google ❤️ Open Source for everyone.
Alibaba

Alibaba Open Source for everyone
D3

Data-Driven Documents codes.
Tencent

China tencent open source team.