Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Out of memory after number of redeployments #4098

Closed
peterpz1 opened this issue Jul 22, 2019 · 22 comments · Fixed by #5081 or #6677
Closed

Out of memory after number of redeployments #4098

peterpz1 opened this issue Jul 22, 2019 · 22 comments · Fixed by #5081 or #6677
Assignees
Labels
Type: Bug Label issue as a bug defect

Comments

@peterpz1
Copy link

Description


On our preprod env after a couple tenths of redeployments instances are lacking memory and have to be killed manually from OS. Problem is reproduced on two separate environments.

Expected Outcome

No out of memory error.

Current Outcome

2019-07-22 11:50:12 WARNING [org.apache.catalina.core.ApplicationDispatcher doInvoke] Servlet.service() for servlet Faces Servlet threw exception
java.lang.OutOfMemoryError: Java heap space

2019-07-22 11:50:12 WARNING [org.apache.catalina.core.ApplicationDispatcher doInvoke] Servlet.service() for servlet Faces Servlet threw exception
java.lang.OutOfMemoryError: Java heap space

2019-07-22 11:50:06 WARNING [com.sun.enterprise.web.logger.CatalinaLogger write] StandardWrapperValve[Faces Servlet]: Servlet.service() for servlet Faces Servlet threw exception
java.lang.OutOfMemoryError: Java heap space

2019-07-22 11:50:12 WARNING [com.sun.enterprise.web.logger.CatalinaLogger write] org.apache.catalina.core.StandardHostValve@409d228: Exception Processing ErrorPage[errorCode=500, location=/WEB-INF/error_500.html]
javax.servlet.ServletException: Java heap space
	at javax.faces.webapp.FacesServlet.executeLifecyle(FacesServlet.java:725)
	at javax.faces.webapp.FacesServlet.service(FacesServlet.java:451)
	at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1628)
	at org.apache.catalina.core.ApplicationDispatcher.doInvoke(ApplicationDispatcher.java:824)
	at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:688)
	at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:527)
	at org.apache.catalina.core.ApplicationDispatcher.doDispatch(ApplicationDispatcher.java:496)
	at org.apache.catalina.core.ApplicationDispatcher.dispatch(ApplicationDispatcher.java:378)
	at org.apache.catalina.core.StandardHostValve.custom(StandardHostValve.java:507)
	at org.apache.catalina.core.StandardHostValve.dispatchToErrorPage(StandardHostValve.java:701)
	at org.apache.catalina.core.StandardHostValve.status(StandardHostValve.java:385)
	at org.apache.catalina.core.StandardHostValve.throwable(StandardHostValve.java:319)
	at org.apache.catalina.core.StandardHostValve.postInvoke(StandardHostValve.java:217)
	at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:373)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:238)
	at com.sun.enterprise.v3.services.impl.ContainerMapper$HttpHandlerCallable.call(ContainerMapper.java:520)
	at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:217)
	at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:182)
	at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:156)
	at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:218)
	at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:95)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:260)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:177)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:109)
	at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:88)
	at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:53)
	at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:524)
	at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:89)
	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:94)
	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$0(WorkerThreadIOStrategy.java:90)
	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:114)
	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:569)
	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:549)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.OutOfMemoryError: Java heap space
----- Root Cause -----
java.lang.OutOfMemoryError: Java heap space

Steps to reproduce (Only for bug reports)

Start the deployment group, perform multiple redeployments of your application and at some time the error will occur.

Environment

  • Payara Version: 5.191
  • Edition: Full
  • JDK Version: zulu8.38.0.13-ca-jre8.0.212-linux_x64
  • Operating System: RHEL
  • Instances memory: -Xmx2g
@smillidge
Copy link
Contributor

How do you know this is caused by Payara and not your application. Have you looked at what objects are causing the OOME?

@rdebusscher
Copy link

Closing as not responsive.

@sgflt
Copy link
Contributor

sgflt commented Jan 4, 2020

Could we reopen this issue? I have been curious and tried https://github.com/sgflt/payara-test-case on Payara 5.194.

Memory leak is clearly visible after many redeployments:
for i in {1..100}; do /app/bin/payara5/bin/asadmin redeploy --name test-case-0 ~/git/payara-test-case/ear/target/test-case-0.ear; done

Most of created instances came from Felix as java-util.HashMap$Node referenced by

m_felix in org.apache.felix.framework.FrameworkWiringImpl#1 [GC root - Java frame]

Snímek obrazovky pořízený 2020-01-04 12-45-11

Also classes seems to be loaded permanently as count of loaded classes is constantly growing.

@smillidge
Copy link
Contributor

I did our usual classloader leak test. Deployed the application, heap dumped the server and looked for EarClassLoader instances and WebAppClassLoader instances for the application. Undeployed the application and forced GC a few times then heap dumped again and the relevant classloaders are gone. So I don't think we have a classloader leak. You need to ensure there is a full GC to unload classes so not sure whether in the image above that has happened.

@sgflt
Copy link
Contributor

sgflt commented Dec 23, 2020

Linking with #5063 that may reveal the cause. (tested on 5.2020.7 and still getting OOM after some count of redeployments)

@sgflt
Copy link
Contributor

sgflt commented Dec 30, 2020

Leak is probably caused by ServiceLocatorImpl with name "__HK2_Generated_0".
Count of ((IndexedListData)((ServiceLocatorImpl)this).allDescriptors).unsortedList is constantly increasing.

[MARKED] addConfigurationInternal:1893, ServiceLocatorImpl (org.jvnet.hk2.internal)
[MARKED] addConfiguration:2113, ServiceLocatorImpl (org.jvnet.hk2.internal)
commit:262, DynamicConfigurationImpl (org.jvnet.hk2.internal)
addOneDescriptor:344, ServiceLocatorUtilities (org.glassfish.hk2.utilities)
addOneDescriptor:303, ServiceLocatorUtilities (org.glassfish.hk2.utilities)
addWithAlias:567, Dom (org.jvnet.hk2.config)
insertAfter:602, Dom (org.jvnet.hk2.config)
add:462, ConfigModel$CollectionNode$1 (org.jvnet.hk2.config)
add:108, AbstractList (java.util)
commitListChanges:419, WriteableView (org.jvnet.hk2.config)
commit:400, WriteableView (org.jvnet.hk2.config)
commit:114, Transaction (org.jvnet.hk2.config)
registerAppInDomainXML:1467, ApplicationLifecycle (com.sun.enterprise.v3.server)
registerAppInDomainXML:1349, ApplicationLifecycle (com.sun.enterprise.v3.server)
execute:616, DeployCommand (org.glassfish.deployment.admin)
run:556, CommandRunnerImpl$2$1 (com.sun.enterprise.v3.admin)
run:552, CommandRunnerImpl$2$1 (com.sun.enterprise.v3.admin)
doPrivileged:-1, AccessController (java.security)
doAs:360, Subject (javax.security.auth)
execute:551, CommandRunnerImpl$2 (com.sun.enterprise.v3.admin)
run:582, CommandRunnerImpl$3 (com.sun.enterprise.v3.admin)
run:574, CommandRunnerImpl$3 (com.sun.enterprise.v3.admin)
doPrivileged:-1, AccessController (java.security)
doAs:360, Subject (javax.security.auth)
doCommand:573, CommandRunnerImpl (com.sun.enterprise.v3.admin)
doCommand:1497, CommandRunnerImpl (com.sun.enterprise.v3.admin)
access$1300:120, CommandRunnerImpl (com.sun.enterprise.v3.admin)
execute:1879, CommandRunnerImpl$ExecutionContext (com.sun.enterprise.v3.admin)
execute:1755, CommandRunnerImpl$ExecutionContext (com.sun.enterprise.v3.admin)
execute:129, ReDeployCommand (org.glassfish.deployment.admin)
run:556, CommandRunnerImpl$2$1 (com.sun.enterprise.v3.admin)
run:552, CommandRunnerImpl$2$1 (com.sun.enterprise.v3.admin)
doPrivileged:-1, AccessController (java.security)
doAs:360, Subject (javax.security.auth)
execute:551, CommandRunnerImpl$2 (com.sun.enterprise.v3.admin)
run:582, CommandRunnerImpl$3 (com.sun.enterprise.v3.admin)
run:574, CommandRunnerImpl$3 (com.sun.enterprise.v3.admin)
doPrivileged:-1, AccessController (java.security)
doAs:360, Subject (javax.security.auth)
doCommand:573, CommandRunnerImpl (com.sun.enterprise.v3.admin)
doCommand:1497, CommandRunnerImpl (com.sun.enterprise.v3.admin)
access$1300:120, CommandRunnerImpl (com.sun.enterprise.v3.admin)
execute:1879, CommandRunnerImpl$ExecutionContext (com.sun.enterprise.v3.admin)
execute:1755, CommandRunnerImpl$ExecutionContext (com.sun.enterprise.v3.admin)
executeCommand:409, CommandResource (org.glassfish.admin.rest.resources.admin)
execCommandSimpInMultOut:236, CommandResource (org.glassfish.admin.rest.resources.admin)
invoke:-1, GeneratedMethodAccessor441 (sun.reflect)
invoke:43, DelegatingMethodAccessorImpl (sun.reflect)
invoke:498, Method (java.lang.reflect)
lambda$static$0:52, ResourceMethodInvocationHandlerFactory (org.glassfish.jersey.server.model.internal)
invoke:-1, 610366744 (org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$$Lambda$1483)
run:124, AbstractJavaResourceMethodDispatcher$1 (org.glassfish.jersey.server.model.internal)
invoke:167, AbstractJavaResourceMethodDispatcher (org.glassfish.jersey.server.model.internal)
doDispatch:176, JavaResourceMethodDispatcherProvider$ResponseOutInvoker (org.glassfish.jersey.server.model.internal)
dispatch:79, AbstractJavaResourceMethodDispatcher (org.glassfish.jersey.server.model.internal)
invoke:469, ResourceMethodInvoker (org.glassfish.jersey.server.model)
apply:391, ResourceMethodInvoker (org.glassfish.jersey.server.model)
apply:80, ResourceMethodInvoker (org.glassfish.jersey.server.model)
run:253, ServerRuntime$1 (org.glassfish.jersey.server)
call:248, Errors$1 (org.glassfish.jersey.internal)
call:244, Errors$1 (org.glassfish.jersey.internal)
process:292, Errors (org.glassfish.jersey.internal)
process:274, Errors (org.glassfish.jersey.internal)
process:244, Errors (org.glassfish.jersey.internal)
runInScope:265, RequestScope (org.glassfish.jersey.process.internal)
process:232, ServerRuntime (org.glassfish.jersey.server)
handle:680, ApplicationHandler (org.glassfish.jersey.server)
service:356, GrizzlyHttpContainer (org.glassfish.jersey.grizzly2.httpserver)
service:179, JerseyContainerCommandService$3 (org.glassfish.admin.rest.adapter)
service:189, RestAdapter (org.glassfish.admin.rest.adapter)
call:520, ContainerMapper$HttpHandlerCallable (com.sun.enterprise.v3.services.impl)
service:217, ContainerMapper (com.sun.enterprise.v3.services.impl)
runService:182, HttpHandler (org.glassfish.grizzly.http.server)
doHandle:156, HttpHandler (org.glassfish.grizzly.http.server)
handleRead:218, HttpServerFilter (org.glassfish.grizzly.http.server)
execute:95, ExecutorResolver$9 (org.glassfish.grizzly.filterchain)
executeFilter:260, DefaultFilterChain (org.glassfish.grizzly.filterchain)
executeChainPart:177, DefaultFilterChain (org.glassfish.grizzly.filterchain)
execute:109, DefaultFilterChain (org.glassfish.grizzly.filterchain)
process:88, DefaultFilterChain (org.glassfish.grizzly.filterchain)
execute:53, ProcessorExecutor (org.glassfish.grizzly)
fireIOEvent:524, TCPNIOTransport (org.glassfish.grizzly.nio.transport)
fireIOEvent:89, AbstractIOStrategy (org.glassfish.grizzly.strategies)
run0:94, WorkerThreadIOStrategy (org.glassfish.grizzly.strategies)
access$100:33, WorkerThreadIOStrategy (org.glassfish.grizzly.strategies)
run:114, WorkerThreadIOStrategy$WorkerThreadRunnable (org.glassfish.grizzly.strategies)
doWork:569, AbstractThreadPool$Worker (org.glassfish.grizzly.threadpool)
run:549, AbstractThreadPool$Worker (org.glassfish.grizzly.threadpool)
run:748, Thread (java.lang)

@lprimak
Copy link
Contributor

lprimak commented Dec 30, 2020

@sgflt since you are looking at it, any chance you can pinpoint the source of the leak in non-generated code?
I am seeing a leak with the new leak tester, but am not yet looking for a source of the leak (got holiday + more high-priority projects before I can look at this)

@sgflt
Copy link
Contributor

sgflt commented Dec 30, 2020

Yes, another candidate is org.glassfish.deployment.admin.DeployCommand. Retained size is about 230 MB.

@lprimak
Copy link
Contributor

lprimak commented Dec 30, 2020

Something is not deleting a reference to the class loader and this what's causing redeploy leak, and needs to be pinpointed / fixed. Anything else would be a small leak

@sgflt
Copy link
Contributor

sgflt commented Dec 30, 2020

Tracked GC root to archiveMetaData in com.sun.enterprise.deploy.shared.FileArchive#440 [GC root - Java frame]

@lprimak lprimak reopened this Dec 30, 2020
@sgflt
Copy link
Contributor

sgflt commented Dec 30, 2020

There is some relation between FileArchive.archiveMetaData -> DeployCommand.report -> PropsFileActionReporter.subAction -> DeployCommandSupplementalInfo.dc -> DeploymentContextImpl.source -> FileArchive.archiveMetadata again

@lprimak lprimak self-assigned this Dec 30, 2020
@sgflt
Copy link
Contributor

sgflt commented Dec 31, 2020

I was able to cut out some fields. Now the leak is not so fast, but still present. All fixed places used nested classes.

@sgflt
Copy link
Contributor

sgflt commented Dec 31, 2020

And the way turned into ServiceLocatorImpl back again. Now stored in static field in Globals with nice comment: "Very sensitive class, anything stored here cannot be garbage collected"

@sgflt
Copy link
Contributor

sgflt commented Dec 31, 2020

I think Globals are the main cause. All places I have fixed was Services instantiated by ServiceLocator.

@sgflt
Copy link
Contributor

sgflt commented Dec 31, 2020

Yes. Each redeploy puts some descriptors into default service locator, but undeploy does not call shutdown nor unregisters its own descriptors from default service locator, so count of initialized services is unstopably growing.

Insertion stacktrace:

addConfigurationInternal:1893, ServiceLocatorImpl (org.jvnet.hk2.internal)
addConfiguration:2113, ServiceLocatorImpl (org.jvnet.hk2.internal)
commit:262, DynamicConfigurationImpl (org.jvnet.hk2.internal)
addOneDescriptor:344, ServiceLocatorUtilities (org.glassfish.hk2.utilities)
addOneDescriptor:303, ServiceLocatorUtilities (org.glassfish.hk2.utilities)
addWithAlias:562, Dom (org.jvnet.hk2.config)
insertAfter:602, Dom (org.jvnet.hk2.config)
add:462, ConfigModel$CollectionNode$1 (org.jvnet.hk2.config)
add:108, AbstractList (java.util)
commitListChanges:419, WriteableView (org.jvnet.hk2.config)
commit:400, WriteableView (org.jvnet.hk2.config)
commit:114, Transaction (org.jvnet.hk2.config)
registerAppInDomainXML:1467, ApplicationLifecycle (com.sun.enterprise.v3.server)
registerAppInDomainXML:1349, ApplicationLifecycle (com.sun.enterprise.v3.server)
execute:615, DeployCommand (org.glassfish.deployment.admin)
run:556, CommandRunnerImpl$2$1 (com.sun.enterprise.v3.admin)
run:552, CommandRunnerImpl$2$1 (com.sun.enterprise.v3.admin)
doPrivileged:-1, AccessController (java.security)
doAs:360, Subject (javax.security.auth)
execute:551, CommandRunnerImpl$2 (com.sun.enterprise.v3.admin)
run:582, CommandRunnerImpl$3 (com.sun.enterprise.v3.admin)
run:574, CommandRunnerImpl$3 (com.sun.enterprise.v3.admin)
doPrivileged:-1, AccessController (java.security)
doAs:360, Subject (javax.security.auth)
doCommand:573, CommandRunnerImpl (com.sun.enterprise.v3.admin)
doCommand:1497, CommandRunnerImpl (com.sun.enterprise.v3.admin)
access$1300:120, CommandRunnerImpl (com.sun.enterprise.v3.admin)
execute:1879, CommandRunnerImpl$ExecutionContext (com.sun.enterprise.v3.admin)
execute:1755, CommandRunnerImpl$ExecutionContext (com.sun.enterprise.v3.admin)
execute:129, ReDeployCommand (org.glassfish.deployment.admin)
run:556, CommandRunnerImpl$2$1 (com.sun.enterprise.v3.admin)
run:552, CommandRunnerImpl$2$1 (com.sun.enterprise.v3.admin)
doPrivileged:-1, AccessController (java.security)
doAs:360, Subject (javax.security.auth)
execute:551, CommandRunnerImpl$2 (com.sun.enterprise.v3.admin)
run:582, CommandRunnerImpl$3 (com.sun.enterprise.v3.admin)
run:574, CommandRunnerImpl$3 (com.sun.enterprise.v3.admin)
doPrivileged:-1, AccessController (java.security)
doAs:360, Subject (javax.security.auth)
doCommand:573, CommandRunnerImpl (com.sun.enterprise.v3.admin)
doCommand:1497, CommandRunnerImpl (com.sun.enterprise.v3.admin)
access$1300:120, CommandRunnerImpl (com.sun.enterprise.v3.admin)
execute:1879, CommandRunnerImpl$ExecutionContext (com.sun.enterprise.v3.admin)
execute:1755, CommandRunnerImpl$ExecutionContext (com.sun.enterprise.v3.admin)
executeCommand:409, CommandResource (org.glassfish.admin.rest.resources.admin)
execCommandSimpInMultOut:236, CommandResource (org.glassfish.admin.rest.resources.admin)
invoke:-1, GeneratedMethodAccessor380 (sun.reflect)
invoke:43, DelegatingMethodAccessorImpl (sun.reflect)
invoke:498, Method (java.lang.reflect)
lambda$static$0:52, ResourceMethodInvocationHandlerFactory (org.glassfish.jersey.server.model.internal)
invoke:-1, 1066657839 (org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$$Lambda$1415)
run:124, AbstractJavaResourceMethodDispatcher$1 (org.glassfish.jersey.server.model.internal)
invoke:167, AbstractJavaResourceMethodDispatcher (org.glassfish.jersey.server.model.internal)
doDispatch:176, JavaResourceMethodDispatcherProvider$ResponseOutInvoker (org.glassfish.jersey.server.model.internal)
dispatch:79, AbstractJavaResourceMethodDispatcher (org.glassfish.jersey.server.model.internal)
invoke:469, ResourceMethodInvoker (org.glassfish.jersey.server.model)
apply:391, ResourceMethodInvoker (org.glassfish.jersey.server.model)
apply:80, ResourceMethodInvoker (org.glassfish.jersey.server.model)
run:253, ServerRuntime$1 (org.glassfish.jersey.server)
call:248, Errors$1 (org.glassfish.jersey.internal)
call:244, Errors$1 (org.glassfish.jersey.internal)
process:292, Errors (org.glassfish.jersey.internal)
process:274, Errors (org.glassfish.jersey.internal)
process:244, Errors (org.glassfish.jersey.internal)
runInScope:265, RequestScope (org.glassfish.jersey.process.internal)
process:232, ServerRuntime (org.glassfish.jersey.server)
handle:680, ApplicationHandler (org.glassfish.jersey.server)
service:356, GrizzlyHttpContainer (org.glassfish.jersey.grizzly2.httpserver)
service:179, JerseyContainerCommandService$3 (org.glassfish.admin.rest.adapter)
service:189, RestAdapter (org.glassfish.admin.rest.adapter)
call:520, ContainerMapper$HttpHandlerCallable (com.sun.enterprise.v3.services.impl)
service:217, ContainerMapper (com.sun.enterprise.v3.services.impl)
runService:182, HttpHandler (org.glassfish.grizzly.http.server)
doHandle:156, HttpHandler (org.glassfish.grizzly.http.server)
handleRead:218, HttpServerFilter (org.glassfish.grizzly.http.server)
execute:95, ExecutorResolver$9 (org.glassfish.grizzly.filterchain)
executeFilter:260, DefaultFilterChain (org.glassfish.grizzly.filterchain)
executeChainPart:177, DefaultFilterChain (org.glassfish.grizzly.filterchain)
execute:109, DefaultFilterChain (org.glassfish.grizzly.filterchain)
process:88, DefaultFilterChain (org.glassfish.grizzly.filterchain)
execute:53, ProcessorExecutor (org.glassfish.grizzly)
fireIOEvent:524, TCPNIOTransport (org.glassfish.grizzly.nio.transport)
fireIOEvent:89, AbstractIOStrategy (org.glassfish.grizzly.strategies)
run0:94, WorkerThreadIOStrategy (org.glassfish.grizzly.strategies)
access$100:33, WorkerThreadIOStrategy (org.glassfish.grizzly.strategies)
run:114, WorkerThreadIOStrategy$WorkerThreadRunnable (org.glassfish.grizzly.strategies)
doWork:569, AbstractThreadPool$Worker (org.glassfish.grizzly.threadpool)
run:549, AbstractThreadPool$Worker (org.glassfish.grizzly.threadpool)
run:748, Thread (java.lang)

@lprimak
Copy link
Contributor

lprimak commented Dec 31, 2020

Unfortunately, I am not sure you are barking up the right tree here.
Most services are singletons and will not hold a copy of anything in them.
Some do hold some stuff, but if (and that's a big if) there is a leak, it's usually small.
The big leak is when something holds onto the Class loader instance (WebappClassLoader or ASURLClassLoader),
and that's where the big problems lie because those hold huge amounts of data

@sgflt
Copy link
Contributor

sgflt commented Dec 31, 2020

I wouldn't be suprised if there were multiple causes of different leaks. I am going to measure the change to confirm that the big leak is fixed and small is still present.

sgflt added a commit to sgflt/Payara that referenced this issue Dec 31, 2020
sgflt added a commit to sgflt/Payara that referenced this issue Dec 31, 2020
- this could be the first cause of leak
sgflt added a commit to sgflt/Payara that referenced this issue Dec 31, 2020
…lasses

- anonymous and inner holds implicit reference to parent
- this was probably the second cause of leak
@sgflt
Copy link
Contributor

sgflt commented Dec 31, 2020

After fix: 30 minutes, heap growing slowly, 1000 redeployments passed, metaspace usege constant, clases being unloaded

Snímek obrazovky pořízený 2020-12-31 11-39-23

Snímek obrazovky pořízený 2020-12-31 11-39-32

Heap stats: retained size is mostly caused by in ServiceLocator's defaultHabitat.
Snímek obrazovky pořízený 2020-12-31 11-43-17

Before fix: 10 minutes, heap full, ~ 200 redeployments, metaspace growing, classes sitting in memory

Snímek obrazovky pořízený 2020-12-31 11-59-03

Snímek obrazovky pořízený 2020-12-31 11-59-07

Heap stats:
Snímek obrazovky pořízený 2020-12-31 12-10-44

@lprimak lprimak added the Type: Bug Label issue as a bug defect label Jan 1, 2021
sgflt added a commit to sgflt/Payara that referenced this issue Jan 21, 2021
sgflt added a commit to sgflt/Payara that referenced this issue Jan 21, 2021
lprimak added a commit that referenced this issue Jan 26, 2021
* #4098 Reduced too broad scope of variable

* #4098 Moved field to local variable

- this could be the first cause of leak

* #4098 Refactored inner and anonymous classes to nested static classes

- anonymous and inner holds implicit reference to parent
- this was probably the second cause of leak

* #4098 Fixed code consistency

* Fix more class loader leaks by:
- making sure Server Threads and Timers do not inherit app's context class loaders
- making sure app's security contexts don't get propagated to server threads and timers

Added correct ear classes to class loader leak tests

Co-authored-by: lprimak <[email protected]>
@lprimak
Copy link
Contributor

lprimak commented Jan 27, 2021

Yes. Each redeploy puts some descriptors into default service locator, but undeploy does not call shutdown nor unregisters its own descriptors from default service locator, so count of initialized services is unstopably growing.

FYI I tried to track this down today, and services are actually unregistered from ServiceLocatorImpl
However, as @dmatej knows there is a race condition with logging that was causing the wrong service locator to be cached. I removed the @Inject of ServiceLocator from logging and that leak went away.

This was all part of the fix to this issue.

lprimak added a commit that referenced this issue Feb 5, 2021
* [FISH-1018] Out of memory redeploy leaks (#5081)

* #4098 Reduced too broad scope of variable

* #4098 Moved field to local variable

- this could be the first cause of leak

* #4098 Refactored inner and anonymous classes to nested static classes

- anonymous and inner holds implicit reference to parent
- this was probably the second cause of leak

* #4098 Fixed code consistency

* Fix more class loader leaks by:
- making sure Server Threads and Timers do not inherit app's context class loaders
- making sure app's security contexts don't get propagated to server threads and timers

Added correct ear classes to class loader leak tests

Co-authored-by: lprimak <[email protected]>

* [FISH-1018] found more leaks and more reliable leak test (#5102)

* found more leaks and more reliable leak test

* bump jakarta.el to -p3 patch

* tyrus patched update

Co-authored-by: Lukáš Kvídera <[email protected]>
@heatherita
Copy link

heatherita commented Jun 16, 2021

Lately we are getting memory leak errors and heap space errors in our server log. The heap space problem prevents me from deploying. Will a newer version of Payara solve this? I'm currently on Payara Server 5.194 #badassfish (build 327). Thanks.

2021-06-10T17:16:01.892-0400] [Payara 5.194] [SEVERE] [] [javax.enterprise.web.util] [tid: _ThreadID=251929 _ThreadName=RunLevelControllerThread-1623359761397] [timeMillis: 1623359761892] [levelValue: 1000] [[
  The web application [/myapp] created a ThreadLocal with key of type [org.glassfish.pfl.dynamic.codegen.impl.CurrentClassLoader$1] (value [org.glassfish.pfl.dynamic.codegen.impl.CurrentClassLoader$1@2aca5abb]) and a value of type [org.glassfish.web.loader.WebappClassLoader] (value [WebappClassLoader (delegate=true; repositories=WEB-INF/classes/) Object: 5ad6c9e7 Created: Jun 10, 2021, 5:05:26 PM]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.]]
[2021-06-15T17:56:37.914-0400] [Payara 5.194] [WARNING] [NCLS-CORE-00069] [javax.enterprise.system.core] [tid: _ThreadID=65727 _ThreadName=RunLevelControllerThread-1623794197218] [timeMillis: 1623794197914] [levelValue: 900] [[
  Exception while dispatching an event
java.lang.OutOfMemoryError: Java heap space
]]

[2021-06-15T17:56:37.923-0400] [Payara 5.194] [SEVERE] [] [javax.enterprise.web.util] [tid: _ThreadID=65727 _ThreadName=RunLevelControllerThread-1623794197218] [timeMillis: 1623794197923] [levelValue: 1000] [[
  The web application [] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@26816562]) and a value of type [org.glassfish.admingui.theme.AdminguiThemeContext] (value [org.glassfish.admingui.theme.AdminguiThemeContext@e604929]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.]]


@lprimak
Copy link
Contributor

lprimak commented Jun 16, 2021

Yes. Latest Payara Enterprise and community will solve most of these issues. While there are still small leaks, the large ones are absent

@heatherita
Copy link

heatherita commented Jun 16, 2021

Thanks. Is there any way to temporarily reset the server and the memory, until we get a chance to upgrade?

UPDATE: Confirmed. A restart of web instances prior to deployment will clear the memory and prevent the heap space error. This is a good temporary solution until the Payara upgrade can be done.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Type: Bug Label issue as a bug defect
Projects
None yet
6 participants