Database upgrade from 4.1.10 to 5.1.1 fails

[pcharsle]

We are following the instructions at http://docs.alfresco.com/5.1/tasks/upgrade-process.html to upgrade from 4.1.10 to 5.1.1. We are using AWS RDS MySQL 5.6 with tomcat7 as supported by Alfresco. We successfully install and run Alfresco 5.1.1 with all our extensions. We then do the following:

1) Stop Alfresco
2) Copy across our production contentstore
3) Copy across our 4.1.10 database
4) Tailing the logs, we can see that the database is recognised and the first upgrade patches are successfully applied

However the upgrade stops and "hangs" at the patch activiti-upgrade-5-11.sql and eventually times out. See the snippet from catalina.out below
<!–break–>

Normalized schema dumped to file /tmp/tomcat7-tmp/Alfresco/Alfresco-schema-MySQLInnoDBDialect-pre-upgrade-alf_-498310534441415069.xml.
 2016-08-01 04:18:00,631  INFO  [domain.schema.SchemaBootstrap] [localhost-startStop-1] Normalized schema dumped to file /tmp/tomcat7-tmp/Alfresco/Alfresco-schema-MySQLInnoDBDialect-pre-upgrade-jbpm_-6566384843334377561.xml.
 2016-08-01 04:18:00,632  INFO  [domain.schema.SchemaBootstrap] [localhost-startStop-1] Normalized schema dumped to file /tmp/tomcat7-tmp/Alfresco/Alfresco-schema-MySQLInnoDBDialect-pre-upgrade-act_-6400341803565615802.xml.
 2016-08-01 04:18:00,696  INFO  [domain.schema.SchemaBootstrap] [localhost-startStop-1] Executing database script /tmp/tomcat7-tmp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-1125795265852298082.sql (Copied from classpath:alfresco/dbscripts/upgrade/4.2/org.hibernate.dialect.MySQLInnoDBDialect/remove-index-acl_id.sql).
 2016-08-01 04:18:00,755  INFO  [domain.schema.SchemaBootstrap] [localhost-startStop-1] Executing database script /tmp/tomcat7-tmp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-2914601116970840258.sql (Copied from classpath:alfresco/dbscripts/upgrade/4.2/org.hibernate.dialect.MySQLInnoDBDialect/restructure-idx_alf_nprop_s-MSSQL.sql).
 2016-08-01 04:18:00,794  INFO  [domain.schema.SchemaBootstrap] [localhost-startStop-1] Executing database script /tmp/tomcat7-tmp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-7084032070803741293.sql (Copied from classpath:alfresco/dbscripts/upgrade/4.2/org.hibernate.dialect.MySQLInnoDBDialect/migrate-locale-multilingual.sql).
 2016-08-01 04:18:00,928  INFO  [domain.schema.SchemaBootstrap] [localhost-startStop-1] Executing database script /tmp/tomcat7-tmp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-2945145454516771820.sql (Copied from classpath:alfresco/dbscripts/create/org.hibernate.dialect.MySQLInnoDBDialect/AlfrescoCreate-AuthorizationTables.sql).
 2016-08-01 04:18:00,999  INFO  [domain.schema.SchemaBootstrap] [localhost-startStop-1] Executing database script /tmp/tomcat7-tmp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-8014122370050000922.sql (Copied from classpath:alfresco/dbscripts/create/org.hibernate.dialect.MySQLInnoDBDialect/AlfrescoCreate-ContentUrlEncryptionTables.sql).
 2016-08-01 04:18:01,111  INFO  [domain.schema.SchemaBootstrap] [localhost-startStop-1] Executing database script /tmp/tomcat7-tmp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-6503919872556366086.sql (Copied from classpath:alfresco/dbscripts/upgrade/4.2/org.hibernate.dialect.MySQLInnoDBDialect/activiti-upgrade-5-10.sql).
 2016-08-01 04:18:06,358  INFO  [domain.schema.SchemaBootstrap] [localhost-startStop-1] Executing database script /tmp/tomcat7-tmp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-742574778828474973.sql (Copied from classpath:alfresco/dbscripts/upgrade/4.2/org.hibernate.dialect.MySQLInnoDBDialect/add-activti-index-historic-activity.sql).
 2016-08-01 04:18:06,383  INFO  [domain.schema.SchemaBootstrap] [localhost-startStop-1] Executing database script /tmp/tomcat7-tmp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-2297210573458188263.sql (Copied from classpath:alfresco/dbscripts/upgrade/4.2/org.hibernate.dialect.MySQLInnoDBDialect/activiti-upgrade-5-11.sql).
 2016-08-01 04:18:13,592  INFO  [domain.schema.SchemaBootstrap] [localhost-startStop-1] Executing database script /tmp/tomcat7-tmp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-6241599408556461012.sql (Copied from classpath:alfresco/dbscripts/upgrade/4.2/org.hibernate.dialect.MySQLInnoDBDialect/migrate-activiti-workflows.sql).
java.net.SocketTimeoutException: Read timed out
   at java.net.SocketInputStream.socketRead0(Native Method)
   at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
   at java.net.SocketInputStream.read(SocketInputStream.java:170)
   at java.net.SocketInputStream.read(SocketInputStream.java:141)
   at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
   at sun.security.ssl.InputRecord.read
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

We checked the script that is failing, /tmp/tomcat7-tmp/Alfresco/AlfrescoSchema-MySQLInnoDBDialect-Update-6241599408556461012.sql. While the upgrade was "hanging" we ran the following commands in our database to find out what was causing the problem:

show open tables;

/* snippet shows that there are 2 locks on tables act_hi_detail and act_hi_varinst */
| alfresco_test | act_hi_detail | 2 | 0 |
| alfresco_test | act_hi_varinst | 2 | 0 | 
‍‍‍‍‍

show engine innodb status;

—TRANSACTION 115281, ACTIVE 2451 sec
mysql tables in use 4, locked 1
MySQL thread id 18, OS thread handle 0x2acf7ab59700, query id 2906 10.0.30.159 alfresco_test Sending data
INSERT INTO ACT_HI_VARINST(
ID_,
PROC_INST_ID_,
EXECUTION_ID_,
TASK_ID_,
NAME_,
VAR_TYPE_,
REV_,
BYTEARRAY_ID_,
DOUBLE_,
LONG_,
TEXT_,
TEXT2_
)
SELECT
(@cnt := @cnt + 1),
PROC_INST_ID_,
EXECUTION_ID_,
TASK_ID_,
NAME_,
VAR_TYPE_,
REV_,
BYTEARRAY_ID_,
DOUBLE_,
LONG_,
TEXT_,
TEXT2_
FROM ACT_HI_DETAIL AHD
CROSS JOIN (SELECT @cnt := 134601 + 1) AS dummy
WHERE AHD.PROC_INST_ID_ not in (select PROC_INST_ID_ from ACT_HI_VARINST)
AND
(AHD.PROC_INST_ID_ , AHD.NAME_, AHD.REV_, AHD.time_) IN
(SELECT
Trx read view will not see trx with id >= 115282, sees < 115282
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

We have configured our AWS RDS MySQL database with all MySQL settings as recommended by Alfresco. Has anyone else encountered this problem which seems to be caused by the table insert being locked because it has a select from the same table in which it is trying to insert.

Note that after the application times out, we have rebooted our database and are successfully able to run the same insert on the MySQL command line.
Note that the previous patch creates the new table ACT_HI_VARINST

Any help or ideas would be very much appreciated.

[angelborroy]

According to this http://docs.alfresco.com/5.1/concepts/upgrade-path.html you need an intermediate migration to 5.0 and then to 5.1

[ianw]

I've have been testing an upgrade from 4.2 to 5.1 and migrate-activiti-workflows.sql patch has been taking many, many, many hours, but it does eventually complete. I do not, however suffer from a timeout exception. I suspect the slow patch may be due to the use of nested queries, which MySQL is known to have speed issues with. I am, however, far from being a MySQL DB expert.

I am using mariadb-java-client-1.1.9.jar instead of mysql-connector-java.jar which maybe different to your setup.

BTW, I read the direct upgrade path from 4.1.x to 5.1 as being supported.

[pcharsle]

This is a known issue which has been around for a while. See https://issues.alfresco.com/jira/browse/MNT-16716 . We are now doing the following to upgrade from 4.1.x to 5.1.1:

1) Follow Alfresco instructions and perform the upgrade process up to the point when the script migrate-activiti-workflows.sql hangs/takes a VERY long time
2) Reboot the database
3) Stop Alfresco
4) Drop the table alf_bootstrap_lock
5) Manually ran each sql command in the script migrate-activiti-workflows.sql (the problematic statement only takes a few seconds to run)
6) Start Alfresco
7) The rest of the upgrade then continues without a problem

[ianw]

Thank you for posting this back, however it did not work for me. Running the query manually took just as long.

The solution for me was to upgrade the database. I was using MariaDB 5.5 as supplied as standard with Centos 7, but, Alfresco requires a Mysql 5.6. I believe that MariaDB 10 is also supported. I upgraded to MariaDB 10.1 and the migrate-activiti-workflows.sql took about 3 seconds without any work-arounds being required.

[darkredd]

Hi, 

We were able to migrate from 4.2.2 to 5.1.f two months ago. We also had an issue initially, only to realize that we had not give the "alfresco" db user enough privileges. So give full access to the user that connects to the DB from Alfresco; it will enable the user to alter, update or drop tables as required by the upgrade scripts.