Infrastructure at your Service

Morgan Patou

Documentum – WildFly not able to start in a CS 7.3 / xPlore 1.6

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.

 

 

Leave a Reply


five × 7 =

Morgan Patou
Morgan Patou

Senior Consultant