Friday, February 5, 2016

Server subsystem failed. Reason: A MultiException has 10 exceptions when starting Oracle® WebLogic managed server

The problem

After starting the Oracle® WebLogic AdminServer in a sandbox environment, I attempted to start the managed servers, but got the following errors in the $DOMAIN_HOME/servers/<ms-server>/logs/<ms-server>.out log file:

<Feb 5, 2016 8:31:03 AM UTC> <Critical> <WebLogicServer> <BEA-000386> <Server subsystem failed. Reason: A MultiException has 10 exceptions.  They are:
1. java.lang.AssertionError: Assertion violated
2. java.lang.IllegalStateException: Unable to perform operation: post construct on weblogic.ldap.EmbeddedLDAP
3. java.lang.IllegalArgumentException: While attempting to resolve the dependencies of weblogic.security.PreSecurityService errors were found
4. java.lang.IllegalStateException: Unable to perform operation: resolve on weblogic.security.PreSecurityService
5. java.lang.IllegalArgumentException: While attempting to resolve the dependencies of weblogic.security.SecurityService errors were found
6. java.lang.IllegalStateException: Unable to perform operation: resolve on weblogic.security.SecurityService
7. java.lang.IllegalArgumentException: While attempting to resolve the dependencies of weblogic.jndi.internal.RemoteNamingService errors were found
8. java.lang.IllegalStateException: Unable to perform operation: resolve on weblogic.jndi.internal.RemoteNamingService
9. java.lang.IllegalArgumentException: While attempting to resolve the dependencies of weblogic.jndi.internal.ForeignJNDIManagerService errors were found
10. java.lang.IllegalStateException: Unable to perform operation: resolve on weblogic.jndi.internal.ForeignJNDIManagerService

A MultiException has 10 exceptions.  They are:
1. java.lang.AssertionError: Assertion violated
2. java.lang.IllegalStateException: Unable to perform operation: post construct on weblogic.ldap.EmbeddedLDAP
3. java.lang.IllegalArgumentException: While attempting to resolve the dependencies of weblogic.security.PreSecurityService errors were found
4. java.lang.IllegalStateException: Unable to perform operation: resolve on weblogic.security.PreSecurityService
5. java.lang.IllegalArgumentException: While attempting to resolve the dependencies of weblogic.security.SecurityService errors were found
6. java.lang.IllegalStateException: Unable to perform operation: resolve on weblogic.security.SecurityService
7. java.lang.IllegalArgumentException: While attempting to resolve the dependencies of weblogic.jndi.internal.RemoteNamingService errors were found
8. java.lang.IllegalStateException: Unable to perform operation: resolve on weblogic.jndi.internal.RemoteNamingService
9. java.lang.IllegalArgumentException: While attempting to resolve the dependencies of weblogic.jndi.internal.ForeignJNDIManagerService errors were found
10. java.lang.IllegalStateException: Unable to perform operation: resolve on weblogic.jndi.internal.ForeignJNDIManagerService

        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: java.lang.AssertionError: Assertion violated
        at weblogic.utils.Debug.assertion(Debug.java:58)
        at weblogic.server.channels.ChannelService.getServerChannel(ChannelService.java:2049)
        at weblogic.server.channels.ChannelService.getServerChannel(ChannelService.java:1987)
        at weblogic.protocol.ServerChannelManager.findServerChannel(ServerChannelManager.java:79)
        at weblogic.ldap.EmbeddedLDAP.findLdapURL(EmbeddedLDAP.java:1082)
        Truncated. see log file for complete stacktrace
>


The solution

This turned out to be a side effect of a mismatch between the domain binaries and the domain version number in $DOMAIN_HOME/config/config.xml. I have written about that here: http://audunnes.blogspot.dk/2016/02/the-domain-version-122100-is-greater.html

The domain version 12.2.1.0.0 is greater than the release version 12.1.3.0 of this server when starting an Oracle® WebLogic managed server.

The problem

After starting the Oracle® WebLogic AdminServer in a sandbox environment, I attempted to start the managed servers, but got the following errors in the $DOMAIN_HOME/servers/<ms-server>/logs/<ms-server>.out log file:

<Error> <Configuration Management> <BEA-150001> <An error occurred while connecting to the Administration Server to bootstrap through the URL: http://localhost:7001/bea_wls_management_internal2/Bootstrap,
 user: weblogic.
weblogic.management.configuration.ConfigurationException: [Management:141252]The domain version 12.2.1.0.0 is greater than the release version 12.1.3.0 of this server.
        at weblogic.management.provider.internal.BootStrapHelper.getBootStrapStruct(BootStrapHelper.java:147)
        at weblogic.management.provider.internal.RuntimeAccessImpl.initialize(RuntimeAccessImpl.java:444)
        at weblogic.management.provider.internal.RuntimeAccessService.start(RuntimeAccessService.java:70)
        at weblogic.server.AbstractServerService.postConstruct(AbstractServerService.java:78)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:606)
        at org.glassfish.hk2.utilities.reflection.ReflectionHelper.invoke(ReflectionHelper.java:1017)
        at org.jvnet.hk2.internal.ClazzCreator.postConstructMe(ClazzCreator.java:388)
        at org.jvnet.hk2.internal.ClazzCreator.create(ClazzCreator.java:430)
        at org.jvnet.hk2.internal.SystemDescriptor.create(SystemDescriptor.java:456)
        at org.glassfish.hk2.runlevel.internal.AsyncRunLevelContext.findOrCreate(AsyncRunLevelContext.java:225)
        at org.glassfish.hk2.runlevel.RunLevelContext.findOrCreate(RunLevelContext.java:82)
        at org.jvnet.hk2.internal.Utilities.createService(Utilities.java:2488)
        at org.jvnet.hk2.internal.ServiceHandleImpl.getService(ServiceHandleImpl.java:98)
        at org.jvnet.hk2.internal.ServiceLocatorImpl.getService(ServiceLocatorImpl.java:606)
        at org.jvnet.hk2.internal.ThreeThirtyResolver.resolve(ThreeThirtyResolver.java:77)
        at org.jvnet.hk2.internal.ClazzCreator.resolve(ClazzCreator.java:231)
        at org.jvnet.hk2.internal.ClazzCreator.resolveAllDependencies(ClazzCreator.java:254)
        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)
        at org.glassfish.hk2.runlevel.RunLevelContext.findOrCreate(RunLevelContext.java:82)
        at org.jvnet.hk2.internal.Utilities.createService(Utilities.java:2488)
        at org.jvnet.hk2.internal.ServiceHandleImpl.getService(ServiceHandleImpl.java:98)
        at org.jvnet.hk2.internal.ServiceHandleImpl.getService(ServiceHandleImpl.java:87)
        at org.glassfish.hk2.runlevel.internal.CurrentTaskFuture$QueueRunner.oneJob(CurrentTaskFuture.java:1162)
        at org.glassfish.hk2.runlevel.internal.CurrentTaskFuture$QueueRunner.run(CurrentTaskFuture.java:1147)

The cause

I was at first a bit puzzled by the message "The domain version 12.2.1.0.0 is greater than the release version 12.1.3.0 of this server." because the AdminServer console footer said it was version 12.1.3.0, and the startup scripts in $DOMAIN_HOME/bin also only pointed to 12.1.3.0 binaries.

I discovered there were 12.2.1.0.0 binaries installed in a new $ORACLE_HOME, but as mentioned, these binaries were not referenced by the scripts in $DOMAIN_HOME/bin.

The fact that 12.2.1.0.0 binaries were available on the file system suggested someone had either planned to create a new 12.2.1.0.0 domain, or planned to upgrade the existing 12.1.3.0 domain.

After discussing this with a colleague it became clear that he had installed the new binaries, and that all he wanted to do with them was to create response files for running the upgrade of a domain on a different server. He only intended to run the information collection part, but it had obviously also touched the $DOMAIN_HOME/config/confix.xml file in the 12.1.3.0 domain, and changed the version parameter to 12.2.1.0.0 as shown below:

$ grep version $DOMAIN_HOME/config/config.xml
<?xml version='1.0' encoding='UTF-8'?>
  <domain-version>12.2.1.0.0</domain-version>
  <configuration-version>12.2.1.0.0</configuration-version>

The solution

  1. Shutdown the entire domain. In my case that meant the AdminServer and the NodeManager.
  2. Took a file system backup of $DOMAIN_HOME
  3. Edited $DOMAIN_HOME/config/config.xml and replaced the two occurences of 12.2.1.0.0 with 12.1.3.0.0
  4. Started the NodeManager, the AdminServer and the managed servers up without any errors.

Post-change verification:

$ grep version config.xml
<?xml version='1.0' encoding='UTF-8'?>
  <domain-version>12.1.3.0.0</domain-version>
  <configuration-version>12.1.3.0.0</configuration-version>

Unexpected EOF in prolog when starting Oracle® WebLogic AdminServer

The problem

The Oracle® WebLogic AdminServer has started up and reached RUNNING state, but I have the habit of checking the AdminServer.out file after startup, and today I saw the following error:

<Error> <Default> <J2EE JMX-47001> <A JAXB error occurred during unmarshalling of "usermessagingconfig.xml".
javax.xml.bind.UnmarshalException
 - with linked exception:
[Exception [EclipseLink-25004] (Eclipse Persistence Services - 2.5.2.v20140319-9ad6abd): org.eclipse.persistence.exceptions.XMLMarshalException
Exception Description: An error occurred unmarshalling the document
Internal Exception: com.ctc.wstx.exc.WstxEOFException: Unexpected EOF in prolog
 at [row,col {unknown-source}]: [1,0]]
        at org.eclipse.persistence.jaxb.JAXBUnmarshaller.handleXMLMarshalException(JAXBUnmarshaller.java:980)
        at org.eclipse.persistence.jaxb.JAXBUnmarshaller.unmarshal(JAXBUnmarshaller.java:588)
        at org.eclipse.persistence.jaxb.JAXBUnmarshaller.unmarshal(JAXBUnmarshaller.java:140)
        at oracle.as.config.persistence.jaxb.JAXBXmlPersistenceManagerImpl.load(JAXBXmlPersistenceManagerImpl.java:190)
        at oracle.as.jmx.framework.util.DefaultConfigObjectMBeanAssociationInfo.loadConfigObject(DefaultConfigObjectMBeanAssociationInfo.java:638)
        at oracle.as.jmx.framework.util.DefaultConfigObjectMBeanAssociationInfo.initializeConfigObjectAndAssociatedMBean(DefaultConfigObjectMBeanAssociationInfo.java:676)
        at oracle.as.jmx.framework.wls.spi.ComponentMBeans.registerMBeans(ComponentMBeans.java:244)
        at oracle.as.jmx.framework.wls.spi.ComponentMBeans.registerDomainLevelMBeans(ComponentMBeans.java:356)
        at oracle.as.jmx.framework.wls.spi.ComponentMBeans.registerRuntimeMBeanServerMBeans(ComponentMBeans.java:373)
        at oracle.as.jmx.framework.wls.spi.JMXFrameworkProviderImpl$3.run(JMXFrameworkProviderImpl.java:1134)
        at java.security.AccessController.doPrivileged(Native Method)
        at oracle.as.jmx.framework.wls.spi.JMXFrameworkProviderImpl.initRuntimeMBeanServer(JMXFrameworkProviderImpl.java:1127)
        at oracle.as.jmx.framework.wls.spi.JMXFrameworkProviderImpl.access$200(JMXFrameworkProviderImpl.java:210)
        at oracle.as.jmx.framework.wls.spi.JMXFrameworkProviderImpl$2.run(JMXFrameworkProviderImpl.java:1080)
        at java.lang.Thread.run(Thread.java:745)
Caused By: Exception [EclipseLink-25004] (Eclipse Persistence Services - 2.5.2.v20140319-9ad6abd): org.eclipse.persistence.exceptions.XMLMarshalException

The cause

The usermessagingconfig.xml in question was located in $DOMAIN_HOME/config/fmwconfig/usermessagingconfig.xml

ls -l $DOMAIN_HOME/config/fmwconfig/usermessagingconfig.xml confirmed that the file had not been update since the 9th of September 2015, but then again this WebLogic server had been running for several months before I restarted it today. This is a sandbox server so it is used very infrequently.

ls -l $DOMAIN_HOME/config/fmwconfig/usermessagingconfig.xml also showed me that the size was 0 bytes. 

I remembered that the mount point where WebLogic stores its domain configuration files ran out of disk space in September last year. At that time it corrupted the EmbeddedLDAP folder, but after clearing the log files and re-creating the EmbeddedLDAP, WebLogic was started up again. In hindsight I realize that the same error with usermessagingconfig.xml must have been in AdminServer.out back then as well, but I obviously failed to notice it at the time. 

The solution

I added the following to $DOMAIN_HOME/config/fmwconfig/usermessagingconfig.xml:

<?xml version="1.0"?>
<MessagingConfiguration xmlns="http://www.oracle.com/ucs/messaging/config"
                        xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
                        xsi:schemaLocation="http://www.oracle.com/ucs/messaging/config ../config.xsd" version="12.1.3.0.0">


  <Server>
  </Server>

</MessagingConfiguration>

Then restarted the AdminServer, and the error was gone.

Thursday, February 4, 2016

Oracle® 12c Database Configuration Assistant hangs on Oracle® Linux 7 in VirtualBox 5

I recently installed Oracle® Linux 7.2 on my VirtualBox 5.0.14 installation on Windows 7 in order to have a private playground for evaluating software. Afterwards I installed Oracle® 12c database version 12.1.0.2 on my new virtual Linux server. This went fine until I fired up Database Configuration Assistant (DBCA) in order to create a playground database. DBCA just hanged forever without consuming noticeable CPU. I kept it running for an entire night, but it never started fully up. It kept hanging at the splash screen as shown below:



Investigations

The log file $ORACLE_BASE/cfgtoollogs/dbca/trace.log_OraDB12Home1_<timestamp> showed the following:

[main] [ 2016-02-04 10:06:33.737 CET ] [Host.<init>:1090]  Begin tracing..
[main] [ 2016-02-04 10:06:34.971 CET ] [UIHost.createHelpSet:485]  HelpSetParseExceptionjava.lang.NullPointerException
[main] [ 2016-02-04 10:06:36.703 CET ] [Host.checkIfBigClusterAndHubNode:1710]  Not a cluster environment: exiting BigCluster Check
[main] [ 2016-02-04 10:06:36.708 CET ] [InventoryUtil.getOUIInvSession:349]  setting OUI READ level to ACCESSLEVEL_READ_LOCKLESS
[main] [ 2016-02-04 10:06:36.708 CET ] [InventoryUtil.isCRSHome:386]  Homeinfo /u01/app/oracle/product/12.1.0/dbhome_1,1
[main] [ 2016-02-04 10:06:36.922 CET ] [Host.validateGridHome:3878]  Validation false
[main] [ 2016-02-04 10:06:36.922 CET ] [Host.startOperation:2395]  Source db null
[main] [ 2016-02-04 10:06:36.922 CET ] [Host.startOperation:2396]  GDB Name null
[main] [ 2016-02-04 10:06:36.957 CET ] [Host.startOperation:2397]  MgmtDB sid -MGMTDB
[main] [ 2016-02-04 10:06:36.957 CET ] [Host.startOperation:2398]  MgmtDB name _mgmtdb
[main] [ 2016-02-04 10:06:36.998 CET ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: null
[main] [ 2016-02-04 10:06:37.000 CET ] [InventoryUtil.getOUIInvSession:349]  setting OUI READ level to ACCESSLEVEL_READ_LOCKLESS
[main] [ 2016-02-04 10:06:37.000 CET ] [OracleHome.getVersion:1010]  Homeinfo /u01/app/oracle/product/12.1.0/dbhome_1,1
[main] [ 2016-02-04 10:06:37.181 CET ] [OracleHome.getVersion:1038]  OracleHome.server.getVersion Version: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.182 CET ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.182 CET ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.182 CET ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.183 CET ] [CommonUtils.createPasswordFile:1243]  calling new orapwd for 11.1 or higher
[main] [ 2016-02-04 10:06:37.183 CET ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.184 CET ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.184 CET ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.184 CET ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.184 CET ] [CommonUtils.getPasswordFileCreateCmd:1182]  for new orapwd for 11.1 or higher
[main] [ 2016-02-04 10:06:37.189 CET ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.190 CET ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.190 CET ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.190 CET ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.191 CET ] [CommonUtils.getPasswordFileCreateCmd:1213]  /u01/app/oracle/product/12.1.0/dbhome_1/bin/orapwd
[main] [ 2016-02-04 10:06:37.191 CET ] [CommonUtils.getPasswordFileCreateCmd:1213]  file=/u01/app/oracle/product/12.1.0/dbhome_1/dbs/orapwDBUA0636958
[main] [ 2016-02-04 10:06:37.191 CET ] [CommonUtils.getPasswordFileCreateCmd:1213]  force=y
[main] [ 2016-02-04 10:06:37.191 CET ] [CommonUtils.getPasswordFileCreateCmd:1213]  format=12
[main] [ 2016-02-04 10:06:37.192 CET ] [OsUtilsBase.execProg:2123]  beginning execProg with input array.
[main] [ 2016-02-04 10:06:37.377 CET ] [OsUtilsBase.execProg:2160]  finished execProg with input array. Status:0
[main] [ 2016-02-04 10:06:37.378 CET ] [OracleHome.initOptionsStopOnError:1356]  Initializing Database Options with  for dummy sid=DBUA0636958 using initfile=/u01/app/oracle/product/12.1.0/dbhome_1/dbs/initDBUA0636958.ora using pwdfile=/u01/app/oracle/product/12.1.0/dbhome_1/dbs/orapwDBUA0636958
[main] [ 2016-02-04 10:06:37.398 CET ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.399 CET ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.399 CET ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.400 CET ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.400 CET ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.401 CET ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.402 CET ] [SQLPlusEngine.getCmmdParams:225]  m_home 12.1.0.2.0
[main] [ 2016-02-04 10:06:37.402 CET ] [SQLPlusEngine.getCmmdParams:226]  version > 112 true
[main] [ 2016-02-04 10:06:37.403 CET ] [SQLEngine.getEnvParams:612]  NLS_LANG: AMERICAN_AMERICA.AL32UTF8
[main] [ 2016-02-04 10:06:37.421 CET ] [SQLEngine.initialize:358]  Execing SQLPLUS/SVRMGR process...
[main] [ 2016-02-04 10:06:37.467 CET ] [SQLEngine.initialize:395]  m_bReaderStarted: false
[main] [ 2016-02-04 10:06:37.467 CET ] [SQLEngine.initialize:399]  Starting Reader Thread...
[main] [ 2016-02-04 10:06:42.068 CET ] [OracleHome.initOptionsStopOnError:1370]  executing: startup nomount pfile='/u01/app/oracle/product/12.1.0/dbhome_1/dbs/initDBUA0636958.ora'


The 'ps -ef' command also confirms that sqlplus is stuck in "startup nomount"




Some unsuccessful attempts

- Tried with CentOS 7.1 instead of Oracle® Linux 7.2. Replicated the issue 100%.
- Tried to run DBCA as part of the Oracle® 12c Database installation (Software and starter database) and after a software only install. Same problem in both cases. 

Searching for an answer

I found a similar issue described in https://community.oracle.com/message/13249304#13249304, but no solution was offered, 

The solution

After various unsuccessful attempts to fix this at Linux level, I turned my attention to VirtualBox. After trying to tweak several options, I found the culprit to be the Paravirtualization Interface for acceleration. Changing that from Default to None fixed the issue.




I did not try all the various options for Paravirtualization Interface, but in my setup both with Default and Legacy I faced issues with DBCA.







Tuesday, January 19, 2016

ORA-01017: invalid username/password; logon denied when updating WebLogic data source and you know the username and password are correct

Background

The title might sound a bit confusing, because everyone that has experienced an ORA-01017 knows it only happens if either the database username or password is incorrect.

I recently had to change the password for all of the infrastructure component schemas in a Oracle® SOA Suite 12.1.3 installation. How to do it is documented at https://docs.oracle.com/middleware/1213/core/ASADM/repos.htm#ASADM637

After running the modifyBootStrapCredential for the OPSS configuration I expected everything to be dandy except a few ORA-01017 errors for the data sources I had not yet updated with the new password. Everything I needed to do was to edit each data source and provide the new password. Or so I thought...

The problem

When I tried to apply the changes I got the following ORA-01017 error for each data source I tried to edit:


I was a bit thunderstruck at first because the username and passwords worked fine in both SQL*Plus and in SQL Developer.

The AdminServer out file contained errors like this:
<Jan 19, 2016 1:15:54 PM UTC> <Error> <Deployer> <BEA-149205> <Failed to initialize the application "LocalSvcTblDataSource" due to error weblogic.application.ModuleException: weblogic.common.resourcepool.ResourceSystemException:
 Could not create connection for datasource '<data source name>'.

 The returned message is: ORA-01017: invalid username/password; logon denied

 It is likely that the login or password is not valid.
 It is also possible that something else is invalid in
 the configuration or that the database is not available.
weblogic.application.ModuleException: weblogic.common.resourcepool.ResourceSystemException:
 Could not create connection for datasource '<data source name>'.

 The returned message is: ORA-01017: invalid username/password; logon denied

 It is likely that the login or password is not valid.
 It is also possible that something else is invalid in
 the configuration or that the database is not available.
        at weblogic.jdbc.module.JDBCModule.prepare(JDBCModule.java:350)
        at weblogic.application.internal.flow.ModuleListenerInvoker.prepare(ModuleListenerInvoker.java:100)
        at weblogic.application.internal.flow.ModuleStateDriver$1.next(ModuleStateDriver.java:175)
        at weblogic.application.internal.flow.ModuleStateDriver$1.next(ModuleStateDriver.java:170)
        at weblogic.application.utils.StateMachineDriver.nextState(StateMachineDriver.java:42)
        Truncated. see log file for complete stacktrace
Caused By: weblogic.common.resourcepool.ResourceSystemException:
 Could not create connection for datasource '<data source name>'.

 The returned message is: ORA-01017: invalid username/password; logon denied

 It is likely that the login or password is not valid.
 It is also possible that something else is invalid in
 the configuration or that the database is not available.
        at weblogic.jdbc.common.internal.JDBCUtil.parseException(JDBCUtil.java:322)
        at weblogic.jdbc.common.internal.ConnectionEnvFactory.makeConnection0(ConnectionEnvFactory.java:492)
        at weblogic.jdbc.common.internal.ConnectionEnvFactory.access$000(ConnectionEnvFactory.java:20)
        at weblogic.jdbc.common.internal.ConnectionEnvFactory$1.run(ConnectionEnvFactory.java:388)
        at java.security.AccessController.doPrivileged(Native Method)
        Truncated. see log file for complete stacktrace
>

The workaround

For each data source I had to do the following to work around this problem:

  1. Clicked the Lock & Edit button.
  2. Had to note which targets the data source was using.
  3. Removed the targets from the data source, and clicked on the Save button.
  4. Clicked on the Activate Changes button.
  5. Clicked the Lock & Edit button.
  6. Updated the password for the data source, and clicked on the Save button.
  7. Clicked on the Activate Changes button.
  8. Clicked the Lock & Edit button.
  9. Added the targets that I noted in step 2 to the data source, before I clicked on the Save button.
  10. Clicked the Activate Changes button.

After all data sources had been updated with the new passwords, and the data sources had been re-targeted, I did a full domain restart. 

While I started the AdminServer up, I looked out for errors like these which could indicate I had forgotten to update some data sources:

<Jan 19, 2016 1:32:34 PM UTC> <Error> <Deployer> <BEA-149205> <Failed to initialize the application "<data source name>" due to error weblogic.application.ModuleException: weblogic.common.resourcepool.ResourceSystemException

Monday, January 11, 2016

How to find which Java thread on WebLogic that causes high CPU utilization on Linux

Scope

Sometimes your Linux server is having close to 100% CPU utilization. It is easy and quick to find which process is spending more CPU by running the top command. It takes a few more steps to establish which Java(TM) thread is using CPU, and what that thread is doing. This blog will explain the procedure for gather evidence to your developers that their code is too CPU intensive.

Scenarios

I have tried this procedure using the following versions of Oracle® WebLogic and Java(TM):
  • Oracle® WebLogic 12.1.3 with Oracle® Java(TM) SE 7 - jdk1.7.0_79
  • Oracle® WebLogic 10.3.6 with Oracle®Java(TM) SE 7 - jdk1.7.0_79
  • Oracle® WebLogic 10.3.6 with Oracle® Java(TM) SE 6 - jdk1.6.0_45
  • Oracle® WebLogic 10.3.6 with Oracle® JRockit(R) 6 - R28.2.7
These guidelines would also work on other servers using Oracle® Java(TM) SE.

Overview

The procedure for finding the most CPU intensive thread is basically the same for each combination of Oracle® WebLogic and Java(TM):
  • Find the ID of the process that has highest CPU utilization
  • Find the ID of the thread that has highest CPU utilization based on the process ID found above.
  • Take a thread dump of the process based on the process ID found above.
  • Search for the thread ID in the thread dump
  • Identify the code that causes issues


Find the ID of the process that has highest CPU utilization

Use the top command and look at the CPU% column to identify which PID has highest CPU utilization. In the case below, the PID with 7253 uses most CPU%.



Find the ID of the thread that has highest CPU utilization based on the process ID found above

Again we can use the top command to find out which threads are spending most CPU% with the PID as input. The command will be:
top -H -p <PID>



Take a thread dump of the process based on the process ID found above

Use the jstack <pid> command with Java HotSpot(TM) or the jrcmd <pid> print_threads command with Oracle® JRockit(R) to get a thread dump. For instance:
$JAVA_HOME/bin/jstack 7253 > /tmp/stack.txt



Search for the thread ID in the thread dump file

Some tools will write the thread IDs as decimal numbers and others will write it as hexadecimal numbers. In this blog post I used Java HotSpot(TM) 64-Bit Server VM (build 24.79-b02, mixed mode) which wrote the thread IDs as hexadecimal numbers. When testing Oracle® JRockit(R) however, my thread IDs were written with decimal numbers. 

From the list of thread IDs above, I converted the three thread IDs with highest CPU% to hex:

[oracle@localhost dom_12c_hotspot7]$ printf "%x\n" 7255
1c57
[oracle@localhost dom_12c_hotspot7]$ printf "%x\n" 7286
1c76
[oracle@localhost dom_12c_hotspot7]$ printf "%x\n" 7291
1c7b

I can now search for 1c57, 1c76 and 1c7b in the /tmp/stack.txt file I created.

Nothing exciting about 1c57 as it was only the "VM Thread":


The other thread ID 1c76 is coming from my custom code:


The third thread ID 1c7b is also coming from my custom code, and that thread is even STUCK.:



This was just an example on how to find threads with high CPU utilization. The code deployed was written poorly on purpose to cater for this article. Finding the performance issue on a real life application will probably prove to be more complex. In case there are multiple threads that fights over the CPU, then it is probably better to do live analyses using a tool like JVisualVM.

How to troubleshoot and fix "ORA-01882 timezone region not found" while creating WebLogic data source

Symptoms

While creating a data source in WebLogic you get the error "ORA-01882 timezone region not found" while saving the new configuration. 

Troubleshooting

This troubleshooting was performed on a Red Hat Linux 6.6 server running WebLogic 12.1.3

Finding the timezone used by the JVM

Even if the user account running WebLogic does not have a TZ environment variable set, the JVM will pickup a timezone as specified by the sysconfig clock on Linux. By running $JAVA_HOME/bin/jvisualvm you will be able to find out which timezone it is using by looking for the user.timezone property in System properties:




In my case this was originally set to Etc/UTC. 

Which timezones are supported by the Oracle database

Log on to the database to which you attempted to create a data source, and then run the following query:

SELECT * FROM V$TIMEZONE_NAMES ORDER BY 1;

In my case there was no such thing as TZNAME = Etc/UTC. But of course just UTC was a valid value. 

Force WebLogic to use UTC timezone

Edit $DOMAIN_HOME/bin/startWebLogic.sh and go to the bottom of the file where the commands to startup WebLogic reside. After each of the three ${MEM_ARGS} add -Dtimezone=UTC. After your change the section will look like this:



echo "starting weblogic with Java version:"

${JAVA_HOME}/bin/java ${JAVA_VM} -version


if [ "${WLS_REDIRECT_LOG}" = "" ] ; then

echo "Starting WLS with line:"

echo "${JAVA_HOME}/bin/java ${JAVA_VM} ${MEM_ARGS} -Duser.timezone=UTC -Dweblogic.Name=${SERVER_NAME} -Djava.security.policy=${WLS_POLICY_FILE} ${JAVA_OPTIONS} ${PROXY_SETTINGS} ${SERVER_CLASS}"

${JAVA_HOME}/bin/java ${JAVA_VM} ${MEM_ARGS} -Duser.timezone=UTC -Dweblogic.Name=${SERVER_NAME} -Djava.security.policy=${WLS_POLICY_FILE} ${JAVA_OPTIONS} ${PROXY_SETTINGS} ${SERVER_CLASS}

else

echo "Redirecting output from WLS window to ${WLS_REDIRECT_LOG}"

${JAVA_HOME}/bin/java ${JAVA_VM} ${MEM_ARGS} -Duser.timezone=UTC -Dweblogic.Name=${SERVER_NAME} -Djava.security.policy=${WLS_POLICY_FILE} ${JAVA_OPTIONS} ${PROXY_SETTINGS} ${SERVER_CLASS} >"${WLS_REDIRECT_LOG}" 2>&1
fi

Finally restart WebLogic.

Verify that the JVM is using the new timezone

The quick way to check it is of course "ps -ef | grep timezone" and make sure there is one hit per managed server plus the AdminServer. 



Of you can check with JVisualVM as explained above.