As mentioned in previous blogs (like this one), we were doing some testing on the newly released versions of Documentum (CS 7.3, xPlore 1.6, aso…). On this blog, I will talk about something that can prevent the WildFly instances to start properly (RedHat renamed the JBoss Application Server to WildFly in 2013 starting with the version 8.0). As this issue is linked to WildFly, you can understand that this might happen on both Content Servers 7.3 and Full Text Servers 1.6 but in this blog, I will use a Content Server for the example.
So when I first installed a Content Server 7.3 (in full silent of course!), the Java Method Server wasn’t running properly. Actually worse than that, it wasn’t even starting completely. Here are the entries put in the JMS log file (server.log):
JAVA_OPTS already set in environment; overriding default settings with values: -XX:+UseParallelOldGC -XX:ReservedCodeCacheSize=128m -XX:MaxMetaspaceSize=256m -XX:NewRatio=4 -Xms4096m -Xmx4096m -XX:NewSize=256m -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8 -Xss256k -Djava.awt.headless=true -Djava.io.tmpdir=$DOCUMENTUM/temp/JMS_Temp -Djboss.server.base.dir=$DOCUMENTUM_SHARED/wildfly9.0.1/server/DctmServer_MethodServer ========================================================================= JBoss Bootstrap Environment JBOSS_HOME: $DOCUMENTUM_SHARED/wildfly9.0.1 JAVA: $DOCUMENTUM_SHARED/java64/JAVA_LINK/bin/java JAVA_OPTS: -server -XX:+UseCompressedOops -server -XX:+UseCompressedOops -XX:+UseParallelOldGC -XX:ReservedCodeCacheSize=128m -XX:MaxMetaspaceSize=256m -XX:NewRatio=4 -Xms4096m -Xmx4096m -XX:NewSize=256m -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8 -Xss256k -Djava.awt.headless=true -Djava.io.tmpdir=$DOCUMENTUM/temp/JMS_Temp -Djboss.server.base.dir=$DOCUMENTUM_SHARED/wildfly9.0.1/server/DctmServer_MethodServer ========================================================================= 15:48:41,985 INFO [org.jboss.modules] (main) JBoss Modules version 1.4.3.Final 15:48:44,301 INFO [org.jboss.msc] (main) JBoss MSC version 1.2.6.Final 15:48:44,502 INFO [org.jboss.as] (MSC service thread 1-8) WFLYSRV0049: WildFly Full 9.0.1.Final (WildFly Core 1.0.1.Final) starting 15:48:50,818 INFO [org.jboss.as.controller.management-deprecated] (ServerService Thread Pool -- 28) WFLYCTL0028: Attribute 'enabled' in the resource at address '/subsystem=datasources/data-source=ExampleDS' is deprecated, and may be removed in future version. See the attribute description in the output of the read-resource-description operation to learn more about the deprecation. 15:48:50,819 INFO [org.jboss.as.controller.management-deprecated] (ServerService Thread Pool -- 27) WFLYCTL0028: Attribute 'job-repository-type' in the resource at address '/subsystem=batch' is deprecated, and may be removed in future version. See the attribute description in the output of the read-resource-description operation to learn more about the deprecation. 15:48:50,867 WARN [org.jboss.messaging] (ServerService Thread Pool -- 30) WFLYMSG0071: There is no resource matching the expiry-address jms.queue.ExpiryQueue for the address-settings #, expired messages from destinations matching this address-setting will be lost! 15:48:50,868 WARN [org.jboss.messaging] (ServerService Thread Pool -- 30) WFLYMSG0072: There is no resource matching the dead-letter-address jms.queue.DLQ for the address-settings #, undelivered messages from destinations matching this address-setting will be lost! 15:48:51,024 INFO [org.jboss.as.server.deployment.scanner] (DeploymentScanner-threads - 1) WFLYDS0004: Found acs.ear in deployment directory. To trigger deployment create a file called acs.ear.dodeploy 15:48:51,026 INFO [org.jboss.as.server.deployment.scanner] (DeploymentScanner-threads - 1) WFLYDS0004: Found ServerApps.ear in deployment directory. To trigger deployment create a file called ServerApps.ear.dodeploy 15:48:51,109 INFO [org.xnio] (MSC service thread 1-5) XNIO version 3.3.1.Final 15:48:51,113 INFO [org.jboss.as.server] (Controller Boot Thread) WFLYSRV0039: Creating http management service using socket-binding (management-http) 15:48:51,128 INFO [org.xnio.nio] (MSC service thread 1-5) XNIO NIO Implementation Version 3.3.1.Final 15:48:51,164 INFO [org.jboss.remoting] (MSC service thread 1-5) JBoss Remoting version 4.0.9.Final 15:48:51,325 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 39) WFLYCLINF0001: Activating Infinispan subsystem. 15:48:51,335 INFO [org.wildfly.extension.io] (ServerService Thread Pool -- 38) WFLYIO001: Worker 'default' has auto-configured to 8 core threads with 64 task threads based on your 4 available processors 15:48:51,374 INFO [org.jboss.as.naming] (ServerService Thread Pool -- 47) WFLYNAM0001: Activating Naming Subsystem 15:48:51,353 INFO [org.jboss.as.security] (ServerService Thread Pool -- 54) WFLYSEC0002: Activating Security Subsystem 15:48:51,359 WARN [org.jboss.as.txn] (ServerService Thread Pool -- 55) WFLYTX0013: Node identifier property is set to the default value. Please make sure it is unique. 15:48:51,387 INFO [org.jboss.as.webservices] (ServerService Thread Pool -- 57) WFLYWS0002: Activating WebServices Extension 15:48:51,410 INFO [org.jboss.as.jsf] (ServerService Thread Pool -- 45) WFLYJSF0007: Activated the following JSF Implementations: [main] 15:48:51,429 INFO [org.jboss.as.security] (MSC service thread 1-3) WFLYSEC0001: Current PicketBox version=4.9.2.Final 15:48:51,499 INFO [org.jboss.as.connector] (MSC service thread 1-7) WFLYJCA0009: Starting JCA Subsystem (IronJacamar 1.2.4.Final) 15:48:51,541 INFO [org.jboss.as.naming] (MSC service thread 1-4) WFLYNAM0003: Starting Naming Service 15:48:51,554 INFO [org.jboss.as.mail.extension] (MSC service thread 1-7) WFLYMAIL0001: Bound mail session 15:48:51,563 INFO [org.wildfly.extension.undertow] (ServerService Thread Pool -- 56) WFLYUT0003: Undertow 1.2.9.Final starting 15:48:51,564 INFO [org.wildfly.extension.undertow] (MSC service thread 1-8) WFLYUT0003: Undertow 1.2.9.Final starting 15:48:51,583 INFO [org.jboss.as.connector.subsystems.datasources] (ServerService Thread Pool -- 34) WFLYJCA0004: Deploying JDBC-compliant driver class org.h2.Driver (version 1.3) 15:48:51,593 INFO [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-4) WFLYJCA0018: Started Driver service with driver-name = h2 15:48:51,931 INFO [org.wildfly.extension.undertow] (ServerService Thread Pool -- 56) WFLYUT0014: Creating file handler for path $DOCUMENTUM_SHARED/wildfly9.0.1/welcome-content 15:48:51,984 INFO [org.wildfly.extension.undertow] (MSC service thread 1-8) WFLYUT0012: Started server default-server. 15:48:52,049 INFO [org.wildfly.extension.undertow] (MSC service thread 1-3) WFLYUT0018: Host default-host starting 15:48:52,112 ERROR [org.jboss.msc.service.fail] (MSC service thread 1-8) MSC000001: Failed to start service jboss.undertow.listener.default: org.jboss.msc.service.StartException in service jboss.undertow.listener.default: Could not start http listener at org.wildfly.extension.undertow.ListenerService.start(ListenerService.java:150) at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1948) at org.jboss.msc.service.ServiceControllerImpl$StartTask.run(ServiceControllerImpl.java:1881) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: java.net.SocketException: Protocol family unavailable at sun.nio.ch.Net.bind0(Native Method) at sun.nio.ch.Net.bind(Net.java:433) at sun.nio.ch.Net.bind(Net.java:425) at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223) at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74) at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:67) at org.xnio.nio.NioXnioWorker.createTcpConnectionServer(NioXnioWorker.java:182) at org.xnio.XnioWorker.createStreamConnectionServer(XnioWorker.java:243) at org.wildfly.extension.undertow.HttpListenerService.startListening(HttpListenerService.java:115) at org.wildfly.extension.undertow.ListenerService.start(ListenerService.java:147) ... 5 more ... 15:49:37,585 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([ ("core-service" => "management"), ("management-interface" => "native-interface") ]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.remoting.server.management" => "org.jboss.msc.service.StartException in service jboss.remoting.server.management: WFLYRMT0005: Failed to start service Caused by: java.net.SocketException: Protocol family unavailable"}} 15:49:37,589 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([ ("core-service" => "management"), ("management-interface" => "http-interface") ]) - failure description: { "WFLYCTL0080: Failed services" => {"jboss.serverManagement.controller.management.http" => "org.jboss.msc.service.StartException in service jboss.serverManagement.controller.management.http: WFLYSRV0083: Failed to start the http-interface service Caused by: java.lang.RuntimeException: java.net.SocketException: Protocol family unavailable Caused by: java.net.SocketException: Protocol family unavailable"}, "WFLYCTL0288: One or more services were unable to start due to one or more indirect dependencies not being available." => { "Services that were unable to start:" => ["jboss.serverManagement.controller.management.http.shutdown"], "Services that may be the cause:" => ["jboss.remoting.remotingConnectorInfoService.http-remoting-connector"] } } ... 15:49:37,653 INFO [org.jboss.as.server] (ServerService Thread Pool -- 35) WFLYSRV0010: Deployed "acs.ear" (runtime-name : "acs.ear") 15:49:37,654 INFO [org.jboss.as.server] (ServerService Thread Pool -- 35) WFLYSRV0010: Deployed "ServerApps.ear" (runtime-name : "ServerApps.ear") ... 15:49:37,901 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0063: Http management interface is not enabled 15:49:37,902 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0054: Admin console is not enabled 15:49:37,903 ERROR [org.jboss.as] (Controller Boot Thread) WFLYSRV0026: WildFly Full 9.0.1.Final (WildFly Core 1.0.1.Final) started (with errors) in 57426ms - Started 225 of 424 services (16 services failed or missing dependencies, 225 services are lazy, passive or on-demand) ... 15:49:38,609 INFO [org.jboss.as.server] (DeploymentScanner-threads - 2) WFLYSRV0009: Undeployed "acs.ear" (runtime-name: "acs.ear") 15:49:38,610 INFO [org.jboss.as.server] (DeploymentScanner-threads - 2) WFLYSRV0009: Undeployed "ServerApps.ear" (runtime-name: "ServerApps.ear") ... 15:53:02,276 INFO [org.jboss.as] (MSC service thread 1-4) WFLYSRV0050: WildFly Full 9.0.1.Final (WildFly Core 1.0.1.Final) stopped in 124ms
After all these errors, the logs are showing that the Http Management interface isn’t enabled and then the WildFly is just shutting itself down. So what is this “Protocol family unavailable”? This is actually linked to one of the changes included in WildFly compared to the old version (JBoss 7.1.1): WildFly supports and use by default IPv4 and IPv6. Unfortunately if your OS isn’t configured to use IPv6, this error will appear and will prevent your WildFly to start.
Fortunately, it is very easy to correct this, you just have to force WildFly to only use IPv4. For that purpose, we will add a single JVM parameter in the start script of the JMS:
sed -i 's,^JAVA_OPTS="[^"]*,& -Djava.net.preferIPv4Stack=true,' $DOCUMENTUM_SHARED/wildfly9.0.1/server/startMethodServer.sh
This command will simply add ” -Djava.net.preferIPv4Stack=true” just before the ending double quote of the line that is starting with JAVA_OPTS= in the file $DOCUMENTUM_SHARED/wildfly9.0.1/server/startMethodServer.sh. As a side note, to do the same thing on a Full Text Server, just change the path and the name of startup script and it will do the same thing (E.g.: $XPLORE_HOME/wildfly9.0.1/server/startPrimaryDsearch.sh).
After that, just restart the JMS and it will be able to start without issue:
JAVA_OPTS already set in environment; overriding default settings with values: -XX:+UseParallelOldGC -XX:ReservedCodeCacheSize=128m -XX:MaxMetaspaceSize=256m -XX:NewRatio=4 -Xms4096m -Xmx4096m -XX:NewSize=256m -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8 -Xss256k -Djava.awt.headless=true -Djava.io.tmpdir=$DOCUMENTUM/temp/JMS_Temp -Djboss.server.base.dir=$DOCUMENTUM_SHARED/wildfly9.0.1/server/DctmServer_MethodServer -Djava.net.preferIPv4Stack=true ========================================================================= JBoss Bootstrap Environment JBOSS_HOME: $DOCUMENTUM_SHARED/wildfly9.0.1 JAVA: $DOCUMENTUM_SHARED/java64/JAVA_LINK/bin/java JAVA_OPTS: -server -XX:+UseCompressedOops -server -XX:+UseCompressedOops -XX:+UseParallelOldGC -XX:ReservedCodeCacheSize=128m -XX:MaxMetaspaceSize=256m -XX:NewRatio=4 -Xms4096m -Xmx4096m -XX:NewSize=256m -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8 -Xss256k -Djava.awt.headless=true -Djava.io.tmpdir=$DOCUMENTUM/temp/JMS_Temp -Djboss.server.base.dir=$DOCUMENTUM_SHARED/wildfly9.0.1/server/DctmServer_MethodServer -Djava.net.preferIPv4Stack=true ========================================================================= 16:10:22,285 INFO [org.jboss.modules] (main) JBoss Modules version 1.4.3.Final 16:10:22,601 INFO [org.jboss.msc] (main) JBoss MSC version 1.2.6.Final 16:10:22,711 INFO [org.jboss.as] (MSC service thread 1-7) WFLYSRV0049: WildFly Full 9.0.1.Final (WildFly Core 1.0.1.Final) starting 16:10:24,627 INFO [org.jboss.as.controller.management-deprecated] (ServerService Thread Pool -- 28) WFLYCTL0028: Attribute 'job-repository-type' in the resource at address '/subsystem=batch' is deprecated, and may be removed in future version. See the attribute description in the output of the read-resource-description operation to learn more about the deprecation. 16:10:24,645 INFO [org.jboss.as.controller.management-deprecated] (ServerService Thread Pool -- 27) WFLYCTL0028: Attribute 'enabled' in the resource at address '/subsystem=datasources/data-source=ExampleDS' is deprecated, and may be removed in future version. See the attribute description in the output of the read-resource-description operation to learn more about the deprecation. 16:10:24,664 INFO [org.jboss.as.server.deployment.scanner] (DeploymentScanner-threads - 1) WFLYDS0004: Found acs.ear in deployment directory. To trigger deployment create a file called acs.ear.dodeploy 16:10:24,665 INFO [org.jboss.as.server.deployment.scanner] (DeploymentScanner-threads - 1) WFLYDS0004: Found ServerApps.ear in deployment directory. To trigger deployment create a file called ServerApps.ear.dodeploy 16:10:24,701 WARN [org.jboss.messaging] (ServerService Thread Pool -- 30) WFLYMSG0071: There is no resource matching the expiry-address jms.queue.ExpiryQueue for the address-settings #, expired messages from destinations matching this address-setting will be lost! 16:10:24,702 WARN [org.jboss.messaging] (ServerService Thread Pool -- 30) WFLYMSG0072: There is no resource matching the dead-letter-address jms.queue.DLQ for the address-settings #, undelivered messages from destinations matching this address-setting will be lost! 16:10:24,728 INFO [org.xnio] (MSC service thread 1-2) XNIO version 3.3.1.Final 16:10:24,737 INFO [org.jboss.as.server] (Controller Boot Thread) WFLYSRV0039: Creating http management service using socket-binding (management-http) 16:10:24,745 INFO [org.xnio.nio] (MSC service thread 1-2) XNIO NIO Implementation Version 3.3.1.Final 16:10:24,808 INFO [org.jboss.remoting] (MSC service thread 1-2) JBoss Remoting version 4.0.9.Final 16:10:24,831 INFO [org.wildfly.extension.io] (ServerService Thread Pool -- 38) WFLYIO001: Worker 'default' has auto-configured to 8 core threads with 64 task threads based on your 4 available processors 16:10:24,852 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 39) WFLYCLINF0001: Activating Infinispan subsystem. 16:10:24,867 INFO [org.jboss.as.jsf] (ServerService Thread Pool -- 45) WFLYJSF0007: Activated the following JSF Implementations: [main] 16:10:24,890 WARN [org.jboss.as.txn] (ServerService Thread Pool -- 55) WFLYTX0013: Node identifier property is set to the default value. Please make sure it is unique. 16:10:24,899 INFO [org.jboss.as.security] (ServerService Thread Pool -- 54) WFLYSEC0002: Activating Security Subsystem 16:10:24,901 INFO [org.jboss.as.naming] (ServerService Thread Pool -- 47) WFLYNAM0001: Activating Naming Subsystem 16:10:24,916 INFO [org.jboss.as.connector.subsystems.datasources] (ServerService Thread Pool -- 34) WFLYJCA0004: Deploying JDBC-compliant driver class org.h2.Driver (version 1.3) 16:10:24,939 INFO [org.wildfly.extension.undertow] (MSC service thread 1-6) WFLYUT0003: Undertow 1.2.9.Final starting 16:10:24,939 INFO [org.wildfly.extension.undertow] (ServerService Thread Pool -- 56) WFLYUT0003: Undertow 1.2.9.Final starting 16:10:24,959 INFO [org.jboss.as.security] (MSC service thread 1-2) WFLYSEC0001: Current PicketBox version=4.9.2.Final 16:10:24,967 INFO [org.jboss.as.webservices] (ServerService Thread Pool -- 57) WFLYWS0002: Activating WebServices Extension 16:10:24,977 INFO [org.jboss.as.connector] (MSC service thread 1-4) WFLYJCA0009: Starting JCA Subsystem (IronJacamar 1.2.4.Final) 16:10:25,034 INFO [org.jboss.as.naming] (MSC service thread 1-7) WFLYNAM0003: Starting Naming Service 16:10:25,035 INFO [org.jboss.as.mail.extension] (MSC service thread 1-7) WFLYMAIL0001: Bound mail session 16:10:25,044 INFO [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-6) WFLYJCA0018: Started Driver service with driver-name = h2 16:10:25,394 INFO [org.wildfly.extension.undertow] (ServerService Thread Pool -- 56) WFLYUT0014: Creating file handler for path $DOCUMENTUM_SHARED/wildfly9.0.1/welcome-content 16:10:25,414 INFO [org.wildfly.extension.undertow] (MSC service thread 1-3) WFLYUT0012: Started server default-server. 16:10:25,508 INFO [org.wildfly.extension.undertow] (MSC service thread 1-6) WFLYUT0018: Host default-host starting 16:10:25,581 INFO [org.wildfly.extension.undertow] (MSC service thread 1-3) WFLYUT0006: Undertow HTTP listener default listening on /0.0.0.0:9080 16:10:25,933 INFO [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-6) WFLYJCA0001: Bound data source 16:10:26,177 INFO [org.jboss.as.server.deployment.scanner] (MSC service thread 1-6) WFLYDS0013: Started FileSystemDeploymentService for directory $DOCUMENTUM_SHARED/wildfly9.0.1/server/DctmServer_MethodServer/deployments 16:10:26,198 INFO [org.jboss.as.server.deployment] (MSC service thread 1-7) WFLYSRV0027: Starting deployment of "ServerApps.ear" (runtime-name: "ServerApps.ear") 16:10:26,201 INFO [org.jboss.as.server.deployment] (MSC service thread 1-4) WFLYSRV0027: Starting deployment of "acs.ear" (runtime-name: "acs.ear") 16:10:26,223 INFO [org.jboss.as.remoting] (MSC service thread 1-5) WFLYRMT0001: Listening on 0.0.0.0:9084 ... 16:10:42,398 INFO [org.wildfly.extension.undertow] (ServerService Thread Pool -- 63) WFLYUT0021: Registered web context: /DmMethods 16:10:44,519 INFO [org.wildfly.extension.undertow] (ServerService Thread Pool -- 64) WFLYUT0021: Registered web context: /ACS 16:10:44,563 INFO [org.jboss.as.server] (ServerService Thread Pool -- 35) WFLYSRV0010: Deployed "acs.ear" (runtime-name : "acs.ear") 16:10:44,564 INFO [org.jboss.as.server] (ServerService Thread Pool -- 35) WFLYSRV0010: Deployed "ServerApps.ear" (runtime-name : "ServerApps.ear") 16:10:44,911 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0060: Http management interface listening on http://0.0.0.0:9085/management 16:10:44,912 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0051: Admin console listening on http://0.0.0.0:9085 16:10:44,912 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0025: WildFly Full 9.0.1.Final (WildFly Core 1.0.1.Final) started in 23083ms - Started 686 of 905 services (298 services are lazy, passive or on-demand)
As shown above, the WildFly has been started successfully. In this example, I really took a default JMS setup with just a few custom JVM parameters (Xms, Xmx, aso…) but as you can see in the logs above, there are a few issues with the default setup like deprecated or missing parameters. So I would strongly suggest you to take a look at that and configure properly your JMS once it is up & running!
Earlier in this blog, I mentioned that there are a few things that changed between JBoss 7.1.1 (CS 7.2 / xPlore 1.5) and WildFly 9.0.1 (CS 7.3 / xPlore 1.6). In a future blog, I will talk about another change which is how to setup a WildFly instance in SSL.