Documentum story – Unable to start a new Managed Server in SSL in WebLogic

Some time ago, I was creating a new Managed Server named msD2-02 on an existing domain of a WebLogic Server 12.1.3.0 created loooong ago and I faced a small issue that I will try to explain in this blog. This Managed Server will be used to host a D2 4.5 Application (Documentum Client) and I created it using the Administration Console, customized it, enabled the SSL with internal SSL Certificates, the SAML2 Single Sign-On, aso…

When I wanted to start it for the first time, I get an error showing that the user/password used was wrong… So I tried to recreate the boot.properties file from scratch, setting up the username/password in there and tried again: same error. What to do then? To be sure that the password was correct (even if I was pretty sure), I tried to copy the boot.properties file from another Managed Server and tried again but same result over and over. Therefore I tried a last time removing the boot.properties completely to enter the credentials during the startup:

[weblogic@weblogic_server_01 msD2-02]$ /app/weblogic/domains/DOMAIN/bin/startManagedWebLogic.sh msD2-02 t3s://weblogic_server_01:8443

JAVA Memory arguments: -Xms2048m -Xmx2048m -XX:MaxMetaspaceSize=512m

CLASSPATH=/app/weblogic/Middleware/wlserver/server/lib/jcmFIPS.jar:/app/weblogic/Middleware/wlserver/server/lib/sslj.jar:/app/weblogic/Middleware/wlserver/server/lib/cryptoj.jar::/app/weblogic/Java/jdk1.8.0_45/lib/tools.jar:/app/weblogic/Middleware/wlserver/server/lib/weblogic_sp.jar:/app/weblogic/Middleware/wlserver/server/lib/weblogic.jar:/app/weblogic/Middleware/wlserver/../oracle_common/modules/net.sf.antcontrib_1.1.0.0_1-0b3/lib/ant-contrib.jar:/app/weblogic/Middleware/wlserver/modules/features/oracle.wls.common.nodemanager_2.0.0.0.jar:/app/weblogic/Middleware/wlserver/common/derby/lib/derbyclient.jar:/app/weblogic/Middleware/wlserver/common/derby/lib/derby.jar:/app/weblogic/Middleware/wlserver/server/lib/xqrl.jar:/app/weblogic/domains/DOMAIN/lib/LB.jar:/app/weblogic/domains/DOMAIN/lib/LBJNI.jar:

PATH=/app/weblogic/Middleware/wlserver/server/bin:/app/weblogic/Middleware/wlserver/../oracle_common/modules/org.apache.ant_1.9.2/bin:/app/weblogic/Java/jdk1.8.0_45/jre/bin:/app/weblogic/Java/jdk1.8.0_45/bin:/app/weblogic/domains/DOMAIN/D2/lockbox:/app/weblogic/domains/DOMAIN/D2/lockbox/lib/native/linux_gcc34_x64:/app/weblogic/Java/jdk1.8.0_45/bin:/usr/lib64/qt-3.3/bin:/usr/local/bin:/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/sbin:/home/weblogic/bin

***************************************************
*  To start WebLogic Server, use a username and   *
*  password assigned to an admin-level user.  For *
*  server administration, use the WebLogic Server *
*  console at http://hostname:port/console        *
***************************************************
starting weblogic with Java version:
java version "1.8.0_45"
Java(TM) SE Runtime Environment (build 1.8.0_45-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.45-b02, mixed mode)
Starting WLS with line:
/app/weblogic/Java/jdk1.8.0_45/bin/java -server -Xms2048m -Xmx2048m -XX:MaxMetaspaceSize=512m -Dweblogic.Name=msD2-02 -Djava.security.policy=/app/weblogic/Middleware/wlserver/server/lib/weblogic.policy  -Dweblogic.ProductionModeEnabled=true -Dweblogic.security.SSL.trustedCAKeyStore=/app/weblogic/Middleware/wlserver/server/lib/cacerts  -Dcom.sun.xml.ws.api.streaming.XMLStreamReaderFactory.woodstox=true -Dcom.sun.xml.ws.api.streaming.XMLStreamWriterFactory.woodstox=true -Djava.io.tmpdir=/app/weblogic/tmp/DOMAIN/msD2-02 -Ddomain.home=/app/weblogic/domains/DOMAIN -Dweblogic.nodemanager.ServiceEnabled=true -Dweblogic.security.SSL.protocolVersion=TLS1 -Dweblogic.security.disableNullCipher=true -Djava.security.egd=file:///dev/./urandom -Dweblogic.security.allowCryptoJDefaultJCEVerification=true -Dweblogic.nodemanager.ServiceEnabled=true  -Djava.endorsed.dirs=/app/weblogic/Java/jdk1.8.0_45/jre/lib/endorsed:/app/weblogic/Middleware/wlserver/../oracle_common/modules/endorsed  -da -Dwls.home=/app/weblogic/Middleware/wlserver/server -Dweblogic.home=/app/weblogic/Middleware/wlserver/server   -Dweblogic.management.server=t3s://weblogic_server_01:8443  -Dweblogic.utils.cmm.lowertier.ServiceDisabled=true  weblogic.Server
<Jun 14, 2016 11:52:43 AM UTC> <Info> <Security> <BEA-090906> <Changing the default Random Number Generator in RSA CryptoJ from ECDRBG128 to FIPS186PRNG. To disable this change, specify -Dweblogic.security.allowCryptoJDefaultPRNG=true.>
<Jun 14, 2016 11:52:43 AM UTC> <Notice> <WebLogicServer> <BEA-000395> <The following extensions directory contents added to the end of the classpath:
/app/weblogic/domains/DOMAIN/lib/LB.jar:/app/weblogic/domains/DOMAIN/lib/LBJNI.jar.>
<Jun 14, 2016 11:52:44 AM UTC> <Info> <WebLogicServer> <BEA-000377> <Starting WebLogic Server with Java HotSpot(TM) 64-Bit Server VM Version 25.45-b02 from Oracle Corporation.>
<Jun 14, 2016 11:52:44 AM UTC> <Info> <Security> <BEA-090065> <Getting boot identity from user.>
Enter username to boot WebLogic server:weblogic
Enter password to boot WebLogic server:
<Jun 14, 2016 11:52:54 AM UTC> <Warning> <Security> <BEA-090924> <JSSE has been selected by default, since the SSLMBean is not available.>
<Jun 14, 2016 11:52:54 AM UTC> <Info> <Security> <BEA-090908> <Using the default WebLogic SSL Hostname Verifier implementation.>
<Jun 14, 2016 11:52:54 AM UTC> <Notice> <Security> <BEA-090169> <Loading trusted certificates from the jks keystore file /app/weblogic/Middleware/wlserver/server/lib/cacerts.>
<Jun 14, 2016 11:52:54 AM UTC> <Info> <Management> <BEA-141298> <Could not register with the Administration Server: java.rmi.RemoteException: [Deployer:149150]An IOException occurred while reading the input.; nested exception is:
        javax.net.ssl.SSLException: Error using PKIX CertPathBuilder.>
<Jun 14, 2016 11:52:54 AM UTC> <Info> <Management> <BEA-141107> <Version: WebLogic Server 12.1.3.0.0  Wed May 21 18:53:34 PDT 2014 1604337 >
<Jun 14, 2016 11:52:55 AM UTC> <Info> <Security> <BEA-090908> <Using the default WebLogic SSL Hostname Verifier implementation.>
<Jun 14, 2016 11:52:55 AM UTC> <Notice> <Security> <BEA-090169> <Loading trusted certificates from the jks keystore file /app/weblogic/Middleware/wlserver/server/lib/cacerts.>
<Jun 14, 2016 11:52:55 AM UTC> <Alert> <Management> <BEA-141151> <The Administration Server could not be reached at https://weblogic_server_01:8443.>
<Jun 14, 2016 11:52:55 AM UTC> <Info> <Configuration Management> <BEA-150018> <This server is being started in Managed Server independence mode in the absence of the Administration Server.>
<Jun 14, 2016 11:52:55 AM UTC> <Notice> <WebLogicServer> <BEA-000365> <Server state changed to STARTING.>
<Jun 14, 2016 11:52:55 AM UTC> <Info> <WorkManager> <BEA-002900> <Initializing self-tuning thread pool.>
<Jun 14, 2016 11:52:55 AM UTC> <Info> <WorkManager> <BEA-002942> <CMM memory level becomes 0. Setting standby thread pool size to 256.>
<Jun 14, 2016 11:52:55 AM UTC> <Notice> <Log Management> <BEA-170019> <The server log file /app/weblogic/domains/DOMAIN/servers/msD2-02/logs/msD2-02.log is opened. All server side log events will be written to this file.>
<Jun 14, 2016 11:52:57 AM UTC> <Notice> <Security> <BEA-090082> <Security initializing using security realm myrealm.>
<Jun 14, 2016 11:52:57 AM UTC> <Notice> <Security> <BEA-090171> <Loading the identity certificate and private key stored under the alias alias_cert from the JKS keystore file /app/weblogic/domains/DOMAIN/certs/identity.jks.>
<Jun 14, 2016 11:52:57 AM UTC> <Notice> <Security> <BEA-090169> <Loading trusted certificates from the JKS keystore file /app/weblogic/domains/DOMAIN/certs/trust.jks.>
<Jun 14, 2016 11:52:58 AM UTC> <Critical> <Security> <BEA-090403> <Authentication for user weblogic denied.>
<Jun 14, 2016 11:52:58 AM UTC> <Critical> <WebLogicServer> <BEA-000386> <Server subsystem failed. Reason: A MultiException has 6 exceptions.  They are:
1. weblogic.security.SecurityInitializationException: Authentication for user weblogic denied.
2. java.lang.IllegalStateException: Unable to perform operation: post construct on weblogic.security.SecurityService
3. java.lang.IllegalArgumentException: While attempting to resolve the dependencies of weblogic.jndi.internal.RemoteNamingService errors were found
4. java.lang.IllegalStateException: Unable to perform operation: resolve on weblogic.jndi.internal.RemoteNamingService
5. java.lang.IllegalArgumentException: While attempting to resolve the dependencies of weblogic.t3.srvr.T3InitializationService errors were found
6. java.lang.IllegalStateException: Unable to perform operation: resolve on weblogic.t3.srvr.T3InitializationService

A MultiException has 6 exceptions.  They are:
1. weblogic.security.SecurityInitializationException: Authentication for user weblogic denied.
2. java.lang.IllegalStateException: Unable to perform operation: post construct on weblogic.security.SecurityService
3. java.lang.IllegalArgumentException: While attempting to resolve the dependencies of weblogic.jndi.internal.RemoteNamingService errors were found
4. java.lang.IllegalStateException: Unable to perform operation: resolve on weblogic.jndi.internal.RemoteNamingService
5. java.lang.IllegalArgumentException: While attempting to resolve the dependencies of weblogic.t3.srvr.T3InitializationService errors were found
6. java.lang.IllegalStateException: Unable to perform operation: resolve on weblogic.t3.srvr.T3InitializationService

        at org.jvnet.hk2.internal.Collector.throwIfErrors(Collector.java:88)
        at org.jvnet.hk2.internal.ClazzCreator.resolveAllDependencies(ClazzCreator.java:269)
        at org.jvnet.hk2.internal.ClazzCreator.create(ClazzCreator.java:413)
        at org.jvnet.hk2.internal.SystemDescriptor.create(SystemDescriptor.java:456)
        at org.glassfish.hk2.runlevel.internal.AsyncRunLevelContext.findOrCreate(AsyncRunLevelContext.java:225)
        Truncated. see log file for complete stacktrace
Caused By: weblogic.security.SecurityInitializationException: Authentication for user weblogic denied.
        at weblogic.security.service.CommonSecurityServiceManagerDelegateImpl.doBootAuthorization(CommonSecurityServiceManagerDelegateImpl.java:1023)
        at weblogic.security.service.CommonSecurityServiceManagerDelegateImpl.postInitialize(CommonSecurityServiceManagerDelegateImpl.java:1131)
        at weblogic.security.service.SecurityServiceManager.postInitialize(SecurityServiceManager.java:943)
        at weblogic.security.SecurityService.start(SecurityService.java:159)
        at weblogic.server.AbstractServerService.postConstruct(AbstractServerService.java:78)
        Truncated. see log file for complete stacktrace
Caused By: javax.security.auth.login.FailedLoginException: [Security:090303]Authentication Failed: User weblogic weblogic.security.providers.authentication.LDAPAtnDelegateException: [Security:090295]caught unexpected exception
        at weblogic.security.providers.authentication.LDAPAtnLoginModuleImpl.login(LDAPAtnLoginModuleImpl.java:257)
        at com.bea.common.security.internal.service.LoginModuleWrapper$1.run(LoginModuleWrapper.java:110)
        at java.security.AccessController.doPrivileged(Native Method)
        at com.bea.common.security.internal.service.LoginModuleWrapper.login(LoginModuleWrapper.java:106)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        Truncated. see log file for complete stacktrace
>
<Jun 14, 2016 11:52:58 AM UTC> <Notice> <WebLogicServer> <BEA-000365> <Server state changed to FAILED.>
<Jun 14, 2016 11:52:58 AM UTC> <Error> <WebLogicServer> <BEA-000383> <A critical service failed. The server will shut itself down.>
<Jun 14, 2016 11:52:58 AM UTC> <Notice> <WebLogicServer> <BEA-000365> <Server state changed to FORCE_SHUTTING_DOWN.>

As you can see above, the WebLogic Managed Server is able to retrieve and read the SSL Keystores (identity and trust) so this apparently isn’t the issue which seems to be linked to a wrong username/password. Strange isn’t it?

All other Managed Servers are working perfectly, the applications are accessible in HTTPS, we can see the status of the servers via WLST/AdminConsole, aso… But this specific Managed Server isn’t able to start… After some reflexion, I thought at the Embedded LDAP! This is a completely new Managed Server and I tried to start it directly in HTTPS. What if this Managed Server isn’t able to authenticate the user weblogic because this user doesn’t exist in the Embedded LDAP of the Managed Server? Indeed during the first start, a Managed Server will try to automatically replicate the Embedded LDAP from the AdminServer which contains the primary Embedded LDAP. Just for information, we usually create a bunch of Managed Servers for Documentum during the domain creation and therefore all these Managed Servers are usually started at least 1 time in HTTP before setting up the SSL in the Domain: that’s the main difference between the existing Managed Servers and the new one and therefore I dug deeper in this direction.

To test my theory, I tried to replicate the Embedded LDAP manually. In case you don’t know how to do it, please take a look at this blog which explains that in details: click here. After doing that, the Managed Server msD2-02 was indeed able to start because it was able to authenticate the user weblogic but that doesn’t explain why the Embedded LDAP wasn’t replicated automatically in the first place…

So I checked more deeply the logs and actually the first strange message during startup is always the same:

<Jun 14, 2016 11:52:54 AM UTC> <Info> <Management> <BEA-141298> <Could not register with the Administration Server: java.rmi.RemoteException: [Deployer:149150]An IOException occurred while reading the input.; nested exception is:
        javax.net.ssl.SSLException: Error using PKIX CertPathBuilder.>

As said previously, all components are setup in HTTPS and only HTTPS. Therefore all communications are using an SSL Certificate. For this customer, we weren’t using a Self-Signed Certificate but a Certificate Signed by an internal Certificate Authority. As shown in the Info message, the Managed Server wasn’t able to register with the AdminServer with an SSL Exception… Therefore I checked the SSL Certificate, the Root and Gold Certificate Authority too but for me everything was working properly. The Admin Console is accessible in HTTPS, all Applications are accessible, the status of the Managed Servers are visible in the Administration Console and via WLST which shows that they are able to communicate internally too, aso… So what could be wrong? Well after checking the startup command of the Managed Server (and actually it is also mentioned in the startup logs), I found the following:

[weblogic@weblogic_server_01 servers]$ ps -ef | grep msD2-02 | grep -v grep
weblogic 31313     1  0 14:34 pts/2    00:00:00 /bin/sh ../startManagedWebLogic.sh msD2-02 t3s://weblogic_server_01:8443
weblogic 31378 31315 26 14:34 pts/2    00:00:35 /app/weblogic/Java/jdk1.8.0_45/bin/java -server
    -Xms2048m -Xmx2048m -XX:MaxMetaspaceSize=512m -Dweblogic.Name=msD2-02
    -Djava.security.policy=/app/weblogic/Middleware/wlserver/server/lib/weblogic.policy -Dweblogic.ProductionModeEnabled=true
    -Dweblogic.security.SSL.trustedCAKeyStore=/app/weblogic/Middleware/wlserver/server/lib/cacerts
    -Dcom.sun.xml.ws.api.streaming.XMLStreamReaderFactory.woodstox=true -Dcom.sun.xml.ws.api.streaming.XMLStreamWriterFactory.woodstox=true
    -Djava.io.tmpdir=/app/weblogic/tmp/DOMAIN/msD2-02 -Ddomain.home=/app/weblogic/domains/DOMAIN -Dweblogic.nodemanager.ServiceEnabled=true
    -Dweblogic.security.SSL.protocolVersion=TLS1 -Dweblogic.security.disableNullCipher=true -Djava.security.egd=file:///dev/./urandom
    -Dweblogic.security.allowCryptoJDefaultJCEVerification=true -Dweblogic.nodemanager.ServiceEnabled=true
    -Djava.endorsed.dirs=/app/weblogic/Java/jdk1.8.0_45/jre/lib/endorsed:/app/weblogic/Middleware/wlserver/../oracle_common/modules/endorsed
    -da -Dwls.home=/app/weblogic/Middleware/wlserver/server -Dweblogic.home=/app/weblogic/Middleware/wlserver/server
    -Dweblogic.management.server=t3s://weblogic_server_01:8443 -Dweblogic.utils.cmm.lowertier.ServiceDisabled=true weblogic.Server

What is this JVM parameter? Why does WebLogic defines a specific cacerts for this Managed Server and isn’t using the default one (included in Java)? Something is strange with this startup command…So I checked all other WebLogic Server processes and apparently ALL Managed Servers include this custom cacerts while the AdminServer doesn’t… Is that a bug?! Even if it makes sense to create a custom cacerts for WebLogic only, then why the AdminServer isn’t using it? This fact doesn’t make any sense and this is why we are facing this issue:
– All Managed Servers are using: /app/weblogic/Middleware/wlserver/server/lib/cacerts
– The AdminServer is using: /app/weblogic/Java/jdk1.8.0_45/jre/lib/security/cacerts

After checking the different startup scripts, it appears that this is define in the file startManagedServer.sh. Therefore this JVM parameter is only used by the Managed Server and therefore it is apparently a choice from Oracle (or something that has been forgotten…) to only start the Managed Servers with this option and not the AdminServer… Using different cacerts means that the SSL Certificates trusted by Java (default one) will be trusted by the AdminServer but it will not be the case for the Managed Servers. In our setup, we always add the Root and Gold Certificates (SSL Chain) in the default Java cacerts because it is the one used to allow the setup of our Domain and our Applications in SSL. This is working properly but that isn’t enough to allow the Managed Servers to start properly: you also need to take care of this second cacerts and that’s the reason why the new Managed Server wasn’t able to register to the AdminServer and therefore not able to replicate the Embedded LDAP.

So how to correct that? First, let’s export the Certificate Chain from the identity keystore and import that into the WebLogic cacerts too:

[weblogic@weblogic_server_01 servers]$ keytool -export -v -alias root_ca -file rootCA.der -keystore /app/weblogic/domains/DOMAIN/certs/identity.jks
[weblogic@weblogic_server_01 servers]$ keytool -export -v -alias gold_ca -file goldCA.der -keystore /app/weblogic/domains/DOMAIN/certs/identity.jks
[weblogic@weblogic_server_01 servers]$
[weblogic@weblogic_server_01 servers]$ keytool -import -v -trustcacerts -alias root_ca -file rootCA.der -keystore /app/weblogic/Middleware/wlserver/server/lib/cacerts
Enter keystore password:
[weblogic@weblogic_server_01 servers]$ keytool -import -v -trustcacerts -alias gold_ca -file goldCA.der -keystore /app/weblogic/Middleware/wlserver/server/lib/cacerts
Enter keystore password:

After doing that, you just have to remove the Embedded LDAP of this Managed Server to reinitialize it using the same steps as before but just do not copy the ldap from the AdminServer since we need to ensure that the automatic replication is working now. Then start the Managed Server one last time and verify that the replication is happening properly and therefore if the Managed Server is able to start or not. For me, everything was now working properly, so that’s a victory! 🙂