Update from 7.3.0 patch level 730_20160916 to 7.3.2 hangs

While attempting an update from Rhythmyx 7.3.0 patch level 730_20160916 to Rhythmyx 7.3.2, the update process seems to hang for hours on end with the following displayed in terminal:

Expanding: doc.zip to: /tmp/191665.tmp…Done

Installing Rhythmyx…
------|------------------|------------------|------------------]

This is repeatable. Processes belonging to the user running the update appear to be sleeping:

rhythmyx 30856  3.4  8.2 1730648 500232 pts/9  Sl+  08:40   1:09 /tmp/install.dir.30856/Linux/resource/jre/bin/java -Xmx50331648 -Xms16777216 -Xmx1024m com.zerog.lax.LAX /tmp/install.dir.30856/temp.lax /tmp/env.properties.30856 “-i” “conso
le”
rhythmyx 31092  7.4  0.0  13900  2776 pts/9    S+   08:41   2:28 /bin/sh /tmp/ismp001/1197651.tmp

Disk space is available both in the /tmp and application directories, and the machine does nothing else but serve rhythmyx, with 4CPUs and 6GB RAM.

The longest run before manual interruption was 3.5 hours. Is this common? Is there some sort of an indication as to how long the update process could or should take?

Many thanks!

Predrag

I may have found the culprit myself:

ORA-00257: archiver error. Connect internal only, until freed.

I’ll report whether this could have been the issue once it is addressed.

Thank you Predrag - Please let us know if it worked. 

Have a great day
Brendan

Hi Brendan,

It might be useful to know for other folk using Oracle as their DB backend, that the ORA error message I listed above does, indeed, point to the DB server, and that they should have their DBA awake and in front of the screen when upgrading.

We are now further afield, waiting at:

INFO  [PSLogger] 03/20/17 11:33:33  Cleaning rxconfig/Server/server.properties
INFO  [PSLogger] 03/20/17 11:33:33  Cleaning rxconfig/Workflow/rxworkflow.properties
INFO  [PSLogger] 03/20/17 11:33:41  Copying : /home/rhythmyx/Rhythmyx/cacerts.6 to /home/rhythmyx/Rhythmyx/JRE/lib/security/cacerts.6

That is the latest log message. All four CPUs appear to be busy with the /tmp/ismp001/*.tmp (sone number, they are different each time you start the update process, it seems). I am assuming that something is still happening, and that this is not another deep freeze, since the CPU load does not drop.

This may be a problem on the Oracle side because the upgrade is doing allot of work on the tables.  The problem can occur if Oracle is running out of space for the redo logs.  Please see:

  http://damir-vadas.blogspot.com/2010/01/ora-00257-archiver-error-connect.html?m=1

Also if you tail the /tablefactory.log that is where the installer logs database updates during the installation.

The other two logs that will show activity are /rxconfig/installer/ant.log /rxconfig/installer/install.log

-n

It was Oracle initially, but that was fixed and now it has 185GB available on the partition where the redo logs go, which ought to be sufficient. Monitoring that space show no significant change.

The ant.log appears to be happy with the state of the world:
BUILD SUCCESSFUL
Total time: 2 minutes 43 seconds

tableFactory.log, last two entries show:
Creating schema plan for table: TAX_VALUE
Table exists, no changes
onCreateOnly=yes and table not created, skipping data plan

Creating schema plan for table: TAX_VISIBILITY
Table exists, no changes
onCreateOnly=yes and table not created, skipping data plan

No write activity on this file for more than one hour.

Finally, the install.log, again not written to in the last hour or so, with the last few lines:
INFO  [PSLogger] 03/20/17 14:19:02  Executing statement : create view RHYTHMYX.RXSITEITEMS AS select PD.PUBSTATUSID, PD.CONTENTID, PD.VARIANTID, PD.LOCATIONHASH, PD.PUBSTATUS, PD.PUBDATE, PD.PUBOP AS PUBOPERATION, PD.PUBLOCATION AS LOCATIO
N, PD.CONTENTURL, PD.VERSIONID, PD.REVISIONID, PD.ELAPSETIME, PD.REFERENCE_ID, PSI.SITE_ID AS SITEID, PSI.CONTEXT_ID AS CONTEXT from RHYTHMYX.PSX_PUBLICATION_SITE_ITEM PSI inner join RHYTHMYX.RXPUBDOCS PD on PSI.REFERENCE_ID = PD.REFERENCE
_ID
INFO  [PSLogger] 03/20/17 14:19:02  Succesfully executed statement.
INFO  [PSLogger] 03/20/17 14:19:41  #### Running RxFix ####
INFO  [PSLogger] 03/20/17 14:19:41  Fix: com.percussion.rxfix.dbfixes.PSFixNextNumberTable
INFO  [PSLogger] 03/20/17 14:19:41  Fix: com.percussion.rxfix.dbfixes.PSFixDanglingAssociations
INFO  [PSLogger] 03/20/17 14:19:41  #### Completed RxFix ####
INFO  [PSLogger] 03/20/17 14:19:44  Cleaning rxconfig/Server/server.properties
INFO  [PSLogger] 03/20/17 14:19:44  Cleaning rxconfig/Workflow/rxworkflow.properties
INFO  [PSLogger] 03/20/17 14:19:52  Copying : /home/rhythmyx/Rhythmyx/cacerts.7 to /home/rhythmyx/Rhythmyx/JRE/lib/security/cacerts.7

Note that the caccerts.n starts with cacerts.1 and ends with cacerts.7, and increases each time an update attempt is made. I’m note sure whether this is relevant at all.

At the same time, the two /tmp/ismp001/ /tmp/ismp002/ scripts show constant ~80-85% CPU usage.

There is an intermittent issue that has been reported with the install framework on some Linux installations where the installer hangs setting permissions as part of the cleanup stage of the installer.  Based on the logs the install Rhythmyx upgrade is complete.  I would kill -9 the installer process, clear your /tmp directory and resume with the post installation part of the upgrade.  

To verify permissions you could chown -R : /* where is the user identified in the /rx_user.id file.

-n

There was, indeed, a lingering process trying to chmod one of the sites’ _templates/soaspggenericlibrarytable.html.

Killing the installer routine here, then changing permissions, as well as running InstallDaemon.sh, gives the following with JBoss when attempting to start:

Caused by: java.sql.SQLException: Listener refused the connection with the following error:
ORA-12519, TNS:no appropriate service handler found
The Connection descriptor used by the client was:
SERVER:THAT:USEDTOWORKBEFORETHEUPGRADE

        at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:112)
        at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:261)
        at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:387)
        at oracle.jdbc.driver.PhysicalConnection.(PhysicalConnection.java:414)
at oracle.jdbc.driver.T4CConnection.(T4CConnection.java:165)
at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:35)
at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:801)
at org.jboss.resource.adapter.jdbc.local.LocalManagedConnectionFactory.createManagedConnection(LocalManagedConnectionFactory.java:172)
… 27 more

2017-03-20 08:38:00,170 ERROR [FTSIndexQueue] An unexpected exception occurred. The reason was: Could not open Hibernate Session for transaction; nested exception is org.hibernate.exception.GenericJDBCException: Cannot open connection. Ple
ase consult the log for further information.
2017-03-20 08:38:00,171 INFO [PSServerLogHandler] appid: 0 type: 1 time: Mon Mar 20 08:38:00 GMT 2017 msg: An internal error (end-condition) was encountered. An unexpected exception occurred:
An unexpected exception occurred. The reason was: java.lang.NullPointerException. Please consult the log for further information…
The call-stack was:
java.lang.NullPointerException
at com.percussion.server.PSRequest.getContextForRequest(Unknown Source)
at com.percussion.server.PSRequest.getContextForRequest(Unknown Source)
at com.percussion.server.PSRequest.getContextForRequest(Unknown Source)
at com.percussion.search.PSSearchIndexEventQueue$1.run(Unknown Source)


and the following with jetty:

Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name ‘sys_sessionFactory’ defined in ServletContext resource [/WEB-INF/config/spring/beans.xml]: Invocation of init method failed; nested exceptio
n is java.lang.RuntimeException: Failed to initialize the hibernate configuration: null
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1514)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:521)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:458)
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:293)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:223)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:290)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:191)
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:328)
… 50 more
Caused by: java.lang.RuntimeException: Failed to initialize the hibernate configuration: null
at com.percussion.services.datasource.PSSessionFactoryBean.afterPropertiesSet(Unknown Source)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1573)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1511)
… 57 more
Caused by: java.lang.NullPointerException
at com.percussion.services.datasource.impl.PSDatasourceManager.getConnectionDetail(Unknown Source)
at com.percussion.services.datasource.impl.PSDatasourceManager.getHibernateProperties(Unknown Source)
… 60 more
15:54:31,933 INFO [AbstractCXFServlet] Load the bus with application context
15:54:31,938 INFO [BusApplicationContext] Refreshing org.apache.cxf.bus.spring.BusApplicationContext@1ddc676: startup date [Mon Mar 20 15:54:31 GMT 2017]; parent: Root WebApplicationContext


As if the credentials have not been copied in migration… but the keystore files are there.

Can you confirm the version of Oracle that you are running?  

There are multiple versions of the Oracle drivers ojdb6.jar, ojdbc.jar, ojdbc7.jar and they must match the Oracle and Java version.  

Make sure that you only have ojdbc7.jar in /AppServer/server/rx/lib remove any older versions if present. 

While under JBOSS check the AppServer/server/rx/deploy/rx-ds.xml file make sure that the driver-class element is set to oracle.jdbc.driver.OracleDriver.

-n

It’s Oracle 11g 11.2.0.1.0. I suspect the ojdbc7.jar won’t work with that version. There is a driver at the bottom of this page which I tried:

http://www.oracle.com/technetwork/apps-tech/jdbc-112010-090769.html

Which also fails. JBoss won’t even fire up. Jetty throws this:

        at org.eclipse.jetty.xml.XmlConfiguration.main(XmlConfiguration.java:1435)
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name ‘sys_sessionFactory’ defined in ServletContext resource [/WEB-INF/config/spring/beans.xml]: Invocation of init method failed; nested exceptio
n is java.lang.RuntimeException: Failed to initialize the hibernate configuration: null
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1514)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:521)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:458)
        at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:293)
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:223)
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:290)
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:191)
        at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:328)
        … 50 more
Caused by: java.lang.RuntimeException: Failed to initialize the hibernate configuration: null
        at com.percussion.services.datasource.PSSessionFactoryBean.afterPropertiesSet(Unknown Source)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1573)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1511)
        … 57 more
Caused by: java.lang.NullPointerException
        at com.percussion.services.datasource.impl.PSDatasourceManager.getConnectionDetail(Unknown Source)
        at com.percussion.services.datasource.impl.PSDatasourceManager.getHibernateProperties(Unknown Source)
        … 60 more
09:55:04,955 INFO  [AbstractCXFServlet] Load the bus with application context
09:55:04,960 INFO  [BusApplicationContext] Refreshing org.apache.cxf.bus.spring.BusApplicationContext@14c6767: startup date [Tue Mar 21 09:55:04 GMT 2017]; parent: Root WebApplicationContext

You would want this one:

ojdbc6.jar (2,739,670 bytes) - (SHA1 Checksum: a483a046eee2f404d864a6ff5b09dc0e1be3fe6c)
Certified with JDK 8, JDK 7 and JDK 6 : It contains the JDBC driver classes except classes for NLS support in Oracle Object and Collection types.

I am going to pull this into a support ticket. 

-n

Much obliged for all your help so far.

I will try one more time with the file you point out first thing tomorrow morning.

P