RE: High memory consumption and millions of file descriptors

thumbnail
Narsingh Pal, modified 5 Years ago. Junior Member Posts: 53 Join Date: 1/18/14 Recent Posts
This problem is going on since some time now on our production environment (RHEL + Weblogic + liferay 7.1 DXP), that after restart the  memory usage and the number of allocated file descriptors shoots up gradually.The file descriptors limit configured on the node is 
$ ulimit -n
65536
The output of the below command gives below result ~1.8 million
$ lsof | wc -l
1790389
After further investigation we filtered the output of lsof and found that there are  a lot (~750,000) of entries for the bundle files e.g 
<liferay_home>/osgi/state/org.eclipse.osgi/1000/0/bundleFile</liferay_home>
These entries are for liferay modules and custom modules - bothAnd after further filtering of these entries of (lsof output) we see that , for each bundle deployed on portal there are 650 entries, and this keeps on growing, I have seen it go upto 960 for each bundle. With this the memory consumption also keeps on increasing
I analyzed the threads and see that liferay tries to access the bundle file 
<liferay_home>/osgi/state/org.eclipse.osgi/247/0/bundleFile by thread:[STANDBY] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)' on Thu Dec 05 10:52:19 UTC 2019
&nbsp;&nbsp; &nbsp;at java.util.zip.ZipFile.<init>(ZipFile.java:150)
&nbsp;&nbsp; &nbsp;at java.util.zip.ZipFile.<init>(ZipFile.java:163)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.framework.util.SecureAction.getZipFile(SecureAction.java:304)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.storage.bundlefile.ZipBundleFile.getZipFile(ZipBundleFile.java:132)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.storage.bundlefile.ZipBundleFile.lockOpen(ZipBundleFile.java:79)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.storage.bundlefile.ZipBundleFile.getEntry(ZipBundleFile.java:288)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.storage.BundleInfo$Generation.getRawHeaders(BundleInfo.java:125)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.storage.BundleInfo$CachedManifest.get(BundleInfo.java:578)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.storage.BundleInfo$CachedManifest.get(BundleInfo.java:1)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.storage.ManifestLocalization.lookupResourceBundle(ManifestLocalization.java:125)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.storage.ManifestLocalization.getResourceBundle(ManifestLocalization.java:112)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.storage.ManifestLocalization.getHeaders(ManifestLocalization.java:75)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.storage.BundleInfo$Generation.getHeaders(BundleInfo.java:166)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.internal.framework.EquinoxBundle.privGetHeaders(EquinoxBundle.java:507)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.internal.framework.EquinoxBundle.getHeaders(EquinoxBundle.java:502)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.internal.framework.EquinoxBundle.getHeaders(EquinoxBundle.java:496)
&nbsp;&nbsp; &nbsp;at org.apache.aries.spifly.BaseActivator.getAllHeaders(BaseActivator.java:133)
&nbsp;&nbsp; &nbsp;at org.apache.aries.spifly.BaseActivator.addConsumerWeavingData(BaseActivator.java:95)
&nbsp;&nbsp; &nbsp;at org.apache.aries.spifly.ConsumerBundleTrackerCustomizer.addingBundle(ConsumerBundleTrackerCustomizer.java:37)
&nbsp;&nbsp; &nbsp;at org.osgi.util.tracker.BundleTracker$Tracked.customizerAdding(BundleTracker.java:475)
&nbsp;&nbsp; &nbsp;at org.osgi.util.tracker.BundleTracker$Tracked.customizerAdding(BundleTracker.java:1)
&nbsp;&nbsp; &nbsp;at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)
&nbsp;&nbsp; &nbsp;at org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183)
&nbsp;&nbsp; &nbsp;at org.osgi.util.tracker.BundleTracker.open(BundleTracker.java:159)
&nbsp;&nbsp; &nbsp;at org.apache.aries.spifly.BaseActivator.start(BaseActivator.java:79)
&nbsp;&nbsp; &nbsp;at org.apache.aries.spifly.dynamic.DynamicWeavingActivator.start(DynamicWeavingActivator.java:37)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.storage.FrameworkExtensionInstaller.startActivator(FrameworkExtensionInstaller.java:256)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.storage.FrameworkExtensionInstaller.startExtensionActivator(FrameworkExtensionInstaller.java:242)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.storage.FrameworkExtensionInstaller.startExtensionActivators(FrameworkExtensionInstaller.java:205)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.internal.framework.SystemBundleActivator.start(SystemBundleActivator.java:102)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:779)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:1)
&nbsp;&nbsp; &nbsp;at java.security.AccessController.doPrivileged(Native Method)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:772)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.internal.framework.BundleContextImpl.start(BundleContextImpl.java:729)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.internal.framework.EquinoxBundle.startWorker0(EquinoxBundle.java:1002)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.internal.framework.EquinoxBundle$SystemBundle$EquinoxSystemModule.initWorker(EquinoxBundle.java:187)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.container.SystemModule.init(SystemModule.java:94)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.internal.framework.EquinoxBundle$SystemBundle.init(EquinoxBundle.java:269)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.internal.framework.EquinoxBundle$SystemBundle.init(EquinoxBundle.java:254)
&nbsp;&nbsp; &nbsp;at org.eclipse.osgi.launch.Equinox.init(Equinox.java:168)
&nbsp;&nbsp; &nbsp;at com.liferay.portal.bootstrap.ModuleFrameworkImpl.initFramework(ModuleFrameworkImpl.java:290)
&nbsp;&nbsp; &nbsp;at com.liferay.portal.module.framework.ModuleFrameworkUtilAdapter.initFramework(ModuleFrameworkUtilAdapter.java:64)
&nbsp;&nbsp; &nbsp;at com.liferay.portal.spring.context.PortalContextLoaderListener.contextInitialized(PortalContextLoaderListener.java:246)
&nbsp;&nbsp; &nbsp;at weblogic.servlet.internal.EventsManager$FireContextListenerAction.run(EventsManager.java:705)
&nbsp;&nbsp; &nbsp;at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:326)
&nbsp;&nbsp; &nbsp;at weblogic.security.service.SecurityManager.runAsForUserCode(SecurityManager.java:197)
&nbsp;&nbsp; &nbsp;at weblogic.servlet.provider.WlsSecurityProvider.runAsForUserCode(WlsSecurityProvider.java:203)
&nbsp;&nbsp; &nbsp;at weblogic.servlet.provider.WlsSubjectHandle.run(WlsSubjectHandle.java:71)
&nbsp;&nbsp; &nbsp;at weblogic.servlet.internal.EventsManager.executeContextListener(EventsManager.java:251)
&nbsp;&nbsp; &nbsp;at weblogic.servlet.internal.EventsManager.notifyContextCreatedEvent(EventsManager.java:204)
&nbsp;&nbsp; &nbsp;at weblogic.servlet.internal.EventsManager.notifyContextCreatedEvent(EventsManager.java:189)
&nbsp;&nbsp; &nbsp;at weblogic.servlet.internal.WebAppServletContext.preloadResources(WebAppServletContext.java:1921)
&nbsp;&nbsp; &nbsp;at weblogic.servlet.internal.WebAppServletContext.start(WebAppServletContext.java:3101)
&nbsp;&nbsp; &nbsp;at weblogic.servlet.internal.WebAppModule.startContexts(WebAppModule.java:1843)
&nbsp;&nbsp; &nbsp;at weblogic.servlet.internal.WebAppModule.start(WebAppModule.java:884)
&nbsp;&nbsp; &nbsp;at weblogic.application.internal.ExtensibleModuleWrapper$StartStateChange.next(ExtensibleModuleWrapper.java:360)
&nbsp;&nbsp; &nbsp;at weblogic.application.internal.ExtensibleModuleWrapper$StartStateChange.next(ExtensibleModuleWrapper.java:356)
&nbsp;&nbsp; &nbsp;at weblogic.application.utils.StateMachineDriver.nextState(StateMachineDriver.java:45)
&nbsp;&nbsp; &nbsp;at weblogic.application.internal.ExtensibleModuleWrapper.start(ExtensibleModuleWrapper.java:138)
&nbsp;&nbsp; &nbsp;at weblogic.application.internal.flow.ModuleListenerInvoker.start(ModuleListenerInvoker.java:124)
&nbsp;&nbsp; &nbsp;at weblogic.application.internal.flow.ModuleStateDriver$3.next(ModuleStateDriver.java:233)
&nbsp;&nbsp; &nbsp;at weblogic.application.internal.flow.ModuleStateDriver$3.next(ModuleStateDriver.java:228)
&nbsp;&nbsp; &nbsp;at weblogic.application.utils.StateMachineDriver.nextState(StateMachineDriver.java:45)
&nbsp;&nbsp; &nbsp;at weblogic.application.internal.flow.ModuleStateDriver.start(ModuleStateDriver.java:78)
&nbsp;&nbsp; &nbsp;at weblogic.application.internal.flow.StartModulesFlow.activate(StartModulesFlow.java:52)
&nbsp;&nbsp; &nbsp;at weblogic.application.internal.BaseDeployment$2.next(BaseDeployment.java:752)
&nbsp;&nbsp; &nbsp;at weblogic.application.utils.StateMachineDriver.nextState(StateMachineDriver.java:45)
&nbsp;&nbsp; &nbsp;at weblogic.application.internal.BaseDeployment.activate(BaseDeployment.java:262)
&nbsp;&nbsp; &nbsp;at weblogic.application.internal.SingleModuleDeployment.activate(SingleModuleDeployment.java:52)
&nbsp;&nbsp; &nbsp;at weblogic.application.internal.DeploymentStateChecker.activate(DeploymentStateChecker.java:165)
&nbsp;&nbsp; &nbsp;at weblogic.deploy.internal.targetserver.AppContainerInvoker.activate(AppContainerInvoker.java:90)
&nbsp;&nbsp; &nbsp;at weblogic.deploy.internal.targetserver.BasicDeployment.activate(BasicDeployment.java:274)
&nbsp;&nbsp; &nbsp;at weblogic.deploy.internal.targetserver.BasicDeployment.activateFromServerLifecycle(BasicDeployment.java:507)
&nbsp;&nbsp; &nbsp;at weblogic.management.deploy.internal.DeploymentAdapter$1.doActivate(DeploymentAdapter.java:53)
&nbsp;&nbsp; &nbsp;at weblogic.management.deploy.internal.DeploymentAdapter.activate(DeploymentAdapter.java:202)
&nbsp;&nbsp; &nbsp;at weblogic.management.deploy.internal.AppTransition$2.transitionApp(AppTransition.java:52)
&nbsp;&nbsp; &nbsp;at weblogic.management.deploy.internal.ConfiguredDeployments$2.doItem(ConfiguredDeployments.java:741)
&nbsp;&nbsp; &nbsp;at weblogic.management.deploy.internal.parallel.BucketInvoker.invoke(BucketInvoker.java:138)
&nbsp;&nbsp; &nbsp;at weblogic.management.deploy.internal.ConfiguredDeployments.transitionAppsParallel(ConfiguredDeployments.java:749)
&nbsp;&nbsp; &nbsp;at weblogic.management.deploy.internal.ConfiguredDeployments.transitionAppsParallel(ConfiguredDeployments.java:702)
&nbsp;&nbsp; &nbsp;at weblogic.management.deploy.internal.ConfiguredDeployments.activate(ConfiguredDeployments.java:381)
&nbsp;&nbsp; &nbsp;at weblogic.management.deploy.internal.ConfiguredDeployments.deploy(ConfiguredDeployments.java:233)
&nbsp;&nbsp; &nbsp;at weblogic.management.deploy.internal.DeploymentServerService.resume(DeploymentServerService.java:219)
&nbsp;&nbsp; &nbsp;at weblogic.management.deploy.internal.DeploymentServerService.start(DeploymentServerService.java:133)
&nbsp;&nbsp; &nbsp;at weblogic.server.AbstractServerService.postConstruct(AbstractServerService.java:76)
&nbsp;&nbsp; &nbsp;at sun.reflect.GeneratedMethodAccessor7.invoke(Unknown Source)
&nbsp;&nbsp; &nbsp;at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
&nbsp;&nbsp; &nbsp;at java.lang.reflect.Method.invoke(Method.java:498)
&nbsp;&nbsp; &nbsp;at org.glassfish.hk2.utilities.reflection.ReflectionHelper.invoke(ReflectionHelper.java:1287)
&nbsp;&nbsp; &nbsp;at org.jvnet.hk2.internal.ClazzCreator.postConstructMe(ClazzCreator.java:333)
&nbsp;&nbsp; &nbsp;at org.jvnet.hk2.internal.ClazzCreator.create(ClazzCreator.java:375)
&nbsp;&nbsp; &nbsp;at org.jvnet.hk2.internal.SystemDescriptor.create(SystemDescriptor.java:487)
&nbsp;&nbsp; &nbsp;at org.glassfish.hk2.runlevel.internal.AsyncRunLevelContext.findOrCreate(AsyncRunLevelContext.java:305)
&nbsp;&nbsp; &nbsp;at org.glassfish.hk2.runlevel.RunLevelContext.findOrCreate(RunLevelContext.java:85)
&nbsp;&nbsp; &nbsp;at org.jvnet.hk2.internal.Utilities.createService(Utilities.java:2126)
&nbsp;&nbsp; &nbsp;at org.jvnet.hk2.internal.ServiceHandleImpl.getService(ServiceHandleImpl.java:116)
&nbsp;&nbsp; &nbsp;at org.jvnet.hk2.internal.ServiceLocatorImpl.getService(ServiceLocatorImpl.java:698)
&nbsp;&nbsp; &nbsp;at org.jvnet.hk2.internal.ThreeThirtyResolver.resolve(ThreeThirtyResolver.java:78)
&nbsp;&nbsp; &nbsp;at org.jvnet.hk2.internal.ClazzCreator.resolve(ClazzCreator.java:212)
&nbsp;&nbsp; &nbsp;at org.jvnet.hk2.internal.ClazzCreator.resolveAllDependencies(ClazzCreator.java:235)
&nbsp;&nbsp; &nbsp;at org.jvnet.hk2.internal.ClazzCreator.create(ClazzCreator.java:358)
&nbsp;&nbsp; &nbsp;at org.jvnet.hk2.internal.SystemDescriptor.create(SystemDescriptor.java:487)
&nbsp;&nbsp; &nbsp;at org.glassfish.hk2.runlevel.internal.AsyncRunLevelContext.findOrCreate(AsyncRunLevelContext.java:305)
&nbsp;&nbsp; &nbsp;at org.glassfish.hk2.runlevel.RunLevelContext.findOrCreate(RunLevelContext.java:85)
&nbsp;&nbsp; &nbsp;at org.jvnet.hk2.internal.Utilities.createService(Utilities.java:2126)
&nbsp;&nbsp; &nbsp;at org.jvnet.hk2.internal.ServiceHandleImpl.getService(ServiceHandleImpl.java:116)
&nbsp;&nbsp; &nbsp;at org.jvnet.hk2.internal.ServiceHandleImpl.getService(ServiceHandleImpl.java:90)
&nbsp;&nbsp; &nbsp;at org.glassfish.hk2.runlevel.internal.CurrentTaskFuture$QueueRunner.oneJob(CurrentTaskFuture.java:1237)
&nbsp;&nbsp; &nbsp;at org.glassfish.hk2.runlevel.internal.CurrentTaskFuture$QueueRunner.run(CurrentTaskFuture.java:1168)
&nbsp;&nbsp; &nbsp;at weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:670)
&nbsp;&nbsp; &nbsp;at weblogic.invocation.ComponentInvocationContextManager._runAs(ComponentInvocationContextManager.java:352)
&nbsp;&nbsp; &nbsp;at weblogic.invocation.ComponentInvocationContextManager.runAs(ComponentInvocationContextManager.java:337)
&nbsp;&nbsp; &nbsp;at weblogic.work.LivePartitionUtility.doRunWorkUnderContext(LivePartitionUtility.java:57)
&nbsp;&nbsp; &nbsp;at weblogic.work.PartitionUtility.runWorkUnderContext(PartitionUtility.java:41)
&nbsp;&nbsp; &nbsp;at weblogic.work.SelfTuningWorkManagerImpl.runWorkUnderContext(SelfTuningWorkManagerImpl.java:644)
&nbsp;&nbsp; &nbsp;at weblogic.work.ExecuteThread.execute(ExecuteThread.java:415)
&nbsp;&nbsp; &nbsp;at weblogic.work.ExecuteThread.run(ExecuteThread.java:355)</init></init></liferay_home>

Does anybody know, if there is some file descriptors leak happening here. Or any clue to mitigate this ?
Thanks and Regards
Narsingh Pal
thumbnail
David H Nebinger, modified 5 Years ago. Liferay Legend Posts: 14933 Join Date: 9/2/06 Recent Posts
These stacktraces seem to be heavily pointing at something weblogic is doing...

Anyways, since you're DXP, have you opened your support ticket yet? https://liferay.dev/blogs/-/blogs/working-with-liferay-support
thumbnail
Narsingh Pal, modified 5 Years ago. Junior Member Posts: 53 Join Date: 1/18/14 Recent Posts
Hi David,

Thanks for the prompt response.  I am not able to reproduce it on  vanilla Liferay  yet.  Hence did not open the support ticket. 

Could you please explain what is going on here ( basically the mechanism).  I mean why and when does  Liferay  accesses bundle file.  Looking at the source code I see that it is triggering during framework restart/start.

So ideally it should be triggered once during startup but since there are 650 such entries for each bundle  does it mean, that this happened 650 times?  And this number  keeps on increasing steadily 
Thanks and regards
Narsingh Pal 
thumbnail
David H Nebinger, modified 5 Years ago. Liferay Legend Posts: 14933 Join Date: 9/2/06 Recent Posts
It's hard to say, not knowing any of your implementation details...

As an example though, Spring Portlet MVC, when you use component scanning from your Spring xml file, it actually ends up opening all of the jars in the war scanning for annotated classes. And when I say all of the jars, I mean all of the jars...

For your case? I don't know, only your implementation details might have something to tell you about why the scanning is occurring.
thumbnail
Narsingh Pal, modified 5 Years ago. Junior Member Posts: 53 Join Date: 1/18/14 Recent Posts
Thanks David for sharing your thoughts. 

The pattern is like this.   After every hour or so  ~1100 entries get added,  i.e. one for each of the bundle present in the container. 


Is JVM garbage collector  doing something  here.  Because  as per the GC  logs it also runs  with the similar frequency. Is there a possibility that Liferay is opening  file handles for it's bundles after GC ?


Thanks and regards
Narsingh Pal  
thumbnail
Christoph Rabel, modified 5 Years ago. Liferay Legend Posts: 1555 Join Date: 9/24/09 Recent Posts
So, it doesn't happen with vanilla Liferay. Therefore it has to do something with your modules.
Maybe you can narrow it down to some modules? Do you have any dependencies that might interfere with OSGI? Some module that scans all other modules?
Aries Blueprint maybe, or JPA, ... there are several modules out there that look into/read other bundles.
thumbnail
Narsingh Pal, modified 5 Years ago. Junior Member Posts: 53 Join Date: 1/18/14 Recent Posts
Hi Christoph,


Thanks for your response.

We do not have such module in our deployment. All of the modules have been built using Liferay  MVC  and service builder. We do not have a module which scans all other modules.
Can you elaborate  what kind of dependencies can interfere with osgi.
Additionally we only have some hooks and ext. 
Moreover I  think I  have to simulate long running load  test to check vanilla (something that includes few GC cycles).

But let's say hypothetically if there is some code which scans all bundles.  Shouldn't  Liferay/osgi framework  take care of  closing  the file handles? 



Thanks and regards Narsingh Pal 
thumbnail
Christoph Rabel, modified 5 Years ago. Liferay Legend Posts: 1555 Join Date: 9/24/09 Recent Posts
Well, I am just wild guessing here, shoots into the dark.
It is hard to say which libraries can interfere with OSGI or do weird things. I have mentioned Aries already, but basically any library that looks into other bundles and picks up files, descriptors, ... that are relevant to work some "magic".
In any case, you need to narrow it down.
- Is vanilla Liferay affected? --> This one is very important. If it happens without your modules, Liferay has to fix it. If not, you can try to narrow it down to your modules. Then one of them or your hooks or ext plugins is doing something unexpected.
- I would suggest to open a ticket at Liferay. Maybe they can help you and point you in some direction. Maybe they know of that problem already in some context. When I open a ticket, I am always impressed, how good those guys are and how much they know.
- If you have indeed a module/library that misbehaves, it is quite possible that osgi can't clean up. I mean, if a module claims to need those handles, what should the framework do?
thumbnail
Narsingh Pal, modified 5 Years ago. Junior Member Posts: 53 Join Date: 1/18/14 Recent Posts
Hi Christoph,

Thanks for your suggestions. 

I will try to narrow it down further. 


Many thanks for your time and support. 


Thanks and regards Narsingh Pal