Of course we cannot always share details about our work with customers, but nevertheless it is nice to show our technical achievements and share some of our implemented solutions.
Atlassian recently (in August 2021) released the new Confluence LTS (Long Term Support) version, which is now 7.13.x. But during the upgrade (from Confluence 7.7), a couple of road bumpers needed to be cleared first.
This Confluence installation is quite large, with a database size of roughly 6GB:
mysql> SELECT table_schema AS "Database", SUM(data_length + index_length) / 1024 / 1024 AS "Size (MB)" FROM information_schema.TABLES WHERE table_schema = "confluence" GROUP BY table_schema;
+-------------+---------------+
| Database | Size (MB) |
+-------------+---------------+
| confluence | 6098.57812500 |
+-------------+---------------+
1 row in set (0.02 sec)
During the first upgrade attempt, the atlassian-confluence log stopped at the BODYCONTENT table:
2021-09-06 14:18:54,615 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] end TABLE_DATA: [AUDITRECORD]
2021-09-06 14:18:54,619 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] begin TABLE_DATA: [AUDIT_AFFECTED_OBJECT]
2021-09-06 14:18:54,623 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] end TABLE_DATA: [AUDIT_AFFECTED_OBJECT]
2021-09-06 14:18:54,627 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] begin TABLE_DATA: [AUDIT_CHANGED_VALUE]
2021-09-06 14:18:54,630 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] end TABLE_DATA: [AUDIT_CHANGED_VALUE]
2021-09-06 14:18:54,634 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] begin TABLE_DATA: [BANDANA]
2021-09-06 14:18:54,683 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] end TABLE_DATA: [BANDANA]
2021-09-06 14:18:54,686 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] begin TABLE_DATA: [BODYCONTENT]
Eventually the data to be processed by the upgrade seemed to overwhelm the assign Java heap memory, as seen in the catalina.out log:
Exception in thread "Navlink Plugin Executor:thread-2" java.lang.OutOfMemoryError: Java heap space
at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.addConditionWaiter(Unknown Source)
at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(Unknown Source)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Unknown Source)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Unknown Source)
at java.base/java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.base/java.lang.Thread.run(Unknown Source)
Exception in thread "pool-2-thread-5" java.lang.OutOfMemoryError: Java heap space
The Xmx was set to 4GB - but with that max heap size the upgrade ran into the OOM. After increasing the Xmx to 6GB (6144m) in /opt/atlassian/confluence/bin/setenv.sh and another Confluence start, the upgrade continued.
Following the atlassian-confluence log, the upgrade continued and looked good - at first. But the following error was caught:
2021-09-06 14:46:46,563 WARN [Catalina-utility-1] [confluence.impl.hibernate.ConfluenceHibernateTransactionManager] doRollback Performing rollback. Transactions:
->[null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT (Session #1389659368)
2021-09-06 14:46:46,593 ERROR [Catalina-utility-1] [atlassian.confluence.plugin.PluginFrameworkContextListener] launchUpgrades Upgrade failed, application will not start: Upgrade task com.atlassian.confluence.upgrade.upgradetask.DenormalisedSpacePermissionsUpgradeTask@426e5338 failed during the SCHEMA_UPGRADE phase due to: StatementCallback; uncategorized SQLException for SQL [DROP TRIGGER IF EXISTS denormalised_space_permission_trigger_on_update;]; SQL state [HY000]; error code [1419]; You do not have the SUPER privilege and binary logging is enabled (you *might* want to use the less safe log_bin_trust_function_creators variable); nested exception is java.sql.SQLException: You do not have the SUPER privilege and binary logging is enabled (you *might* want to use the less safe log_bin_trust_function_creators variable)
com.atlassian.confluence.upgrade.UpgradeException: Upgrade task com.atlassian.confluence.upgrade.upgradetask.DenormalisedSpacePermissionsUpgradeTask@426e5338 failed during the SCHEMA_UPGRADE phase due to: StatementCallback; uncategorized SQLException for SQL [DROP TRIGGER IF EXISTS denormalised_space_permission_trigger_on_update;]; SQL state [HY000]; error code [1419]; You do not have the SUPER privilege and binary logging is enabled (you *might* want to use the less safe log_bin_trust_function_creators variable); nested exception is java.sql.SQLException: You do not have the SUPER privilege and binary logging is enabled (you *might* want to use the less safe log_bin_trust_function_creators variable)
at com.atlassian.confluence.upgrade.AbstractUpgradeManager.executeUpgradeStep(AbstractUpgradeManager.java:262)
at com.atlassian.confluence.upgrade.AbstractUpgradeManager.runSchemaUpgradeTasks(AbstractUpgradeManager.java:218)
at com.atlassian.confluence.upgrade.AbstractUpgradeManager.upgrade(AbstractUpgradeManager.java:164)
at
[...]
2021-09-06 14:46:46,594 ERROR [Catalina-utility-1] [atlassian.confluence.plugin.PluginFrameworkContextListener] launchUpgrades 1 errors were encountered during upgrade:
2021-09-06 14:46:46,594 ERROR [Catalina-utility-1] [atlassian.confluence.plugin.PluginFrameworkContextListener] launchUpgrades 1: StatementCallback; uncategorized SQLException for SQL [DROP TRIGGER IF EXISTS denormalised_space_permission_trigger_on_update;]; SQL state [HY000]; error code [1419]; You do not have the SUPER privilege and binary logging is enabled (you *might* want to use the less safe log_bin_trust_function_creators variable); nested exception is java.sql.SQLException: You do not have the SUPER privilege and binary logging is enabled (you *might* want to use the less safe log_bin_trust_function_creators variable)
The Confluence database in question is part of a MySQL replication setup, hence binary logging is enabled. But when binary logging is enabled, stored procedures cannot be created or dropped (unless by the root user).
The error is kind of annoying because manually executing the SQL query reveals that there is no such procedure in the database:
mysql> use confluence;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A
Database changed
mysql> DROP TRIGGER IF EXISTS denormalised_space_permission_trigger_on_update;
Query OK, 0 rows affected, 1 warning (0.00 sec)
mysql> show warnings;
+-------+------+------------------------+
| Level | Code | Message |
+-------+------+------------------------+
| Note | 1360 | Trigger does not exist |
+-------+------+------------------------+
1 row in set (0.00 sec)
Yet Confluence upgrade really wants/needs to run this command and fails. Which then results in a big upgrade error on the graphical user interface:
As a workaround, the log_bin_trust_function_creators can be set to ON:
mysql> show global variables WHERE Variable_name LIKE 'log_bin%';
+---------------------------------+--------------------------------+
| Variable_name | Value |
+---------------------------------+--------------------------------+
| log_bin | ON |
| log_bin_basename | /var/log/mysql/mysql-bin |
| log_bin_index | /var/log/mysql/mysql-bin.index |
| log_bin_trust_function_creators | OFF |
| log_bin_use_v1_row_events | OFF |
+---------------------------------+--------------------------------+
5 rows in set (0.00 sec)
mysql> SET GLOBAL log_bin_trust_function_creators = "ON";
Query OK, 0 rows affected (0.00 sec)
mysql> show global variables WHERE Variable_name LIKE 'log_bin%';
+---------------------------------+--------------------------------+
| Variable_name | Value |
+---------------------------------+--------------------------------+
| log_bin | ON |
| log_bin_basename | /var/log/mysql/mysql-bin |
| log_bin_index | /var/log/mysql/mysql-bin.index |
| log_bin_trust_function_creators | ON |
| log_bin_use_v1_row_events | OFF |
+---------------------------------+--------------------------------+
5 rows in set (0.00 sec)
After another Confluence (re-)start, the upgrade procedure ran once again and this time continued until the end with success.
Almost similar issues can be seen during the upgrade procedure trying to upgrade Confluence to version 7.19. After the upgrade successfully completed, Confluence might be stuck during the start. The following log entries appear as the last one in the application log:
root@confluence:~# tail -f /var/atlassian/application-data/confluence/logs/atlassian-confluence.log
[...]
2023-11-13 16:31:12,149 WARN [AtlassianEvent::CustomizableThreadFactory-1] [core.persistence.hibernate.HibernateVersionHistoryDao] getLatestBuildNumber Unable to determine build number from database. If you are upgrading from a Confluence version prior to 7.14.0, this is expected: Unknown column 'FINALIZED' in 'where clause'
2023-11-13 16:31:14,653 INFO [Catalina-utility-1] [confluence.upgrade.impl.DefaultUpgradeManager] beforeUpgrade Generating pre-upgrade recovery file...
2023-11-13 16:31:14,695 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] begin Starting
2023-11-13 16:31:14,702 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] logTask Starting DATABASE_INFORMATION
2023-11-13 16:31:14,710 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] logTask Finishing DATABASE_INFORMATION
2023-11-13 16:31:14,710 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] logTask Starting TABLE_DEFINITION
2023-11-13 16:31:15,777 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] logTask Finishing TABLE_DEFINITION
2023-11-13 16:31:15,778 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] totalNumberOfTables Total number of tables: 230
2023-11-13 16:31:15,778 INFO [Catalina-utility-1] [confluence.upgrade.recovery.ConfluenceProgressMonitor] logTask Starting TABLES_DATA
Only after setting Confluence's Java Heap Memory to 6GB the task eventually continued (with 2GB or 4GB the application start was stuck here and led to a stale Java process).