Details
-
Bug
-
Resolution: Won't Do
-
Minor
-
None
-
7.3.0.CD16
-
None
Description
Test where the issue has been spotted is eap-7.x-clustering-singleton-deployment-random-election;
The server emits errors when stopped at the end of regular clustering fail-over test with a singleton deployment ear;
Fail-over is introduced via JVMKILL;
Those errors do not produce client errors, hence this issue is not considered having high priority;
The errors seem to be triggered by a cache that is created but not actually used in the test: the cache for a granular webapp that does not receive http requests;
Server configuration is as follows:
embed-server --server-config=standalone-ha.xml /subsystem=singleton/singleton-policy=default/election-policy=random:add() /subsystem=jgroups:write-attribute(name=default-stack,value=tcp) /subsystem=jgroups/channel=ee:write-attribute(name=stack,value=tcp)
When the server is shut down at the end of the test cycle we see the followign errors:
2019-04-19 07:45:52,645 INFO [org.jboss.as.server] (Thread-2) WFLYSRV0272: Suspending server
2019-04-19 07:45:52,646 INFO [org.jboss.as.ejb3] (Thread-2) WFLYEJB0493: EJB subsystem suspension complete
2019-04-19 07:45:52,647 INFO [org.jboss.as.server] (Thread-2) WFLYSRV0220: Server shutdown has been requested via an OS signal
2019-04-19 07:45:52,696 INFO [org.jboss.as.mail.extension] (MSC service thread 1-2) WFLYMAIL0002: Unbound mail session [java:jboss/mail/Default]
2019-04-19 07:45:52,697 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-2) ISPN000080: Disconnecting JGroups channel ejb
2019-04-19 07:45:52,702 INFO [org.wildfly.extension.undertow] (ServerService Thread Pool -- 119) WFLYUT0022: Unregistered web context: '/clusterbench' from server 'default-server'
2019-04-19 07:45:52,704 INFO [org.wildfly.extension.undertow] (ServerService Thread Pool -- 117) WFLYUT0022: Unregistered web context: '/clusterbench-passivating' from server 'default-server'
2019-04-19 07:45:52,734 INFO [org.infinispan.eviction.impl.PassivationManagerImpl] (ServerService Thread Pool -- 121) ISPN000029: Passivating all entries to disk
2019-04-19 07:45:52,735 INFO [org.infinispan.eviction.impl.PassivationManagerImpl] (ServerService Thread Pool -- 121) ISPN000030: Passivated 0 entries in 0 milliseconds
2019-04-19 07:45:52,740 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 121) WFLYCLINF0003: Stopped clusterbench-ee8.ear/clusterbench-ee8-ejb.jar/infinispan cache from ejb container
2019-04-19 07:45:52,761 INFO [org.infinispan.eviction.impl.PassivationManagerImpl] (ServerService Thread Pool -- 117) ISPN000029: Passivating all entries to disk
2019-04-19 07:45:52,769 INFO [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0019: Host default-host stopping
2019-04-19 07:45:52,771 INFO [org.jboss.modcluster] (ServerService Thread Pool -- 126) MODCLUSTER000002: Initiating mod_cluster shutdown
2019-04-19 07:45:52,780 INFO [org.infinispan.eviction.impl.PassivationManagerImpl] (ServerService Thread Pool -- 116) ISPN000029: Passivating all entries to disk
2019-04-19 07:45:52,780 INFO [org.infinispan.eviction.impl.PassivationManagerImpl] (ServerService Thread Pool -- 116) ISPN000030: Passivated 0 entries in 0 milliseconds
2019-04-19 07:45:52,824 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 116) WFLYCLINF0003: Stopped clusterbench-ee8.ear.clusterbench-ee8-web-passivating.war cache from web container
2019-04-19 07:45:52,897 INFO [org.infinispan.CLUSTER] (ServerService Thread Pool -- 127) [Context=default-server] ISPN100008: Updating cache members list [wildfly4], topology id 6
2019-04-19 07:45:52,901 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 127) WFLYCLINF0003: Stopped default-server cache from web container
2019-04-19 07:45:52,901 INFO [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-2) WFLYJCA0010: Unbound data source [java:jboss/datasources/ExampleDS]
2019-04-19 07:45:53,136 INFO [org.infinispan.eviction.impl.PassivationManagerImpl] (ServerService Thread Pool -- 117) ISPN000030: Passivated 1500 entries in 374 milliseconds
2019-04-19 07:45:53,159 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 117) WFLYCLINF0003: Stopped clusterbench-ee8.ear.clusterbench-ee8-web.war cache from web container
2019-04-19 07:46:30,920 INFO [org.infinispan.CLUSTER] (remote-thread--p17-t3) [Context=clusterbench-ee8.ear.clusterbench-ee8-web-granular.war] ISPN100008: Updating cache members list [wildfly1], topology id 4
2019-04-19 07:46:30,922 INFO [org.infinispan.CLUSTER] (remote-thread--p17-t3) [Context=clusterbench-ee8.ear.clusterbench-ee8-web-granular.war] ISPN100008: Updating cache members list [wildfly1], topology id 5
2019-04-19 07:49:42,204 INFO [org.infinispan.eviction.impl.PassivationManagerImpl] (ServerService Thread Pool -- 120) ISPN000029: Passivating all entries to disk
2019-04-19 07:49:42,204 INFO [org.infinispan.eviction.impl.PassivationManagerImpl] (ServerService Thread Pool -- 120) ISPN000030: Passivated 0 entries in 0 milliseconds
2019-04-19 07:49:42,219 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 120) WFLYCLINF0003: Stopped clusterbench-ee8.ear.clusterbench-ee8-web-granular.war cache from web container
2019-04-19 07:49:42,219 ERROR [org.jboss.msc.service.fail] (ServerService Thread Pool -- 120) MSC000001: Failed to start service org.wildfly.clustering.infinispan.cache.web.clusterbench-ee8.ear.clusterbench-ee8-web-granular.war: org.jboss.msc.service.StartException in service org.wildfly.clustering.infinispan.cache.web.clusterbench-ee8.ear.clusterbench-ee8-web-granular.war: org.infinispan.commons.CacheException: Initial state transfer timed out for cache clusterbench-ee8.ear.clusterbench-ee8-web-granular.war on wildfly3
at org.wildfly.clustering.service.FunctionalService.start(FunctionalService.java:70)
at org.wildfly.clustering.service.AsyncServiceConfigurator$AsyncService.lambda$start$0(AsyncServiceConfigurator.java:117)
at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1982)
at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1348)
at java.lang.Thread.run(Thread.java:748)
at org.jboss.threads.JBossThread.run(JBossThread.java:485)
Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache clusterbench-ee8.ear.clusterbench-ee8-web-granular.war on wildfly3
at org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete(StateTransferManagerImpl.java:238)
at org.infinispan.cache.impl.CacheImpl.start(CacheImpl.java:1113)
at org.infinispan.cache.impl.AbstractDelegatingCache.start(AbstractDelegatingCache.java:511)
at org.infinispan.manager.DefaultCacheManager.wireAndStartCache(DefaultCacheManager.java:657)
at org.infinispan.manager.DefaultCacheManager.createCache(DefaultCacheManager.java:601)
at org.infinispan.manager.DefaultCacheManager.internalGetCache(DefaultCacheManager.java:484)
at org.infinispan.manager.DefaultCacheManager.getCache(DefaultCacheManager.java:468)
at org.infinispan.manager.DefaultCacheManager.getCache(DefaultCacheManager.java:454)
at org.jboss.as.clustering.infinispan.DefaultCacheContainer.getCache(DefaultCacheContainer.java:83)
at org.wildfly.clustering.infinispan.spi.service.CacheServiceConfigurator.get(CacheServiceConfigurator.java:77)
at org.wildfly.clustering.infinispan.spi.service.CacheServiceConfigurator.get(CacheServiceConfigurator.java:55)
at org.wildfly.clustering.service.FunctionalService.start(FunctionalService.java:67)
... 7 more
2019-04-19 07:49:42,236 INFO [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-2) WFLYJCA0019: Stopped Driver service with driver-name = h2
2019-04-19 07:49:42,239 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-2) ISPN000080: Disconnecting JGroups channel ejb
2019-04-19 07:49:42,259 INFO [org.jboss.as.server.deployment] (MSC service thread 1-1) WFLYSRV0208: Stopped subdeployment (runtime-name: clusterbench-ee8-web-granular.war) in 229611ms
2019-04-19 07:49:42,260 INFO [org.jboss.as.server.deployment] (MSC service thread 1-1) WFLYSRV0208: Stopped subdeployment (runtime-name: clusterbench-ee8-ejb.jar) in 229610ms
2019-04-19 07:49:42,260 INFO [org.jboss.as.server.deployment] (MSC service thread 1-1) WFLYSRV0208: Stopped subdeployment (runtime-name: clusterbench-ee8-web-passivating.war) in 229610ms
2019-04-19 07:49:42,260 INFO [org.jboss.as.server.deployment] (MSC service thread 1-2) WFLYSRV0208: Stopped subdeployment (runtime-name: clusterbench-ee8-web.war) in 229610ms
2019-04-19 07:49:42,261 INFO [org.wildfly.extension.undertow] (MSC service thread 1-2) WFLYUT0008: Undertow HTTPS listener https suspending
2019-04-19 07:49:42,261 INFO [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0008: Undertow AJP listener ajp suspending
2019-04-19 07:49:42,261 INFO [org.wildfly.extension.undertow] (MSC service thread 1-2) WFLYUT0007: Undertow HTTPS listener https stopped, was bound to 10.0.145.133:8443
2019-04-19 07:49:42,265 INFO [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0007: Undertow AJP listener ajp stopped, was bound to 10.0.145.133:8009
2019-04-19 07:49:42,290 INFO [org.jboss.as.server.deployment] (MSC service thread 1-1) WFLYSRV0028: Stopped deployment clusterbench-ee8.ear (runtime-name: clusterbench-ee8.ear) in 229640ms
2019-04-19 07:49:42,293 INFO [org.infinispan.CLUSTER] (ServerService Thread Pool -- 120) [Context=default] ISPN100008: Updating cache members list [wildfly4, wildfly1, wildfly2], topology id 36
2019-04-19 07:49:42,296 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 120) WFLYCLINF0003: Stopped default cache from server container
2019-04-19 07:49:42,296 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-1) ISPN000080: Disconnecting JGroups channel ejb
2019-04-19 07:49:42,323 INFO [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0008: Undertow HTTP listener default suspending
2019-04-19 07:49:42,325 INFO [org.infinispan.CLUSTER] (ServerService Thread Pool -- 128) [Context=client-mappings] ISPN100008: Updating cache members list [wildfly4, wildfly1, wildfly2], topology id 36
2019-04-19 07:49:42,327 INFO [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0007: Undertow HTTP listener default stopped, was bound to 10.0.145.133:8080
2019-04-19 07:49:42,327 INFO [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0004: Undertow 2.0.19.Final-redhat-00001 stopping
2019-04-19 07:49:42,329 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 128) WFLYCLINF0003: Stopped client-mappings cache from ejb container
2019-04-19 07:49:42,329 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-1) ISPN000080: Disconnecting JGroups channel ejb
2019-04-19 07:50:45,928 ERROR [org.jboss.as.controller.management-operation] (management I/O-1) WFLYCTL0013: Operation ("read-attribute") failed - address: ([
("subsystem" => "jgroups"),
("channel" => "ee"),
("protocol" => "TCP")
]) - failure description: "WFLYCTL0343: The service container has been destabilized by a previous operation and further runtime updates cannot be processed. Restart is required."
2019-04-19 07:50:50,928 ERROR [org.jboss.as.controller.management-operation] (management I/O-1) WFLYCTL0349: Timeout after [5] seconds waiting for service container stability while finalizing an operation. Process must be restarted. Step that first updated the service container was 'read-attribute' at address '[
("subsystem" => "jgroups"),
("channel" => "ee"),
("protocol" => "TCP")
]'
2019-04-19 07:50:50,929 ERROR [io.undertow.request] (management I/O-1) UT005071: Undertow request failed HttpServerExchange{ GET /metrics request {Accept=[application/openmetrics-text; version=0.0.1,text/plain;version=0.0.4;q=0.5,*/*;q=0.1], Accept-Encoding=[gzip], User-Agent=[Prometheus/2.9.1], X-Prometheus-Scrape-Timeout-Seconds=[10.000000], Host=[10.0.145.133:9990]} response {Access-Control-Allow-Origin=[*], Access-Control-Allow-Headers=[origin, content-type, accept, authorization], Access-Control-Allow-Credentials=[true], Content-Type=[text/plain], Access-Control-Allow-Methods=[GET, POST, PUT, DELETE, OPTIONS, HEAD], Access-Control-Max-Age=[1209600]}}: java.lang.IllegalStateException: WFLYMETRICS0003: Unable to read attribute send_buf_size on [
("subsystem" => "jgroups"),
("channel" => "ee"),
("protocol" => "TCP")
]: "WFLYCTL0343: The service container has been destabilized by a previous operation and further runtime updates cannot be processed. Restart is required.".
at org.wildfly.extension.microprofile.metrics.MetricCollector.lambda$collectResourceMetrics0$0(MetricCollector.java:143)
at org.wildfly.extension.microprofile.metrics.PrometheusCollector.collect(PrometheusCollector.java:51)
at io.prometheus.client.CollectorRegistry$MetricFamilySamplesEnumeration.findNextElement(CollectorRegistry.java:183)
at io.prometheus.client.CollectorRegistry$MetricFamilySamplesEnumeration.<init>(CollectorRegistry.java:147)
at io.prometheus.client.CollectorRegistry$MetricFamilySamplesEnumeration.<init>(CollectorRegistry.java:168)
at io.prometheus.client.CollectorRegistry.metricFamilySamples(CollectorRegistry.java:130)
at org.wildfly.extension.microprofile.metrics.MetricsContextService$1.handleRequest(MetricsContextService.java:100)
at org.jboss.as.domain.http.server.security.RealmReadinessHandler.handleRequest(RealmReadinessHandler.java:51)
at org.jboss.as.domain.http.server.security.ServerErrorReadinessHandler.handleRequest(ServerErrorReadinessHandler.java:35)
at io.undertow.server.handlers.PathHandler.handleRequest(PathHandler.java:91)
at io.undertow.server.handlers.ChannelUpgradeHandler.handleRequest(ChannelUpgradeHandler.java:211)
at io.undertow.server.handlers.cache.CacheHandler.handleRequest(CacheHandler.java:92)
at io.undertow.server.handlers.error.SimpleErrorPageHandler.handleRequest(SimpleErrorPageHandler.java:78)
at io.undertow.server.handlers.CanonicalPathHandler.handleRequest(CanonicalPathHandler.java:49)
at org.jboss.as.domain.http.server.ManagementHttpRequestHandler.handleRequest(ManagementHttpRequestHandler.java:57)
at org.jboss.as.domain.http.server.cors.CorsHttpHandler.handleRequest(CorsHttpHandler.java:75)
at org.jboss.as.domain.http.server.ManagementHttpServer$UpgradeFixHandler.handleRequest(ManagementHttpServer.java:662)
at io.undertow.server.Connectors.executeRootHandler(Connectors.java:364)
at io.undertow.server.protocol.http.HttpReadListener.handleEventWithNoRunningRequest(HttpReadListener.java:255)
at io.undertow.server.protocol.http.HttpReadListener.handleEvent(HttpReadListener.java:136)
at io.undertow.server.protocol.http.HttpReadListener.handleEvent(HttpReadListener.java:59)
at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
at org.xnio.conduits.ReadReadyHandler$ChannelListenerHandler.readReady(ReadReadyHandler.java:66)
at org.xnio.nio.NioSocketConduit.handleReady(NioSocketConduit.java:89)
at org.xnio.nio.WorkerThread.run(WorkerThread.java:591)
2019-04-19 07:50:50,930 ERROR [org.xnio.nio] (management I/O-1) XNIO000011: Task org.xnio.nio.QueuedNioTcpServer$1@71046d0f failed with an exception: java.util.concurrent.RejectedExecutionException: XNIO007007: Thread is terminating
at org.xnio.nio.WorkerThread.execute(WorkerThread.java:620)
at org.xnio.nio.QueuedNioTcpServer$1.run(QueuedNioTcpServer.java:133)
at org.xnio.nio.WorkerThread.safeRun(WorkerThread.java:612)
at org.xnio.nio.WorkerThread.run(WorkerThread.java:479)
2019-04-19 07:50:50,930 ERROR [org.xnio.nio] (management I/O-1) XNIO000011: Task org.xnio.nio.QueuedNioTcpServer$1@71046d0f failed with an exception: java.util.concurrent.RejectedExecutionException: XNIO007007: Thread is terminating
at org.xnio.nio.WorkerThread.execute(WorkerThread.java:620)
at org.xnio.nio.QueuedNioTcpServer$1.run(QueuedNioTcpServer.java:133)
at org.xnio.nio.WorkerThread.safeRun(WorkerThread.java:612)
at org.xnio.nio.WorkerThread.run(WorkerThread.java:479)
2019-04-19 07:50:50,931 ERROR [org.xnio.nio] (management I/O-1) XNIO000011: Task org.xnio.nio.QueuedNioTcpServer$1@71046d0f failed with an exception: java.util.concurrent.RejectedExecutionException: XNIO007007: Thread is terminating
at org.xnio.nio.WorkerThread.execute(WorkerThread.java:620)
at org.xnio.nio.QueuedNioTcpServer$1.run(QueuedNioTcpServer.java:133)
at org.xnio.nio.WorkerThread.safeRun(WorkerThread.java:612)
at org.xnio.nio.WorkerThread.run(WorkerThread.java:479)
2019-04-19 07:50:50,931 ERROR [org.xnio.nio] (management I/O-1) XNIO000011: Task org.xnio.nio.QueuedNioTcpServer$1@71046d0f failed with an exception: java.util.concurrent.RejectedExecutionException: XNIO007007: Thread is terminating
at org.xnio.nio.WorkerThread.execute(WorkerThread.java:620)
at org.xnio.nio.QueuedNioTcpServer$1.run(QueuedNioTcpServer.java:133)
at org.xnio.nio.WorkerThread.safeRun(WorkerThread.java:612)
at org.xnio.nio.WorkerThread.run(WorkerThread.java:479)
2019-04-19 07:50:50,931 ERROR [org.xnio.nio] (management I/O-1) XNIO000011: Task org.xnio.nio.QueuedNioTcpServer$1@71046d0f failed with an exception: java.util.concurrent.RejectedExecutionException: XNIO007007: Thread is terminating
at org.xnio.nio.WorkerThread.execute(WorkerThread.java:620)
at org.xnio.nio.QueuedNioTcpServer$1.run(QueuedNioTcpServer.java:133)
at org.xnio.nio.WorkerThread.safeRun(WorkerThread.java:612)
at org.xnio.nio.WorkerThread.run(WorkerThread.java:479)
2019-04-19 07:50:50,931 ERROR [org.xnio.nio] (management I/O-1) XNIO000011: Task org.xnio.nio.QueuedNioTcpServer$1@71046d0f failed with an exception: java.util.concurrent.RejectedExecutionException: XNIO007007: Thread is terminating
at org.xnio.nio.WorkerThread.execute(WorkerThread.java:620)
at org.xnio.nio.QueuedNioTcpServer$1.run(QueuedNioTcpServer.java:133)
at org.xnio.nio.WorkerThread.safeRun(WorkerThread.java:612)
at org.xnio.nio.WorkerThread.run(WorkerThread.java:479)
2019-04-19 07:50:50,931 ERROR [org.xnio.nio] (management I/O-1) XNIO000011: Task org.xnio.nio.QueuedNioTcpServer$1@71046d0f failed with an exception: java.util.concurrent.RejectedExecutionException: XNIO007007: Thread is terminating
at org.xnio.nio.WorkerThread.execute(WorkerThread.java:620)
at org.xnio.nio.QueuedNioTcpServer$1.run(QueuedNioTcpServer.java:133)
at org.xnio.nio.WorkerThread.safeRun(WorkerThread.java:612)
at org.xnio.nio.WorkerThread.run(WorkerThread.java:479)
2019-04-19 07:50:50,948 INFO [org.jboss.as] (MSC service thread 1-2) WFLYSRV0050: JBoss EAP CD 7.3.0.CD16 (WildFly Core 8.0.1.Final-redhat-00001) stopped in 298300ms
Complete log here.