[Red Hat JIRA] (WFLY-14380) Cant configure Let's Encrypt simple steps
by erick leal (Jira)
[ https://issues.redhat.com/browse/WFLY-14380?page=com.atlassian.jira.plugi... ]
erick leal closed WFLY-14380.
-----------------------------
Resolution: Not a Bug
> Cant configure Let's Encrypt simple steps
> -----------------------------------------
>
> Key: WFLY-14380
> URL: https://issues.redhat.com/browse/WFLY-14380
> Project: WildFly
> Issue Type: Bug
> Components: Security
> Affects Versions: 22.0.0.Final
> Reporter: erick leal
> Priority: Major
> Attachments: Capturar-1.PNG, Capturar.PNG, Capturar5-1.PNG, Capturar5.PNG, ddd.PNG
>
>
> I'm tyring to configure Let's Encrypt in my server, and I followed instructions that said to simple type security enable-ssl-http-server --interactive --lets-encrypt
> But I believe because I'm in Windows I ran into the issue described in the picture below
> !Capturar.PNG!
--
This message was sent by Atlassian Jira
(v8.13.1#813001)
5 years, 2 months
- 1
- 0
[Red Hat JIRA] (WFLY-14380) Cant configure Let's Encrypt simple steps
by erick leal (Jira)
[ https://issues.redhat.com/browse/WFLY-14380?page=com.atlassian.jira.plugi... ]
erick leal commented on WFLY-14380:
-----------------------------------
thank you [~fjuma] , Very helpful info, I believe is is some problem at my provider, sorry.
> Cant configure Let's Encrypt simple steps
> -----------------------------------------
>
> Key: WFLY-14380
> URL: https://issues.redhat.com/browse/WFLY-14380
> Project: WildFly
> Issue Type: Bug
> Components: Security
> Affects Versions: 22.0.0.Final
> Reporter: erick leal
> Priority: Major
> Attachments: Capturar-1.PNG, Capturar.PNG, Capturar5-1.PNG, Capturar5.PNG, ddd.PNG
>
>
> I'm tyring to configure Let's Encrypt in my server, and I followed instructions that said to simple type security enable-ssl-http-server --interactive --lets-encrypt
> But I believe because I'm in Windows I ran into the issue described in the picture below
> !Capturar.PNG!
--
This message was sent by Atlassian Jira
(v8.13.1#813001)
5 years, 2 months
- 1
- 0
[Red Hat JIRA] (WFLY-14380) Cant configure Let's Encrypt simple steps
by Farah Juma (Jira)
[ https://issues.redhat.com/browse/WFLY-14380?page=com.atlassian.jira.plugi... ]
Farah Juma edited comment on WFLY-14380 at 2/8/21 2:29 PM:
-----------------------------------------------------------
{quote}Another small thing is that when it finished the server was rebooted instead of only reload the certificate...
{quote}
When using the {{security enable-ssl-http-server}} command, the server will be automatically reloaded for you since this command is also configuring an {{ssl-context}} for your server and updating Undertow to make use of this newly configured {{ssl-context}}. You should see a message similar to the following that indicates that the server has been successfully reloaded:
{code}
Do you confirm y/n :y
Server reloaded.
SSL enabled for default-server
ssl-context is ssl-context-8eae80c5-4569-4f24-a1fd-063a1a4bc8bf
key-manager is key-manager-8eae80c5-4569-4f24-a1fd-063a1a4bc8bf
key-store is key-store-8eae80c5-4569-4f24-a1fd-063a1a4bc8bf
{code}
When it is time to renew your certificate, you will only need to re-initialize your {{key-manager}}.
was (Author: fjuma):
{quote}
Another small thing is that when it finished the server was rebooted instead of only reload the certificate...
{quote}
When using the {{security enable-ssl-http-server}} command, the server will be automatically reloaded for you since this command is also configuring an {{ssl-context}} for your server and updating Undertow to make use of this newly configured {{ssl-context}}. When it is time to renew your certificate, you will only need to re-initialize your {{key-manager}}.
> Cant configure Let's Encrypt simple steps
> -----------------------------------------
>
> Key: WFLY-14380
> URL: https://issues.redhat.com/browse/WFLY-14380
> Project: WildFly
> Issue Type: Bug
> Components: Security
> Affects Versions: 22.0.0.Final
> Reporter: erick leal
> Priority: Major
> Attachments: Capturar-1.PNG, Capturar.PNG, Capturar5-1.PNG, Capturar5.PNG, ddd.PNG
>
>
> I'm tyring to configure Let's Encrypt in my server, and I followed instructions that said to simple type security enable-ssl-http-server --interactive --lets-encrypt
> But I believe because I'm in Windows I ran into the issue described in the picture below
> !Capturar.PNG!
--
This message was sent by Atlassian Jira
(v8.13.1#813001)
5 years, 2 months
- 1
- 0
[Red Hat JIRA] (WFCORE-5277) Env variables to set installation and data directories
by Jean Francois Denise (Jira)
Jean Francois Denise created WFCORE-5277:
--------------------------------------------
Summary: Env variables to set installation and data directories
Key: WFCORE-5277
URL: https://issues.redhat.com/browse/WFCORE-5277
Project: WildFly Core
Issue Type: Enhancement
Components: Bootable JAR
Reporter: Jean Francois Denise
Assignee: Jean Francois Denise
WildFly Operator has a need to set the Bootable JAR installation dir and data dir to some specific locations. The way to do it is thanks to Environment variables.
A bootable JAR needs to recognize JBOSS_BOOTABLE_HOME and JBOSS_BOOTABLE_DATA_DIR env variables for the Operator to properly operate with an Image containing a Bootable JAR.
--
This message was sent by Atlassian Jira
(v8.13.1#813001)
5 years, 2 months
- 1
- 0
[Red Hat JIRA] (WFCORE-5276) Upgrade jgit to 5.10.0.202012080955-r
by Emmanuel Hugonnet (Jira)
Emmanuel Hugonnet created WFCORE-5276:
-----------------------------------------
Summary: Upgrade jgit to 5.10.0.202012080955-r
Key: WFCORE-5276
URL: https://issues.redhat.com/browse/WFCORE-5276
Project: WildFly Core
Issue Type: Component Upgrade
Components: Server
Affects Versions: 14.0.0.Final
Reporter: Emmanuel Hugonnet
Assignee: Emmanuel Hugonnet
Upgrade jgit library
--
This message was sent by Atlassian Jira
(v8.13.1#813001)
5 years, 2 months
- 1
- 0
[Red Hat JIRA] (WFCORE-5275) Socket handler is holding server to start
by James Perkins (Jira)
[ https://issues.redhat.com/browse/WFCORE-5275?page=com.atlassian.jira.plug... ]
James Perkins updated WFCORE-5275:
----------------------------------
Description:
On EAP 7.3 on OCP and has configured the socket-handler as below:
{code}
<async-handler name="async-logstash-handler">
<queue-length value="${env.LOGGING_BUFFER_SIZE:1048576}"/>
<overflow-action value="discard"/>
<subhandlers>
<handler name="logstash-handler"/>
</subhandlers>
</async-handler>
<console-handler name="CONSOLE">
<formatter>
<named-formatter name="COLOR-PATTERN"/>
</formatter>
</console-handler>
<socket-handler name="logstash-handler" block-on-reconnect="true" outbound-socket-binding-ref="logstash">
<named-formatter name="logstash-json-formatter"/>
</socket-handler>
{code}
The formatter:
{code}
<formatter name="logstash-json-formatter">
<json-formatter>
<exception-output-type value="formatted"/>
<key-overrides host-name="host" logger-name="category" message="log-message" thread-id="thread" thread-name="thread-name" timestamp="@timestamp"/>
<meta-data>
<property name="@version" value="1"/>
<property name="lhtappid" value="2038"/>
<property name="stage" value="dev"/>
</meta-data>
</json-formatter>
</formatter>
{code}
The socket binding :
{code}
<outbound-socket-binding name="logstash">
<remote-destination host="hostname" port="8080"/>
</outbound-socket-binding>
{code}
When based on network policy on OCP the traffic on logstash.lhtlogging-nonprod.svc.cluster.local at 80080 will be enabled. This configuration works well, however if we disable the traffic the server never get started and throws the following error:
{code}
09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-3) WFLYJCA0002: Bound JCA ConnectionFactory [java:/JmsXA]
09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-2) WFLYJCA0118: Binding connection factory named java:/JmsXA to alias java:jboss/DefaultJMSConnectionFactory
09:49:06,466 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0348: Timeout after [90] seconds waiting for service container stability. Operation will roll back. Step that first updated the service container was 'add' at address '[
("core-service" => "management"),
("management-interface" => "http-interface")
]'
Failed to invoke setter setOverflowAction with value null
.java.lang.reflect.InvocationTargetException
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.jboss.logmanager.config.AbstractPropertyConfiguration$1.rollback(AbstractPropertyConfiguration.java:244)
at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:437)
at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:396)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.NullPointerException: overflowAction is null
at org.jboss.logmanager.handlers.AsyncHandler.setOverflowAction(AsyncHandler.java:117)
... 26 more
{code}
When check the thread dumps from the same time, we find that there is a long running thread, which is also mentioned in earlier update:
{code}
"MSC service thread 1-2" #18 prio=5 os_prio=0 cpu=616.95ms elapsed=120.44s tid=0x000055790ece0000 nid=0x78b runnable [0x00007f37a1ee8000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketConnect(java.base(a)11.0.9/Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(java.base@11.0.9/AbstractPlainSocketImpl.java:399)
locked <0x00000000d64c8470> (a java.net.SocksSocketImpl)
at java.net.AbstractPlainSocketImpl.connectToAddress(java.base@11.0.9/AbstractPlainSocketImpl.java:242)
at java.net.AbstractPlainSocketImpl.connect(java.base@11.0.9/AbstractPlainSocketImpl.java:224)
at java.net.SocksSocketImpl.connect(java.base@11.0.9/SocksSocketImpl.java:403)
at java.net.Socket.connect(java.base@11.0.9/Socket.java:609)
at java.net.Socket.connect(java.base@11.0.9/Socket.java:558)
at org.jboss.as.network.OutboundSocketBinding.connect(OutboundSocketBinding.java:125)
at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$WildFlyClientSocketFactory.createSocket(SocketHandlerResourceDefinition.java:441)
at org.jboss.logmanager.handlers.TcpOutputStream.<init>(TcpOutputStream.java:165)
at org.jboss.logmanager.handlers.SocketHandler.createOutputStream(SocketHandler.java:453)
at org.jboss.logmanager.handlers.SocketHandler.initialize(SocketHandler.java:422)
at org.jboss.logmanager.handlers.SocketHandler.doPublish(SocketHandler.java:211)
locked <0x00000000f49b7a10> (a java.lang.Object)
at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:77)
at org.jboss.logmanager.handlers.DelayedHandler.publishToChildren(DelayedHandler.java:213)
at org.jboss.logmanager.handlers.DelayedHandler.activate(DelayedHandler.java:205)
locked <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
at org.jboss.logmanager.handlers.DelayedHandler.setHandlers(DelayedHandler.java:124)
at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1.start(SocketHandlerResourceDefinition.java:252)
locked <0x00000000f49b55a0> (a org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1)
at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1739)
at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1701)
at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1559)
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:1363)
at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)
Which at times blocks the boot controll thread:
"Controller Boot Thread" #23 prio=5 os_prio=0 cpu=564.32ms elapsed=118.63s tid=0x000055790e6e4800 nid=0x7a2 waiting for monitor entry [0x00007f37a13f2000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.jboss.logmanager.handlers.DelayedHandler.close(DelayedHandler.java:82)
waiting to lock <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
at org.jboss.logmanager.config.HandlerConfigurationImpl$9.rollback(HandlerConfigurationImpl.java:413)
at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
at org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
locked <0x00000000f511e1d8> (a java.lang.Object)
at org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
at org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
at org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
at org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
at org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
at org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
at org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
at org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
at org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
at org.jboss.as.server.ServerService.boot(ServerService.java:437)
at org.jboss.as.server.ServerService.boot(ServerService.java:396)
at org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)
{code}
I don't find any issues with the configuration. I see in the code the socket is trying to connect without and timeout and the same is missing from the configuration.
Either the server where the socket is listening should be in start condition to avoid the failure from boot or we should avoid the server from a failure to boot if no processes is running on the socket in socket-handler.
The issue is rarely reproducible on local machine.
was:
CU is on EAP 7.3 on OCP and has configured the socket-handler as below:
<async-handler name="async-logstash-handler">
<queue-length value="${env.LHT_LOGGING_BUFFER_SIZE:1048576}"/>
<overflow-action value="discard"/>
<subhandlers>
<handler name="logstash-handler"/>
</subhandlers>
</async-handler>
<console-handler name="CONSOLE">
<formatter>
<named-formatter name="COLOR-PATTERN"/>
</formatter>
</console-handler>
<socket-handler name="logstash-handler" block-on-reconnect="true" outbound-socket-binding-ref="logstash">
<named-formatter name="logstash-json-formatter"/>
</socket-handler>
The formatter:
<formatter name="logstash-json-formatter">
<json-formatter>
<exception-output-type value="formatted"/>
<key-overrides host-name="host" logger-name="category" message="log-message" thread-id="thread" thread-name="thread-name" timestamp="@timestamp"/>
<meta-data>
<property name="@version" value="1"/>
<property name="lhtappid" value="2038"/>
<property name="namespace" value="lht-platform-sample-applications-nonprod"/>
<property name="stage" value="dev"/>
</meta-data>
</json-formatter>
</formatter>
The socket binding :
<outbound-socket-binding name="logstash">
<remote-destination host="logstash.lhtlogging-nonprod.svc.cluster.local" port="8080"/>
</outbound-socket-binding>
When based on network policy on OCP the traffic on logstash.lhtlogging-nonprod.svc.cluster.local at 80080 will be enabled. This configuration works well, however if we disable the traffic the server never get started and throws the following error:
09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-3) WFLYJCA0002: Bound JCA ConnectionFactory [java:/JmsXA]
09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-2) WFLYJCA0118: Binding connection factory named java:/JmsXA to alias java:jboss/DefaultJMSConnectionFactory
09:49:06,466 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0348: Timeout after [90] seconds waiting for service container stability. Operation will roll back. Step that first updated the service container was 'add' at address '[
("core-service" => "management"),
("management-interface" => "http-interface")
]'
Failed to invoke setter setOverflowAction with value null
.java.lang.reflect.InvocationTargetException
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.jboss.logmanager.config.AbstractPropertyConfiguration$1.rollback(AbstractPropertyConfiguration.java:244)
at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:437)
at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:396)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.NullPointerException: overflowAction is null
at org.jboss.logmanager.handlers.AsyncHandler.setOverflowAction(AsyncHandler.java:117)
... 26 more
When check the thread dumps from the same time, we find that there is a long running thread, which is also mentioned in earlier update:
"MSC service thread 1-2" #18 prio=5 os_prio=0 cpu=616.95ms elapsed=120.44s tid=0x000055790ece0000 nid=0x78b runnable [0x00007f37a1ee8000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketConnect(java.base(a)11.0.9/Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(java.base@11.0.9/AbstractPlainSocketImpl.java:399)
- locked <0x00000000d64c8470> (a java.net.SocksSocketImpl)
at java.net.AbstractPlainSocketImpl.connectToAddress(java.base@11.0.9/AbstractPlainSocketImpl.java:242)
at java.net.AbstractPlainSocketImpl.connect(java.base@11.0.9/AbstractPlainSocketImpl.java:224)
at java.net.SocksSocketImpl.connect(java.base@11.0.9/SocksSocketImpl.java:403)
at java.net.Socket.connect(java.base@11.0.9/Socket.java:609)
at java.net.Socket.connect(java.base@11.0.9/Socket.java:558)
at org.jboss.as.network.OutboundSocketBinding.connect(OutboundSocketBinding.java:125)
at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$WildFlyClientSocketFactory.createSocket(SocketHandlerResourceDefinition.java:441)
at org.jboss.logmanager.handlers.TcpOutputStream.<init>(TcpOutputStream.java:165)
at org.jboss.logmanager.handlers.SocketHandler.createOutputStream(SocketHandler.java:453)
at org.jboss.logmanager.handlers.SocketHandler.initialize(SocketHandler.java:422)
at org.jboss.logmanager.handlers.SocketHandler.doPublish(SocketHandler.java:211)
- locked <0x00000000f49b7a10> (a java.lang.Object)
at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:77)
at org.jboss.logmanager.handlers.DelayedHandler.publishToChildren(DelayedHandler.java:213)
at org.jboss.logmanager.handlers.DelayedHandler.activate(DelayedHandler.java:205)
- locked <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
at org.jboss.logmanager.handlers.DelayedHandler.setHandlers(DelayedHandler.java:124)
at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1.start(SocketHandlerResourceDefinition.java:252)
- locked <0x00000000f49b55a0> (a org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1)
at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1739)
at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1701)
at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1559)
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:1363)
at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)
Which at times blocks the boot controll thread:
"Controller Boot Thread" #23 prio=5 os_prio=0 cpu=564.32ms elapsed=118.63s tid=0x000055790e6e4800 nid=0x7a2 waiting for monitor entry [0x00007f37a13f2000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.jboss.logmanager.handlers.DelayedHandler.close(DelayedHandler.java:82)
- waiting to lock <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
at org.jboss.logmanager.config.HandlerConfigurationImpl$9.rollback(HandlerConfigurationImpl.java:413)
at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
at org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
- locked <0x00000000f511e1d8> (a java.lang.Object)
at org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
at org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
at org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
at org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
at org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
at org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
at org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
at org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
at org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
at org.jboss.as.server.ServerService.boot(ServerService.java:437)
at org.jboss.as.server.ServerService.boot(ServerService.java:396)
at org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)~~~
I don't find any issues with the configuration. I see in the code the socket is trying to connect without and timeout and the same is missing from the configuration.
Either the server where the socket is listening should be in start condition to avoid the failure from boot or we should avoid the server from a failure to boot if no processes is running on the socket in socket-handler.
The issue is rarely reproducible on local machine.
> Socket handler is holding server to start
> -----------------------------------------
>
> Key: WFCORE-5275
> URL: https://issues.redhat.com/browse/WFCORE-5275
> Project: WildFly Core
> Issue Type: Bug
> Components: Logging
> Reporter: James Perkins
> Assignee: James Perkins
> Priority: Major
>
> On EAP 7.3 on OCP and has configured the socket-handler as below:
> {code}
> <async-handler name="async-logstash-handler">
> <queue-length value="${env.LOGGING_BUFFER_SIZE:1048576}"/>
> <overflow-action value="discard"/>
> <subhandlers>
> <handler name="logstash-handler"/>
> </subhandlers>
> </async-handler>
> <console-handler name="CONSOLE">
> <formatter>
> <named-formatter name="COLOR-PATTERN"/>
> </formatter>
> </console-handler>
> <socket-handler name="logstash-handler" block-on-reconnect="true" outbound-socket-binding-ref="logstash">
> <named-formatter name="logstash-json-formatter"/>
> </socket-handler>
> {code}
> The formatter:
> {code}
> <formatter name="logstash-json-formatter">
> <json-formatter>
> <exception-output-type value="formatted"/>
> <key-overrides host-name="host" logger-name="category" message="log-message" thread-id="thread" thread-name="thread-name" timestamp="@timestamp"/>
> <meta-data>
> <property name="@version" value="1"/>
> <property name="lhtappid" value="2038"/>
> <property name="stage" value="dev"/>
> </meta-data>
> </json-formatter>
> </formatter>
> {code}
> The socket binding :
> {code}
> <outbound-socket-binding name="logstash">
> <remote-destination host="hostname" port="8080"/>
> </outbound-socket-binding>
> {code}
> When based on network policy on OCP the traffic on logstash.lhtlogging-nonprod.svc.cluster.local at 80080 will be enabled. This configuration works well, however if we disable the traffic the server never get started and throws the following error:
> {code}
> 09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-3) WFLYJCA0002: Bound JCA ConnectionFactory [java:/JmsXA]
> 09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-2) WFLYJCA0118: Binding connection factory named java:/JmsXA to alias java:jboss/DefaultJMSConnectionFactory
> 09:49:06,466 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0348: Timeout after [90] seconds waiting for service container stability. Operation will roll back. Step that first updated the service container was 'add' at address '[
> ("core-service" => "management"),
> ("management-interface" => "http-interface")
> ]'
> Failed to invoke setter setOverflowAction with value null
> .java.lang.reflect.InvocationTargetException
> at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.base/java.lang.reflect.Method.invoke(Method.java:566)
> at org.jboss.logmanager.config.AbstractPropertyConfiguration$1.rollback(AbstractPropertyConfiguration.java:244)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
> at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
> at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
> at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
> at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:437)
> at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:396)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
> at java.base/java.lang.Thread.run(Thread.java:834)
> Caused by: java.lang.NullPointerException: overflowAction is null
> at org.jboss.logmanager.handlers.AsyncHandler.setOverflowAction(AsyncHandler.java:117)
> ... 26 more
> {code}
> When check the thread dumps from the same time, we find that there is a long running thread, which is also mentioned in earlier update:
> {code}
> "MSC service thread 1-2" #18 prio=5 os_prio=0 cpu=616.95ms elapsed=120.44s tid=0x000055790ece0000 nid=0x78b runnable [0x00007f37a1ee8000]
> java.lang.Thread.State: RUNNABLE
> at java.net.PlainSocketImpl.socketConnect(java.base(a)11.0.9/Native Method)
> at java.net.AbstractPlainSocketImpl.doConnect(java.base@11.0.9/AbstractPlainSocketImpl.java:399)
> locked <0x00000000d64c8470> (a java.net.SocksSocketImpl)
> at java.net.AbstractPlainSocketImpl.connectToAddress(java.base@11.0.9/AbstractPlainSocketImpl.java:242)
> at java.net.AbstractPlainSocketImpl.connect(java.base@11.0.9/AbstractPlainSocketImpl.java:224)
> at java.net.SocksSocketImpl.connect(java.base@11.0.9/SocksSocketImpl.java:403)
> at java.net.Socket.connect(java.base@11.0.9/Socket.java:609)
> at java.net.Socket.connect(java.base@11.0.9/Socket.java:558)
> at org.jboss.as.network.OutboundSocketBinding.connect(OutboundSocketBinding.java:125)
> at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$WildFlyClientSocketFactory.createSocket(SocketHandlerResourceDefinition.java:441)
> at org.jboss.logmanager.handlers.TcpOutputStream.<init>(TcpOutputStream.java:165)
> at org.jboss.logmanager.handlers.SocketHandler.createOutputStream(SocketHandler.java:453)
> at org.jboss.logmanager.handlers.SocketHandler.initialize(SocketHandler.java:422)
> at org.jboss.logmanager.handlers.SocketHandler.doPublish(SocketHandler.java:211)
> locked <0x00000000f49b7a10> (a java.lang.Object)
> at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:77)
> at org.jboss.logmanager.handlers.DelayedHandler.publishToChildren(DelayedHandler.java:213)
> at org.jboss.logmanager.handlers.DelayedHandler.activate(DelayedHandler.java:205)
> locked <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
> at org.jboss.logmanager.handlers.DelayedHandler.setHandlers(DelayedHandler.java:124)
> at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1.start(SocketHandlerResourceDefinition.java:252)
> locked <0x00000000f49b55a0> (a org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1)
> at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1739)
> at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1701)
> at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1559)
> 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:1363)
> at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)
> Which at times blocks the boot controll thread:
> "Controller Boot Thread" #23 prio=5 os_prio=0 cpu=564.32ms elapsed=118.63s tid=0x000055790e6e4800 nid=0x7a2 waiting for monitor entry [0x00007f37a13f2000]
> java.lang.Thread.State: BLOCKED (on object monitor)
> at org.jboss.logmanager.handlers.DelayedHandler.close(DelayedHandler.java:82)
> waiting to lock <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
> at org.jboss.logmanager.config.HandlerConfigurationImpl$9.rollback(HandlerConfigurationImpl.java:413)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
> at org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
> locked <0x00000000f511e1d8> (a java.lang.Object)
> at org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
> at org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
> at org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
> at org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
> at org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
> at org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
> at org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
> at org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
> at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
> at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
> at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
> at org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
> at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
> at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
> at org.jboss.as.server.ServerService.boot(ServerService.java:437)
> at org.jboss.as.server.ServerService.boot(ServerService.java:396)
> at org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
> at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)
> {code}
> I don't find any issues with the configuration. I see in the code the socket is trying to connect without and timeout and the same is missing from the configuration.
> Either the server where the socket is listening should be in start condition to avoid the failure from boot or we should avoid the server from a failure to boot if no processes is running on the socket in socket-handler.
> The issue is rarely reproducible on local machine.
--
This message was sent by Atlassian Jira
(v8.13.1#813001)
5 years, 2 months
- 1
- 0
[Red Hat JIRA] (WFCORE-5275) Socket handler is holding server to start
by James Perkins (Jira)
[ https://issues.redhat.com/browse/WFCORE-5275?page=com.atlassian.jira.plug... ]
James Perkins updated WFCORE-5275:
----------------------------------
Steps to Reproduce:
CU is on EAP 7.3 on OCP and has configured the socket-handler as below:
{code}
<async-handler name="async-logstash-handler">
<queue-length value="${env.LHT_LOGGING_BUFFER_SIZE:1048576}"/>
<overflow-action value="discard"/>
<subhandlers>
<handler name="logstash-handler"/>
</subhandlers>
</async-handler>
<console-handler name="CONSOLE">
<formatter>
<named-formatter name="COLOR-PATTERN"/>
</formatter>
</console-handler>
<socket-handler name="logstash-handler" block-on-reconnect="true" outbound-socket-binding-ref="logstash">
<named-formatter name="logstash-json-formatter"/>
</socket-handler>
{code}
The formatter:
{code}
<formatter name="logstash-json-formatter">
<json-formatter>
<exception-output-type value="formatted"/>
<key-overrides host-name="host" logger-name="category" message="log-message" thread-id="thread" thread-name="thread-name" timestamp="@timestamp"/>
<meta-data>
<property name="@version" value="1"/>
<property name="lhtappid" value="2038"/>
<property name="namespace" value="lht-platform-sample-applications-nonprod"/>
<property name="stage" value="dev"/>
</meta-data>
</json-formatter>
</formatter>
{code}
The socket binding :
{code}
<outbound-socket-binding name="logstash">
<remote-destination host="logstash.lhtlogging-nonprod.svc.cluster.local" port="8080"/>
</outbound-socket-binding>
{code}
When based on network policy on OCP the traffic on logstash.lhtlogging-nonprod.svc.cluster.local at 80080 will be enabled. This configuration works well, however if we disable the traffic the server never get started and throws the following error:
{code}
09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-3) WFLYJCA0002: Bound JCA ConnectionFactory [java:/JmsXA]
09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-2) WFLYJCA0118: Binding connection factory named java:/JmsXA to alias java:jboss/DefaultJMSConnectionFactory
09:49:06,466 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0348: Timeout after [90] seconds waiting for service container stability. Operation will roll back. Step that first updated the service container was 'add' at address '[
("core-service" => "management"),
("management-interface" => "http-interface")
]'
Failed to invoke setter setOverflowAction with value null
.java.lang.reflect.InvocationTargetException
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.jboss.logmanager.config.AbstractPropertyConfiguration$1.rollback(AbstractPropertyConfiguration.java:244)
at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:437)
at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:396)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.NullPointerException: overflowAction is null
at org.jboss.logmanager.handlers.AsyncHandler.setOverflowAction(AsyncHandler.java:117)
... 26 more
{code}
When check the thread dumps from the same time, we find that there is a long running thread, which is also mentioned in earlier update:
{code}
"MSC service thread 1-2" #18 prio=5 os_prio=0 cpu=616.95ms elapsed=120.44s tid=0x000055790ece0000 nid=0x78b runnable [0x00007f37a1ee8000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketConnect(java.base(a)11.0.9/Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(java.base@11.0.9/AbstractPlainSocketImpl.java:399)
- locked <0x00000000d64c8470> (a java.net.SocksSocketImpl)
at java.net.AbstractPlainSocketImpl.connectToAddress(java.base@11.0.9/AbstractPlainSocketImpl.java:242)
at java.net.AbstractPlainSocketImpl.connect(java.base@11.0.9/AbstractPlainSocketImpl.java:224)
at java.net.SocksSocketImpl.connect(java.base@11.0.9/SocksSocketImpl.java:403)
at java.net.Socket.connect(java.base@11.0.9/Socket.java:609)
at java.net.Socket.connect(java.base@11.0.9/Socket.java:558)
at org.jboss.as.network.OutboundSocketBinding.connect(OutboundSocketBinding.java:125)
at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$WildFlyClientSocketFactory.createSocket(SocketHandlerResourceDefinition.java:441)
at org.jboss.logmanager.handlers.TcpOutputStream.<init>(TcpOutputStream.java:165)
at org.jboss.logmanager.handlers.SocketHandler.createOutputStream(SocketHandler.java:453)
at org.jboss.logmanager.handlers.SocketHandler.initialize(SocketHandler.java:422)
at org.jboss.logmanager.handlers.SocketHandler.doPublish(SocketHandler.java:211)
- locked <0x00000000f49b7a10> (a java.lang.Object)
at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:77)
at org.jboss.logmanager.handlers.DelayedHandler.publishToChildren(DelayedHandler.java:213)
at org.jboss.logmanager.handlers.DelayedHandler.activate(DelayedHandler.java:205)
- locked <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
at org.jboss.logmanager.handlers.DelayedHandler.setHandlers(DelayedHandler.java:124)
at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1.start(SocketHandlerResourceDefinition.java:252)
- locked <0x00000000f49b55a0> (a org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1)
at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1739)
at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1701)
at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1559)
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:1363)
at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)
{code}
Which at times blocks the boot controll thread:
{code}
"Controller Boot Thread" #23 prio=5 os_prio=0 cpu=564.32ms elapsed=118.63s tid=0x000055790e6e4800 nid=0x7a2 waiting for monitor entry [0x00007f37a13f2000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.jboss.logmanager.handlers.DelayedHandler.close(DelayedHandler.java:82)
- waiting to lock <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
at org.jboss.logmanager.config.HandlerConfigurationImpl$9.rollback(HandlerConfigurationImpl.java:413)
at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
at org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
- locked <0x00000000f511e1d8> (a java.lang.Object)
at org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
at org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
at org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
at org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
at org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
at org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
at org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
at org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
at org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
at org.jboss.as.server.ServerService.boot(ServerService.java:437)
at org.jboss.as.server.ServerService.boot(ServerService.java:396)
at org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)
{code}
was:
CU is on EAP 7.3 on OCP and has configured the socket-handler as below:
<async-handler name="async-logstash-handler">
<queue-length value="${env.LHT_LOGGING_BUFFER_SIZE:1048576}"/>
<overflow-action value="discard"/>
<subhandlers>
<handler name="logstash-handler"/>
</subhandlers>
</async-handler>
<console-handler name="CONSOLE">
<formatter>
<named-formatter name="COLOR-PATTERN"/>
</formatter>
</console-handler>
<socket-handler name="logstash-handler" block-on-reconnect="true" outbound-socket-binding-ref="logstash">
<named-formatter name="logstash-json-formatter"/>
</socket-handler>
The formatter:
<formatter name="logstash-json-formatter">
<json-formatter>
<exception-output-type value="formatted"/>
<key-overrides host-name="host" logger-name="category" message="log-message" thread-id="thread" thread-name="thread-name" timestamp="@timestamp"/>
<meta-data>
<property name="@version" value="1"/>
<property name="lhtappid" value="2038"/>
<property name="namespace" value="lht-platform-sample-applications-nonprod"/>
<property name="stage" value="dev"/>
</meta-data>
</json-formatter>
</formatter>
The socket binding :
<outbound-socket-binding name="logstash">
<remote-destination host="logstash.lhtlogging-nonprod.svc.cluster.local" port="8080"/>
</outbound-socket-binding>
When based on network policy on OCP the traffic on logstash.lhtlogging-nonprod.svc.cluster.local at 80080 will be enabled. This configuration works well, however if we disable the traffic the server never get started and throws the following error:
09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-3) WFLYJCA0002: Bound JCA ConnectionFactory [java:/JmsXA]
09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-2) WFLYJCA0118: Binding connection factory named java:/JmsXA to alias java:jboss/DefaultJMSConnectionFactory
09:49:06,466 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0348: Timeout after [90] seconds waiting for service container stability. Operation will roll back. Step that first updated the service container was 'add' at address '[
("core-service" => "management"),
("management-interface" => "http-interface")
]'
Failed to invoke setter setOverflowAction with value null
.java.lang.reflect.InvocationTargetException
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.jboss.logmanager.config.AbstractPropertyConfiguration$1.rollback(AbstractPropertyConfiguration.java:244)
at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:437)
at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:396)
at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.NullPointerException: overflowAction is null
at org.jboss.logmanager.handlers.AsyncHandler.setOverflowAction(AsyncHandler.java:117)
... 26 more
When check the thread dumps from the same time, we find that there is a long running thread, which is also mentioned in earlier update:
"MSC service thread 1-2" #18 prio=5 os_prio=0 cpu=616.95ms elapsed=120.44s tid=0x000055790ece0000 nid=0x78b runnable [0x00007f37a1ee8000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketConnect(java.base(a)11.0.9/Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(java.base@11.0.9/AbstractPlainSocketImpl.java:399)
- locked <0x00000000d64c8470> (a java.net.SocksSocketImpl)
at java.net.AbstractPlainSocketImpl.connectToAddress(java.base@11.0.9/AbstractPlainSocketImpl.java:242)
at java.net.AbstractPlainSocketImpl.connect(java.base@11.0.9/AbstractPlainSocketImpl.java:224)
at java.net.SocksSocketImpl.connect(java.base@11.0.9/SocksSocketImpl.java:403)
at java.net.Socket.connect(java.base@11.0.9/Socket.java:609)
at java.net.Socket.connect(java.base@11.0.9/Socket.java:558)
at org.jboss.as.network.OutboundSocketBinding.connect(OutboundSocketBinding.java:125)
at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$WildFlyClientSocketFactory.createSocket(SocketHandlerResourceDefinition.java:441)
at org.jboss.logmanager.handlers.TcpOutputStream.<init>(TcpOutputStream.java:165)
at org.jboss.logmanager.handlers.SocketHandler.createOutputStream(SocketHandler.java:453)
at org.jboss.logmanager.handlers.SocketHandler.initialize(SocketHandler.java:422)
at org.jboss.logmanager.handlers.SocketHandler.doPublish(SocketHandler.java:211)
- locked <0x00000000f49b7a10> (a java.lang.Object)
at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:77)
at org.jboss.logmanager.handlers.DelayedHandler.publishToChildren(DelayedHandler.java:213)
at org.jboss.logmanager.handlers.DelayedHandler.activate(DelayedHandler.java:205)
- locked <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
at org.jboss.logmanager.handlers.DelayedHandler.setHandlers(DelayedHandler.java:124)
at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1.start(SocketHandlerResourceDefinition.java:252)
- locked <0x00000000f49b55a0> (a org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1)
at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1739)
at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1701)
at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1559)
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:1363)
at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)
Which at times blocks the boot controll thread:
"Controller Boot Thread" #23 prio=5 os_prio=0 cpu=564.32ms elapsed=118.63s tid=0x000055790e6e4800 nid=0x7a2 waiting for monitor entry [0x00007f37a13f2000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.jboss.logmanager.handlers.DelayedHandler.close(DelayedHandler.java:82)
- waiting to lock <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
at org.jboss.logmanager.config.HandlerConfigurationImpl$9.rollback(HandlerConfigurationImpl.java:413)
at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
at org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
- locked <0x00000000f511e1d8> (a java.lang.Object)
at org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
at org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
at org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
at org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
at org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
at org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
at org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
at org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
at org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
at org.jboss.as.server.ServerService.boot(ServerService.java:437)
at org.jboss.as.server.ServerService.boot(ServerService.java:396)
at org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)~~~
> Socket handler is holding server to start
> -----------------------------------------
>
> Key: WFCORE-5275
> URL: https://issues.redhat.com/browse/WFCORE-5275
> Project: WildFly Core
> Issue Type: Bug
> Components: Logging
> Reporter: James Perkins
> Assignee: James Perkins
> Priority: Major
>
> CU is on EAP 7.3 on OCP and has configured the socket-handler as below:
> <async-handler name="async-logstash-handler">
> <queue-length value="${env.LHT_LOGGING_BUFFER_SIZE:1048576}"/>
> <overflow-action value="discard"/>
> <subhandlers>
> <handler name="logstash-handler"/>
> </subhandlers>
> </async-handler>
> <console-handler name="CONSOLE">
> <formatter>
> <named-formatter name="COLOR-PATTERN"/>
> </formatter>
> </console-handler>
>
> <socket-handler name="logstash-handler" block-on-reconnect="true" outbound-socket-binding-ref="logstash">
> <named-formatter name="logstash-json-formatter"/>
> </socket-handler>
> The formatter:
> <formatter name="logstash-json-formatter">
> <json-formatter>
> <exception-output-type value="formatted"/>
> <key-overrides host-name="host" logger-name="category" message="log-message" thread-id="thread" thread-name="thread-name" timestamp="@timestamp"/>
> <meta-data>
> <property name="@version" value="1"/>
> <property name="lhtappid" value="2038"/>
> <property name="namespace" value="lht-platform-sample-applications-nonprod"/>
> <property name="stage" value="dev"/>
> </meta-data>
> </json-formatter>
> </formatter>
> The socket binding :
> <outbound-socket-binding name="logstash">
> <remote-destination host="logstash.lhtlogging-nonprod.svc.cluster.local" port="8080"/>
> </outbound-socket-binding>
> When based on network policy on OCP the traffic on logstash.lhtlogging-nonprod.svc.cluster.local at 80080 will be enabled. This configuration works well, however if we disable the traffic the server never get started and throws the following error:
> 09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-3) WFLYJCA0002: Bound JCA ConnectionFactory [java:/JmsXA]
> 09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-2) WFLYJCA0118: Binding connection factory named java:/JmsXA to alias java:jboss/DefaultJMSConnectionFactory
> 09:49:06,466 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0348: Timeout after [90] seconds waiting for service container stability. Operation will roll back. Step that first updated the service container was 'add' at address '[
> ("core-service" => "management"),
> ("management-interface" => "http-interface")
> ]'
> Failed to invoke setter setOverflowAction with value null
> .java.lang.reflect.InvocationTargetException
> at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.base/java.lang.reflect.Method.invoke(Method.java:566)
> at org.jboss.logmanager.config.AbstractPropertyConfiguration$1.rollback(AbstractPropertyConfiguration.java:244)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
> at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
> at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
> at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
> at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:437)
> at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:396)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
> at java.base/java.lang.Thread.run(Thread.java:834)
> Caused by: java.lang.NullPointerException: overflowAction is null
> at org.jboss.logmanager.handlers.AsyncHandler.setOverflowAction(AsyncHandler.java:117)
> ... 26 more
> When check the thread dumps from the same time, we find that there is a long running thread, which is also mentioned in earlier update:
> "MSC service thread 1-2" #18 prio=5 os_prio=0 cpu=616.95ms elapsed=120.44s tid=0x000055790ece0000 nid=0x78b runnable [0x00007f37a1ee8000]
> java.lang.Thread.State: RUNNABLE
> at java.net.PlainSocketImpl.socketConnect(java.base(a)11.0.9/Native Method)
> at java.net.AbstractPlainSocketImpl.doConnect(java.base@11.0.9/AbstractPlainSocketImpl.java:399)
> - locked <0x00000000d64c8470> (a java.net.SocksSocketImpl)
> at java.net.AbstractPlainSocketImpl.connectToAddress(java.base@11.0.9/AbstractPlainSocketImpl.java:242)
> at java.net.AbstractPlainSocketImpl.connect(java.base@11.0.9/AbstractPlainSocketImpl.java:224)
> at java.net.SocksSocketImpl.connect(java.base@11.0.9/SocksSocketImpl.java:403)
> at java.net.Socket.connect(java.base@11.0.9/Socket.java:609)
> at java.net.Socket.connect(java.base@11.0.9/Socket.java:558)
> at org.jboss.as.network.OutboundSocketBinding.connect(OutboundSocketBinding.java:125)
> at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$WildFlyClientSocketFactory.createSocket(SocketHandlerResourceDefinition.java:441)
> at org.jboss.logmanager.handlers.TcpOutputStream.<init>(TcpOutputStream.java:165)
> at org.jboss.logmanager.handlers.SocketHandler.createOutputStream(SocketHandler.java:453)
> at org.jboss.logmanager.handlers.SocketHandler.initialize(SocketHandler.java:422)
> at org.jboss.logmanager.handlers.SocketHandler.doPublish(SocketHandler.java:211)
> - locked <0x00000000f49b7a10> (a java.lang.Object)
> at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:77)
> at org.jboss.logmanager.handlers.DelayedHandler.publishToChildren(DelayedHandler.java:213)
> at org.jboss.logmanager.handlers.DelayedHandler.activate(DelayedHandler.java:205)
> - locked <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
> at org.jboss.logmanager.handlers.DelayedHandler.setHandlers(DelayedHandler.java:124)
> at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1.start(SocketHandlerResourceDefinition.java:252)
> - locked <0x00000000f49b55a0> (a org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1)
> at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1739)
> at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1701)
> at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1559)
> 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:1363)
> at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)
> Which at times blocks the boot controll thread:
> "Controller Boot Thread" #23 prio=5 os_prio=0 cpu=564.32ms elapsed=118.63s tid=0x000055790e6e4800 nid=0x7a2 waiting for monitor entry [0x00007f37a13f2000]
> java.lang.Thread.State: BLOCKED (on object monitor)
> at org.jboss.logmanager.handlers.DelayedHandler.close(DelayedHandler.java:82)
> - waiting to lock <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
> at org.jboss.logmanager.config.HandlerConfigurationImpl$9.rollback(HandlerConfigurationImpl.java:413)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
> at org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
> - locked <0x00000000f511e1d8> (a java.lang.Object)
> at org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
> at org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
> at org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
> at org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
> at org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
> at org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
> at org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
> at org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
> at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
> at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
> at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
> at org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
> at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
> at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
> at org.jboss.as.server.ServerService.boot(ServerService.java:437)
> at org.jboss.as.server.ServerService.boot(ServerService.java:396)
> at org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
> at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)~~~
> I don't find any issues with the configuration. I see in the code the socket is trying to connect without and timeout and the same is missing from the configuration.
> Either the server where the socket is listening should be in start condition to avoid the failure from boot or we should avoid the server from a failure to boot if no processes is running on the socket in socket-handler.
> The issue is rarely reproducible on local machine.
--
This message was sent by Atlassian Jira
(v8.13.1#813001)
5 years, 2 months
- 1
- 0
[Red Hat JIRA] (WFCORE-5275) Socket handler is holding server to start
by James Perkins (Jira)
[ https://issues.redhat.com/browse/WFCORE-5275?page=com.atlassian.jira.plug... ]
James Perkins moved JBEAP-20983 to WFCORE-5275:
-----------------------------------------------
Component/s: Logging
(was: Logging)
Key: WFCORE-5275 (was: JBEAP-20983)
Affects Version/s: (was: 7.3.x)
Workflow: GIT Pull Request workflow (was: CDW with loose statuses v1)
Project: WildFly Core (was: JBoss Enterprise Application Platform)
> Socket handler is holding server to start
> -----------------------------------------
>
> Key: WFCORE-5275
> URL: https://issues.redhat.com/browse/WFCORE-5275
> Project: WildFly Core
> Issue Type: Bug
> Components: Logging
> Reporter: James Perkins
> Priority: Major
>
> CU is on EAP 7.3 on OCP and has configured the socket-handler as below:
> <async-handler name="async-logstash-handler">
> <queue-length value="${env.LHT_LOGGING_BUFFER_SIZE:1048576}"/>
> <overflow-action value="discard"/>
> <subhandlers>
> <handler name="logstash-handler"/>
> </subhandlers>
> </async-handler>
> <console-handler name="CONSOLE">
> <formatter>
> <named-formatter name="COLOR-PATTERN"/>
> </formatter>
> </console-handler>
>
> <socket-handler name="logstash-handler" block-on-reconnect="true" outbound-socket-binding-ref="logstash">
> <named-formatter name="logstash-json-formatter"/>
> </socket-handler>
> The formatter:
> <formatter name="logstash-json-formatter">
> <json-formatter>
> <exception-output-type value="formatted"/>
> <key-overrides host-name="host" logger-name="category" message="log-message" thread-id="thread" thread-name="thread-name" timestamp="@timestamp"/>
> <meta-data>
> <property name="@version" value="1"/>
> <property name="lhtappid" value="2038"/>
> <property name="namespace" value="lht-platform-sample-applications-nonprod"/>
> <property name="stage" value="dev"/>
> </meta-data>
> </json-formatter>
> </formatter>
> The socket binding :
> <outbound-socket-binding name="logstash">
> <remote-destination host="logstash.lhtlogging-nonprod.svc.cluster.local" port="8080"/>
> </outbound-socket-binding>
> When based on network policy on OCP the traffic on logstash.lhtlogging-nonprod.svc.cluster.local at 80080 will be enabled. This configuration works well, however if we disable the traffic the server never get started and throws the following error:
> 09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-3) WFLYJCA0002: Bound JCA ConnectionFactory [java:/JmsXA]
> 09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-2) WFLYJCA0118: Binding connection factory named java:/JmsXA to alias java:jboss/DefaultJMSConnectionFactory
> 09:49:06,466 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0348: Timeout after [90] seconds waiting for service container stability. Operation will roll back. Step that first updated the service container was 'add' at address '[
> ("core-service" => "management"),
> ("management-interface" => "http-interface")
> ]'
> Failed to invoke setter setOverflowAction with value null
> .java.lang.reflect.InvocationTargetException
> at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.base/java.lang.reflect.Method.invoke(Method.java:566)
> at org.jboss.logmanager.config.AbstractPropertyConfiguration$1.rollback(AbstractPropertyConfiguration.java:244)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
> at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
> at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
> at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
> at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:437)
> at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:396)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
> at java.base/java.lang.Thread.run(Thread.java:834)
> Caused by: java.lang.NullPointerException: overflowAction is null
> at org.jboss.logmanager.handlers.AsyncHandler.setOverflowAction(AsyncHandler.java:117)
> ... 26 more
> When check the thread dumps from the same time, we find that there is a long running thread, which is also mentioned in earlier update:
> "MSC service thread 1-2" #18 prio=5 os_prio=0 cpu=616.95ms elapsed=120.44s tid=0x000055790ece0000 nid=0x78b runnable [0x00007f37a1ee8000]
> java.lang.Thread.State: RUNNABLE
> at java.net.PlainSocketImpl.socketConnect(java.base(a)11.0.9/Native Method)
> at java.net.AbstractPlainSocketImpl.doConnect(java.base@11.0.9/AbstractPlainSocketImpl.java:399)
> - locked <0x00000000d64c8470> (a java.net.SocksSocketImpl)
> at java.net.AbstractPlainSocketImpl.connectToAddress(java.base@11.0.9/AbstractPlainSocketImpl.java:242)
> at java.net.AbstractPlainSocketImpl.connect(java.base@11.0.9/AbstractPlainSocketImpl.java:224)
> at java.net.SocksSocketImpl.connect(java.base@11.0.9/SocksSocketImpl.java:403)
> at java.net.Socket.connect(java.base@11.0.9/Socket.java:609)
> at java.net.Socket.connect(java.base@11.0.9/Socket.java:558)
> at org.jboss.as.network.OutboundSocketBinding.connect(OutboundSocketBinding.java:125)
> at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$WildFlyClientSocketFactory.createSocket(SocketHandlerResourceDefinition.java:441)
> at org.jboss.logmanager.handlers.TcpOutputStream.<init>(TcpOutputStream.java:165)
> at org.jboss.logmanager.handlers.SocketHandler.createOutputStream(SocketHandler.java:453)
> at org.jboss.logmanager.handlers.SocketHandler.initialize(SocketHandler.java:422)
> at org.jboss.logmanager.handlers.SocketHandler.doPublish(SocketHandler.java:211)
> - locked <0x00000000f49b7a10> (a java.lang.Object)
> at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:77)
> at org.jboss.logmanager.handlers.DelayedHandler.publishToChildren(DelayedHandler.java:213)
> at org.jboss.logmanager.handlers.DelayedHandler.activate(DelayedHandler.java:205)
> - locked <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
> at org.jboss.logmanager.handlers.DelayedHandler.setHandlers(DelayedHandler.java:124)
> at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1.start(SocketHandlerResourceDefinition.java:252)
> - locked <0x00000000f49b55a0> (a org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1)
> at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1739)
> at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1701)
> at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1559)
> 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:1363)
> at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)
> Which at times blocks the boot controll thread:
> "Controller Boot Thread" #23 prio=5 os_prio=0 cpu=564.32ms elapsed=118.63s tid=0x000055790e6e4800 nid=0x7a2 waiting for monitor entry [0x00007f37a13f2000]
> java.lang.Thread.State: BLOCKED (on object monitor)
> at org.jboss.logmanager.handlers.DelayedHandler.close(DelayedHandler.java:82)
> - waiting to lock <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
> at org.jboss.logmanager.config.HandlerConfigurationImpl$9.rollback(HandlerConfigurationImpl.java:413)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
> at org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
> - locked <0x00000000f511e1d8> (a java.lang.Object)
> at org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
> at org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
> at org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
> at org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
> at org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
> at org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
> at org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
> at org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
> at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
> at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
> at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
> at org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
> at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
> at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
> at org.jboss.as.server.ServerService.boot(ServerService.java:437)
> at org.jboss.as.server.ServerService.boot(ServerService.java:396)
> at org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
> at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)~~~
> I don't find any issues with the configuration. I see in the code the socket is trying to connect without and timeout and the same is missing from the configuration.
> Either the server where the socket is listening should be in start condition to avoid the failure from boot or we should avoid the server from a failure to boot if no processes is running on the socket in socket-handler.
> The issue is rarely reproducible on local machine.
--
This message was sent by Atlassian Jira
(v8.13.1#813001)
5 years, 2 months
- 1
- 0
[Red Hat JIRA] (WFCORE-5275) Socket handler is holding server to start
by James Perkins (Jira)
[ https://issues.redhat.com/browse/WFCORE-5275?page=com.atlassian.jira.plug... ]
James Perkins reassigned WFCORE-5275:
-------------------------------------
Assignee: James Perkins
> Socket handler is holding server to start
> -----------------------------------------
>
> Key: WFCORE-5275
> URL: https://issues.redhat.com/browse/WFCORE-5275
> Project: WildFly Core
> Issue Type: Bug
> Components: Logging
> Reporter: James Perkins
> Assignee: James Perkins
> Priority: Major
>
> CU is on EAP 7.3 on OCP and has configured the socket-handler as below:
> <async-handler name="async-logstash-handler">
> <queue-length value="${env.LHT_LOGGING_BUFFER_SIZE:1048576}"/>
> <overflow-action value="discard"/>
> <subhandlers>
> <handler name="logstash-handler"/>
> </subhandlers>
> </async-handler>
> <console-handler name="CONSOLE">
> <formatter>
> <named-formatter name="COLOR-PATTERN"/>
> </formatter>
> </console-handler>
>
> <socket-handler name="logstash-handler" block-on-reconnect="true" outbound-socket-binding-ref="logstash">
> <named-formatter name="logstash-json-formatter"/>
> </socket-handler>
> The formatter:
> <formatter name="logstash-json-formatter">
> <json-formatter>
> <exception-output-type value="formatted"/>
> <key-overrides host-name="host" logger-name="category" message="log-message" thread-id="thread" thread-name="thread-name" timestamp="@timestamp"/>
> <meta-data>
> <property name="@version" value="1"/>
> <property name="lhtappid" value="2038"/>
> <property name="namespace" value="lht-platform-sample-applications-nonprod"/>
> <property name="stage" value="dev"/>
> </meta-data>
> </json-formatter>
> </formatter>
> The socket binding :
> <outbound-socket-binding name="logstash">
> <remote-destination host="logstash.lhtlogging-nonprod.svc.cluster.local" port="8080"/>
> </outbound-socket-binding>
> When based on network policy on OCP the traffic on logstash.lhtlogging-nonprod.svc.cluster.local at 80080 will be enabled. This configuration works well, however if we disable the traffic the server never get started and throws the following error:
> 09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-3) WFLYJCA0002: Bound JCA ConnectionFactory [java:/JmsXA]
> 09:47:37,297 INFO [org.jboss.as.connector.deployment] (MSC service thread 1-2) WFLYJCA0118: Binding connection factory named java:/JmsXA to alias java:jboss/DefaultJMSConnectionFactory
> 09:49:06,466 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0348: Timeout after [90] seconds waiting for service container stability. Operation will roll back. Step that first updated the service container was 'add' at address '[
> ("core-service" => "management"),
> ("management-interface" => "http-interface")
> ]'
> Failed to invoke setter setOverflowAction with value null
> .java.lang.reflect.InvocationTargetException
> at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.base/java.lang.reflect.Method.invoke(Method.java:566)
> at org.jboss.logmanager.config.AbstractPropertyConfiguration$1.rollback(AbstractPropertyConfiguration.java:244)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
> at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
> at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
> at org.jboss.as.logging@10.1.17.Final-redhat-00001//org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
> at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:437)
> at org.jboss.as.server@10.1.17.Final-redhat-00001//org.jboss.as.server.ServerService.boot(ServerService.java:396)
> at org.jboss.as.controller@10.1.17.Final-redhat-00001//org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
> at java.base/java.lang.Thread.run(Thread.java:834)
> Caused by: java.lang.NullPointerException: overflowAction is null
> at org.jboss.logmanager.handlers.AsyncHandler.setOverflowAction(AsyncHandler.java:117)
> ... 26 more
> When check the thread dumps from the same time, we find that there is a long running thread, which is also mentioned in earlier update:
> "MSC service thread 1-2" #18 prio=5 os_prio=0 cpu=616.95ms elapsed=120.44s tid=0x000055790ece0000 nid=0x78b runnable [0x00007f37a1ee8000]
> java.lang.Thread.State: RUNNABLE
> at java.net.PlainSocketImpl.socketConnect(java.base(a)11.0.9/Native Method)
> at java.net.AbstractPlainSocketImpl.doConnect(java.base@11.0.9/AbstractPlainSocketImpl.java:399)
> - locked <0x00000000d64c8470> (a java.net.SocksSocketImpl)
> at java.net.AbstractPlainSocketImpl.connectToAddress(java.base@11.0.9/AbstractPlainSocketImpl.java:242)
> at java.net.AbstractPlainSocketImpl.connect(java.base@11.0.9/AbstractPlainSocketImpl.java:224)
> at java.net.SocksSocketImpl.connect(java.base@11.0.9/SocksSocketImpl.java:403)
> at java.net.Socket.connect(java.base@11.0.9/Socket.java:609)
> at java.net.Socket.connect(java.base@11.0.9/Socket.java:558)
> at org.jboss.as.network.OutboundSocketBinding.connect(OutboundSocketBinding.java:125)
> at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$WildFlyClientSocketFactory.createSocket(SocketHandlerResourceDefinition.java:441)
> at org.jboss.logmanager.handlers.TcpOutputStream.<init>(TcpOutputStream.java:165)
> at org.jboss.logmanager.handlers.SocketHandler.createOutputStream(SocketHandler.java:453)
> at org.jboss.logmanager.handlers.SocketHandler.initialize(SocketHandler.java:422)
> at org.jboss.logmanager.handlers.SocketHandler.doPublish(SocketHandler.java:211)
> - locked <0x00000000f49b7a10> (a java.lang.Object)
> at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:77)
> at org.jboss.logmanager.handlers.DelayedHandler.publishToChildren(DelayedHandler.java:213)
> at org.jboss.logmanager.handlers.DelayedHandler.activate(DelayedHandler.java:205)
> - locked <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
> at org.jboss.logmanager.handlers.DelayedHandler.setHandlers(DelayedHandler.java:124)
> at org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1.start(SocketHandlerResourceDefinition.java:252)
> - locked <0x00000000f49b55a0> (a org.jboss.as.logging.handlers.SocketHandlerResourceDefinition$1$2$1)
> at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1739)
> at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1701)
> at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1559)
> 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:1363)
> at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)
> Which at times blocks the boot controll thread:
> "Controller Boot Thread" #23 prio=5 os_prio=0 cpu=564.32ms elapsed=118.63s tid=0x000055790e6e4800 nid=0x7a2 waiting for monitor entry [0x00007f37a13f2000]
> java.lang.Thread.State: BLOCKED (on object monitor)
> at org.jboss.logmanager.handlers.DelayedHandler.close(DelayedHandler.java:82)
> - waiting to lock <0x00000000f49b55f0> (a org.jboss.logmanager.handlers.DelayedHandler)
> at org.jboss.logmanager.config.HandlerConfigurationImpl$9.rollback(HandlerConfigurationImpl.java:413)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.doForget(LogContextConfigurationImpl.java:355)
> at org.jboss.logmanager.config.LogContextConfigurationImpl.forget(LogContextConfigurationImpl.java:319)
> at org.jboss.as.logging.logmanager.ConfigurationPersistence.forget(ConfigurationPersistence.java:341)
> - locked <0x00000000f511e1d8> (a java.lang.Object)
> at org.jboss.as.logging.logmanager.ConfigurationPersistence.rollback(ConfigurationPersistence.java:349)
> at org.jboss.as.logging.LoggingOperations$CommitOperationStepHandler$1.handleResult(LoggingOperations.java:123)
> at org.jboss.as.controller.AbstractOperationContext$Step.invokeResultHandler(AbstractOperationContext.java:1533)
> at org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1515)
> at org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1472)
> at org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1455)
> at org.jboss.as.controller.AbstractOperationContext$Step.access$400(AbstractOperationContext.java:1319)
> at org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:876)
> at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
> at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:467)
> at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1413)
> at org.jboss.as.controller.ModelControllerImpl.boot(ModelControllerImpl.java:527)
> at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:481)
> at org.jboss.as.controller.AbstractControllerService.boot(AbstractControllerService.java:443)
> at org.jboss.as.server.ServerService.boot(ServerService.java:437)
> at org.jboss.as.server.ServerService.boot(ServerService.java:396)
> at org.jboss.as.controller.AbstractControllerService$1.run(AbstractControllerService.java:383)
> at java.lang.Thread.run(java.base@11.0.9/Thread.java:834)~~~
> I don't find any issues with the configuration. I see in the code the socket is trying to connect without and timeout and the same is missing from the configuration.
> Either the server where the socket is listening should be in start condition to avoid the failure from boot or we should avoid the server from a failure to boot if no processes is running on the socket in socket-handler.
> The issue is rarely reproducible on local machine.
--
This message was sent by Atlassian Jira
(v8.13.1#813001)
5 years, 2 months
- 1
- 0
[Red Hat JIRA] (WFLY-14372) Multiple metrics collections
by Jason Lee (Jira)
[ https://issues.redhat.com/browse/WFLY-14372?page=com.atlassian.jira.plugi... ]
Jason Lee updated WFLY-14372:
-----------------------------
Issue Type: Bug (was: Task)
> Multiple metrics collections
> ----------------------------
>
> Key: WFLY-14372
> URL: https://issues.redhat.com/browse/WFLY-14372
> Project: WildFly
> Issue Type: Bug
> Components: MP Metrics
> Reporter: Brian Stansberry
> Assignee: Jason Lee
> Priority: Critical
>
> See discussion on https://github.com/wildfly/wildfly/pull/13871
> Do we have MetricsCollector collecting the container metrics multiple times?
> I haven't thought hard about this, but doesn't the Stage.VERIFY collection in MetricsSubsystemAdd end up re-collecting all the deployment=* subtree metrics already collected in Stage.RUNTIME via DeploymentMetricProcessor/DeploymentMetricService? It walks the whole resource tree from the root.
> If the MP Metrics subsystem is installed, isn't MicroProfileMetricsSubsystemAdd and that subsystem's DeploymentMetricProcessor/DeploymentMetricService also collecting the same set of metrics?
> I'm filing this as a Task because maybe all that's needed is to investigate and answer those questions reporting that all is well. But if all isn't well this should converted to a Bug.
> Also, as discussed on PR #13871, https://github.com/wildfly/wildfly/blob/22.0.0.Final/metrics/src/main/jav... is probably not the best idiom given the code is iterating over runtime-only resources, where the cost of hasChildren can be high.
--
This message was sent by Atlassian Jira
(v8.13.1#813001)
5 years, 2 months
- 1
- 0