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.

Sign up for GitHub

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

Jump to bottom

Bug Report: Server shutdown causes unexpected exceptions from monitoring module/FISH-9222 #6879

Closed
lprimak opened this issue Aug 9, 2024 · 1 comment · Fixed by #6880
Closed

Bug Report: Server shutdown causes unexpected exceptions from monitoring module/FISH-9222 #6879

lprimak opened this issue Aug 9, 2024 · 1 comment · Fixed by #6880
Assignees
@felixif
Labels
Status: Accepted Confirmed defect or accepted improvement to implement, issue has been escalated to Platform Dev Type: Bug Label issue as a bug defect

Comments

@lprimak
Copy link
Contributor

lprimak commented Aug 9, 2024 •
edited
Loading

Brief Summary

Monitoring console is trying to call Grizzly after server is shut down from another thread.
This is causing exceptions to happen and prevents a clean shutdown.

This doesn't happen every time, but about 1/30 shutdowns.

Expected Outcome

No exceptions are produced

Current Outcome

[2024-08-09T05:07:59.243-0500] [Payara 6.2024.7] [INFO] [NCLS-CORE-00092] [javax.enterprise.system.core] [tid: _ThreadID=675 _ThreadName=Thread-38] [timeMillis: 1723198079243] [levelValue: 800] [[
  Server shutdown initiated]]

[2024-08-09T05:07:59.265-0500] [Payara 6.2024.7] [INFO] [] [] [tid: _ThreadID=675 _ThreadName=Thread-38] [timeMillis: 1723198079265] [levelValue: 800] [[
  FileMonitoring shutdown]]

[2024-08-09T05:07:59.278-0500] [Payara 6.2024.7] [INFO] [NCLS-JMX-00002] [javax.enterprise.system.jmx] [tid: _ThreadID=675 _ThreadName=Thread-38] [timeMillis: 1723198079278] [levelValue: 800] [[
  JMXStartupService: Stopped JMXConnectorServer: null]]

[2024-08-09T05:07:59.278-0500] [Payara 6.2024.7] [INFO] [NCLS-JMX-00001] [javax.enterprise.system.jmx] [tid: _ThreadID=675 _ThreadName=Thread-38] [timeMillis: 1723198079278] [levelValue: 800] [[
  JMXStartupService and JMXConnectors have been shut down.]]

[2024-08-09T05:07:59.304-0500] [Payara 6.2024.7] [INFO] [] [fish.payara.nucleus.hazelcast.HazelcastCore] [tid: _ThreadID=678 _ThreadName=RunLevelControllerThread-1723198079280] [timeMillis: 1723198079304] [levelValue: 800] [[
  Hazelcast Instance Unbound from JNDI at payara/Hazelcast]]

[2024-08-09T05:07:59.304-0500] [Payara 6.2024.7] [INFO] [] [fish.payara.nucleus.hazelcast.HazelcastCore] [tid: _ThreadID=678 _ThreadName=RunLevelControllerThread-1723198079280] [timeMillis: 1723198079304] [levelValue: 800] [[
  JSR107 Caching Provider Unbound from JNDI at payara/CachingProvider]]

[2024-08-09T05:07:59.305-0500] [Payara 6.2024.7] [INFO] [] [fish.payara.nucleus.hazelcast.HazelcastCore] [tid: _ThreadID=678 _ThreadName=RunLevelControllerThread-1723198079280] [timeMillis: 1723198079305] [levelValue: 800] [[
  JSR107 Cache Manager Unbound from JNDI at payara/CacheManager]]

[2024-08-09T05:07:59.333-0500] [Payara 6.2024.7] [INFO] [] [fish.payara.nucleus.hazelcast.HazelcastCore] [tid: _ThreadID=678 _ThreadName=RunLevelControllerThread-1723198079280] [timeMillis: 1723198079333] [levelValue: 800] [[
  Shutdown Hazelcast]]

[2024-08-09T05:07:59.363-0500] [Payara 6.2024.7] [INFO] [] [] [tid: _ThreadID=680 _ThreadName=RunLevelControllerThread-1723198079280] [timeMillis: 1723198079363] [levelValue: 800] [[
  JdbcRuntimeExtension,  getAllSystemRAResourcesAndPools = [GlassFishConfigBean.org.glassfish.jdbc.config.JdbcResource, GlassFishConfigBean.org.glassfish.jdbc.config.JdbcResource, GlassFishConfigBean.org.glassfish.jdbc.config.JdbcConnectionPool, GlassFishConfigBean.org.glassfish.jdbc.config.JdbcConnectionPool]]]

[2024-08-09T05:07:59.384-0500] [Payara 6.2024.7] [WARNING] [] [fish.payara.appserver.micro.services.PayaraInstanceImpl] [tid: _ThreadID=143 _ThreadName=payara-executor-service-scheduled-task] [timeMillis: 1723198079384] [levelValue: 900] [[
  Failed to get running Grizzly listener.
MultiException stack 1 of 1
java.lang.IllegalStateException: Service com.sun.enterprise.v3.services.impl.GrizzlyService was started at level 1 but it has a run level of 10.  The full descriptor is SystemDescriptor(
	implementation=com.sun.enterprise.v3.services.impl.GrizzlyService
	contracts={com.sun.enterprise.v3.services.impl.GrizzlyService,org.glassfish.api.container.RequestDispatcher,fish.payara.monitoring.collect.MonitoringDataSource}
	scope=org.glassfish.hk2.runlevel.RunLevel
	qualifiers={}
	descriptorType=CLASS
	descriptorVisibility=NORMAL
	metadata=runLevelValue={10},Bundle-SymbolicName={fish.payara.server.core.nucleus.kernel},Bundle-Version={6.17.0}
	rank=50
	loader=OsgiPopulatorPostProcessor.HK2Loader(OSGiModuleImpl:: Bundle = [fish.payara.server.core.nucleus.kernel [322]], State = [READY],1913685535)
	proxiable=null
	proxyForSameScope=null
	analysisName=null
	id=636
	locatorId=0
	identityHashCode=1091399088
	reified=true)
	at org.glassfish.hk2.runlevel.internal.AsyncRunLevelContext.validate(AsyncRunLevelContext.java:422)
	at org.glassfish.hk2.runlevel.internal.AsyncRunLevelContext.findOrCreate(AsyncRunLevelContext.java:275)
	at org.glassfish.hk2.runlevel.RunLevelContext.findOrCreate(RunLevelContext.java:65)
	at org.jvnet.hk2.internal.Utilities.createService(Utilities.java:2103)
	at org.jvnet.hk2.internal.ServiceLocatorImpl.internalGetAllServiceHandles(ServiceLocatorImpl.java:1497)
	at org.jvnet.hk2.internal.ServiceLocatorImpl.getAllServices(ServiceLocatorImpl.java:810)
	at org.jvnet.hk2.internal.ServiceLocatorImpl.getAllServices(ServiceLocatorImpl.java:798)
	at fish.payara.monitoring.runtime.MonitoringConsoleRuntimeImpl.lambda$init$0(MonitoringConsoleRuntimeImpl.java:186)
	at fish.payara.monitoring.internal.adapt.MonitoringConsoleImpl.lambda$new$0(MonitoringConsoleImpl.java:92)
	at fish.payara.monitoring.internal.data.InMemorySeriesRepository.collectAll(InMemorySeriesRepository.java:225)
	at fish.payara.monitoring.internal.data.InMemorySeriesRepository.collectSourcesToMemory(InMemorySeriesRepository.java:196)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
	at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:358)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
	at java.base/java.lang.Thread.run(Thread.java:1570)
]]

[2024-08-09T05:07:59.385-0500] [Payara 6.2024.7] [WARNING] [] [fish.payara.appserver.micro.services.PayaraInstanceImpl] [tid: _ThreadID=143 _ThreadName=payara-executor-service-scheduled-task] [timeMillis: 1723198079385] [levelValue: 900] [[
  Failed to get running Grizzly listener.
MultiException stack 1 of 1
java.lang.IllegalStateException: Service com.sun.enterprise.v3.services.impl.GrizzlyService was started at level 1 but it has a run level of 10.  The full descriptor is SystemDescriptor(
	implementation=com.sun.enterprise.v3.services.impl.GrizzlyService
	contracts={com.sun.enterprise.v3.services.impl.GrizzlyService,org.glassfish.api.container.RequestDispatcher,fish.payara.monitoring.collect.MonitoringDataSource}
	scope=org.glassfish.hk2.runlevel.RunLevel
	qualifiers={}
	descriptorType=CLASS
	descriptorVisibility=NORMAL
	metadata=runLevelValue={10},Bundle-SymbolicName={fish.payara.server.core.nucleus.kernel},Bundle-Version={6.17.0}
	rank=50
	loader=OsgiPopulatorPostProcessor.HK2Loader(OSGiModuleImpl:: Bundle = [fish.payara.server.core.nucleus.kernel [322]], State = [READY],1913685535)
	proxiable=null
	proxyForSameScope=null
	analysisName=null
	id=636
	locatorId=0
	identityHashCode=1091399088
	reified=true)
	at org.glassfish.hk2.runlevel.internal.AsyncRunLevelContext.validate(AsyncRunLevelContext.java:422)
	at org.glassfish.hk2.runlevel.internal.AsyncRunLevelContext.findOrCreate(AsyncRunLevelContext.java:275)
	at org.glassfish.hk2.runlevel.RunLevelContext.findOrCreate(RunLevelContext.java:65)
	at org.jvnet.hk2.internal.Utilities.createService(Utilities.java:2103)
	at org.jvnet.hk2.internal.ServiceLocatorImpl.internalGetAllServiceHandles(ServiceLocatorImpl.java:1497)
	at org.jvnet.hk2.internal.ServiceLocatorImpl.getAllServices(ServiceLocatorImpl.java:810)
	at org.jvnet.hk2.internal.ServiceLocatorImpl.getAllServices(ServiceLocatorImpl.java:798)
	at fish.payara.monitoring.runtime.MonitoringConsoleRuntimeImpl.lambda$init$0(MonitoringConsoleRuntimeImpl.java:186)
	at fish.payara.monitoring.internal.adapt.MonitoringConsoleImpl.lambda$new$0(MonitoringConsoleImpl.java:92)
	at fish.payara.monitoring.internal.data.InMemorySeriesRepository.collectAll(InMemorySeriesRepository.java:225)
	at fish.payara.monitoring.internal.data.InMemorySeriesRepository.collectSourcesToMemory(InMemorySeriesRepository.java:196)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
	at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:358)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
	at java.base/java.lang.Thread.run(Thread.java:1570)
]]

[2024-08-09T05:07:59.387-0500] [Payara 6.2024.7] [WARNING] [] [fish.payara.appserver.micro.services.PayaraInstanceImpl] [tid: _ThreadID=143 _ThreadName=payara-executor-service-scheduled-task] [timeMillis: 1723198079387] [levelValue: 900] [[
  Failed to get running Grizzly listener.
MultiException stack 1 of 1
java.lang.IllegalStateException: Service com.sun.enterprise.v3.services.impl.GrizzlyService was started at level 1 but it has a run level of 10.  The full descriptor is SystemDescriptor(
	implementation=com.sun.enterprise.v3.services.impl.GrizzlyService
	contracts={com.sun.enterprise.v3.services.impl.GrizzlyService,org.glassfish.api.container.RequestDispatcher,fish.payara.monitoring.collect.MonitoringDataSource}
	scope=org.glassfish.hk2.runlevel.RunLevel
	qualifiers={}
	descriptorType=CLASS
	descriptorVisibility=NORMAL
	metadata=runLevelValue={10},Bundle-SymbolicName={fish.payara.server.core.nucleus.kernel},Bundle-Version={6.17.0}
	rank=50
	loader=OsgiPopulatorPostProcessor.HK2Loader(OSGiModuleImpl:: Bundle = [fish.payara.server.core.nucleus.kernel [322]], State = [READY],1913685535)
	proxiable=null
	proxyForSameScope=null
	analysisName=null
	id=636
	locatorId=0
	identityHashCode=1091399088
	reified=true)
	at org.glassfish.hk2.runlevel.internal.AsyncRunLevelContext.validate(AsyncRunLevelContext.java:422)
	at org.glassfish.hk2.runlevel.internal.AsyncRunLevelContext.findOrCreate(AsyncRunLevelContext.java:275)
	at org.glassfish.hk2.runlevel.RunLevelContext.findOrCreate(RunLevelContext.java:65)
	at org.jvnet.hk2.internal.Utilities.createService(Utilities.java:2103)
	at org.jvnet.hk2.internal.ServiceLocatorImpl.internalGetAllServiceHandles(ServiceLocatorImpl.java:1497)
	at org.jvnet.hk2.internal.ServiceLocatorImpl.getAllServices(ServiceLocatorImpl.java:810)
	at org.jvnet.hk2.internal.ServiceLocatorImpl.getAllServices(ServiceLocatorImpl.java:798)
	at fish.payara.monitoring.runtime.MonitoringConsoleRuntimeImpl.lambda$init$0(MonitoringConsoleRuntimeImpl.java:186)
	at fish.payara.monitoring.internal.adapt.MonitoringConsoleImpl.lambda$new$0(MonitoringConsoleImpl.java:92)
	at fish.payara.monitoring.internal.data.InMemorySeriesRepository.collectAll(InMemorySeriesRepository.java:225)
	at fish.payara.monitoring.internal.data.InMemorySeriesRepository.collectSourcesToMemory(InMemorySeriesRepository.java:196)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
	at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:358)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
	at java.base/java.lang.Thread.run(Thread.java:1570)
]]

[2024-08-09T05:07:59.588-0500] [Payara 6.2024.7] [INFO] [] [javax.enterprise.resource.resourceadapter.com.sun.enterprise.connectors.service] [tid: _ThreadID=692 _ThreadName=RA Shutdown] [timeMillis: 1723198079588] [levelValue: 800] [[
  RAR7094: __ds_jdbc_ra shutdown successful.]]

Reproducer

Unable to consistently reproduce.
However, there is good debugging information so I will submit a PR

Operating System

Any

JDK Version

Any

Payara Distribution

Payara Server Full Profile, Payara Server Web Profile
@lprimak lprimak added Status: Open Issue has been triaged by the front-line engineers and is being worked on verification Type: Bug Label issue as a bug defect labels Aug 9, 2024
@lprimak lprimak mentioned this issue Aug 9, 2024
Merged
@felixif
Copy link

felixif commented Aug 15, 2024

Hello @lprimak,

Thank you for the report and for submitting the PR that would fix the issue. The PR will be analysed by our Platform Development team.

Best regards,
Felix

@felixif felixif added Status: Accepted Confirmed defect or accepted improvement to implement, issue has been escalated to Platform Dev and removed Status: Open Issue has been triaged by the front-line engineers and is being worked on verification labels Aug 15, 2024
@felixif felixif changed the title Bug Report: Server shutdown causes unexpected exceptions from monitoring module Bug Report: Server shutdown causes unexpected exceptions from monitoring module/FISH-9222 Aug 15, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@felixif felixif

Labels
Status: Accepted Confirmed defect or accepted improvement to implement, issue has been escalated to Platform Dev Type: Bug Label issue as a bug defect
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

FISH-9222 bugfix: disable PayaraExecutorService events before server shuts down flowlogix/Payara
2 participants
@lprimak @felixif