AdamBien / lightfish

Payara / GlassFish Monitoring Utility
121 stars 41 forks source link

Lightfish doesn't work on GF 4.1 #27

Closed baztian closed 8 years ago

baztian commented 9 years ago

The following issue does only happen on GF 4.1 and not on 4.01! When I activate the lightfish timer I notice lightfish gradually stuggles to answer request to http://localhost:8080/lightfish/. The longer I wait the longer it takes to answer. After a while (couple of minutes) I get an OutOfMemoryError. Under the exact same configuration it works on GF 4.01.

server.log:

[2015-04-01T12:13:45.136+0200] [glassfish 4.1] [INFO] [] [org.lightfish.business.servermonitoring.control.collectors.AbstractRestDataCollector] [tid: _ThreadID=147 _ThreadName=__ejb-thread-pool16] [timeMillis: 1427883225136] [levelValue: 800] [[
  Retrieved JsonObject: {"unit":"String","current":"None of the threads are deadlocked.","lastsampletime":1427883224614,"name":"DeadlockedThreads","description":"Finds cycles of threads that are in deadlock waiting to acquire object monitors or ownable synchronizers","starttime":1427878699953} for InboundJaxrsResponse{ClientResponse{method=GET, uri=http://localhost:4848/monitoring/domain/server/jvm/thread-system/deadlockedthreads, status=200, reason=OK}} deadlockedthreads]]

[2015-04-01T12:13:48.249+0200] [glassfish 4.1] [WARNING] [AS-EJB-00056] [javax.enterprise.ejb.container] [tid: _ThreadID=147 _ThreadName=__ejb-thread-pool16] [timeMillis: 1427883228249] [levelValue: 900] [[
  A system exception occurred during an invocation on EJB ParallelDataCollectionAction, method: public java.util.concurrent.Future org.lightfish.business.servermonitoring.control.collectors.ParallelDataCollectionAction.compute(org.lightfish.business.servermonitoring.control.collectors.DataCollector)]]

[2015-04-01T12:13:48.249+0200] [glassfish 4.1] [WARNING] [] [javax.enterprise.ejb.container] [tid: _ThreadID=147 _ThreadName=__ejb-thread-pool16] [timeMillis: 1427883228249] [levelValue: 900] [[

javax.ejb.EJBException
    at com.sun.ejb.containers.EJBContainerTransactionManager.processSystemException(EJBContainerTransactionManager.java:748)
    at com.sun.ejb.containers.EJBContainerTransactionManager.completeNewTx(EJBContainerTransactionManager.java:698)
    at com.sun.ejb.containers.EJBContainerTransactionManager.postInvokeTx(EJBContainerTransactionManager.java:503)
    at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4566)
    at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2074)
    at com.sun.ejb.containers.EjbAsyncTask.call(EjbAsyncTask.java:114)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.OutOfMemoryError: GC overhead limit exceeded
]]

[2015-04-01T12:13:48.696+0200] [glassfish 4.1] [SEVERE] [] [org.lightfish.business.servermonitoring.boundary.MonitoringController] [tid: _ThreadID=110 _ThreadName=__ejb-thread-pool1] [timeMillis: 1427883228696] [levelValue: 1000] [[
  The snapshot collection for server resulted in an exception
java.util.concurrent.ExecutionException: javax.ejb.EJBException
    at com.sun.ejb.containers.EjbAsyncTask.call(EjbAsyncTask.java:132)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: javax.ejb.EJBException
    at com.sun.ejb.containers.EJBContainerTransactionManager.processSystemException(EJBContainerTransactionManager.java:748)
    at com.sun.ejb.containers.EJBContainerTransactionManager.completeNewTx(EJBContainerTransactionManager.java:698)
    at com.sun.ejb.containers.EJBContainerTransactionManager.postInvokeTx(EJBContainerTransactionManager.java:503)
    at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4566)
    at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2074)
    at com.sun.ejb.containers.EjbAsyncTask.call(EjbAsyncTask.java:114)
    ... 4 more
Caused by: java.lang.OutOfMemoryError: GC overhead limit exceeded
]]

[2015-04-01T12:13:48.696+0200] [glassfish 4.1] [INFO] [] [org.lightfish.business.servermonitoring.boundary.MonitoringController] [tid: _ThreadID=110 _ThreadName=__ejb-thread-pool1] [timeMillis: 1427883228696] [levelValue: 800] [[
  All snapshots collected for this round!]]

[2015-04-01T12:13:51.072+0200] [glassfish 4.1] [WARNING] [AS-EJB-00056] [javax.enterprise.ejb.container] [tid: _ThreadID=110 _ThreadName=__ejb-thread-pool1] [timeMillis: 1427883231072] [levelValue: 900] [[
  A system exception occurred during an invocation on EJB MonitoringController, method: public void org.lightfish.business.servermonitoring.boundary.MonitoringController.gatherAndPersist()]]

[2015-04-01T12:13:51.073+0200] [glassfish 4.1] [WARNING] [] [javax.enterprise.ejb.container] [tid: _ThreadID=110 _ThreadName=__ejb-thread-pool1] [timeMillis: 1427883231073] [levelValue: 900] [[

javax.ejb.EJBException
    at com.sun.ejb.containers.EJBContainerTransactionManager.processSystemException(EJBContainerTransactionManager.java:748)
    at com.sun.ejb.containers.EJBContainerTransactionManager.completeNewTx(EJBContainerTransactionManager.java:698)
    at com.sun.ejb.containers.EJBContainerTransactionManager.postInvokeTx(EJBContainerTransactionManager.java:503)
    at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4566)
    at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2074)
    at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2044)
    at com.sun.ejb.containers.BaseContainer.callEJBTimeout(BaseContainer.java:4080)
    at com.sun.ejb.containers.EJBTimerService.deliverTimeout(EJBTimerService.java:1199)
    at com.sun.ejb.containers.EJBTimerService.access$000(EJBTimerService.java:89)
    at com.sun.ejb.containers.EJBTimerService$TaskExpiredWork.run(EJBTimerService.java:1919)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.OutOfMemoryError: GC overhead limit exceeded
]]

[2015-04-01T12:13:56.825+0200] [glassfish 4.1] [INFO] [] [] [tid: _ThreadID=146 _ThreadName=Thread-8] [timeMillis: 1427883236825] [levelValue: 800] [[
  New beat received]]

[2015-04-01T12:13:57.313+0200] [glassfish 4.1] [WARNING] [] [org.lightfish.business.servermonitoring.boundary.MonitoringController] [tid: _ThreadID=146 _ThreadName=__ejb-thread-pool15] [timeMillis: 1427883237313] [levelValue: 900] [[
  It appears you changed the server instances you are monitoring while the timer is running, this is not recommended...]]

[2015-04-01T12:13:57.313+0200] [glassfish 4.1] [INFO] [] [org.lightfish.business.servermonitoring.boundary.MonitoringController] [tid: _ThreadID=146 _ThreadName=__ejb-thread-pool15] [timeMillis: 1427883237313] [levelValue: 800] [[
  Nothing todo, no data to collect]]

[2015-04-01T12:13:57.313+0200] [glassfish 4.1] [INFO] [] [org.lightfish.business.servermonitoring.boundary.MonitoringController] [tid: _ThreadID=146 _ThreadName=__ejb-thread-pool15] [timeMillis: 1427883237313] [levelValue: 800] [[

Unfortunately I couldn't find any open GF bugs addressing this.

Do you need extra information? I could provide data from visualvm.

baztian commented 9 years ago

A nice colleague of mine did analyze the following: Weld Versions: in GF 4.0.1 – 2.0.0 in GF 4.1 – 2.2.2

(MAT analysis) Leak: One instance of "java.util.Collections$SynchronizedRandomAccessList" loaded by "" occupies 267.971.808 (75,86%) bytes. The instance is referenced by org.jboss.weld.context.CreationalContextImpl @ 0xe507f340 , loaded by "org.apache.felix.framework.BundleWiringImpl$BundleClassLoaderJava5 @ 0xe1d81030". The memory is accumulated in one instance of "java.lang.Object[]" loaded by "".

lightfishissue27

baztian commented 9 years ago

I've created a Glassfish issue: https://java.net/jira/browse/GLASSFISH-21351

AdamBien commented 8 years ago

New releases 1.3.2+ are more stable and require less resources. Please reopen if the problem persists. New releases are tested with Payara.