Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.1.9
-
None
-
CentOS 6.6
-
10.1.11
Description
Trying to upgrade MariaDB from 10.0.22 to 10.1.9 fails. Downgrading back to 10.0.22 makes mariaDB work again.
Here are the logs during upgrade:
Found /usr/local/directadmin/custombuild/mysql/MariaDB-10.1.9-centos6-x86_64-client.rpm
|
Found /usr/local/directadmin/custombuild/mysql/MariaDB-10.1.9-centos6-x86_64-devel.rpm
|
Found /usr/local/directadmin/custombuild/mysql/MariaDB-10.1.9-centos6-x86_64-server.rpm
|
Found /usr/local/directadmin/custombuild/mysql/MariaDB-10.1.9-centos6-x86_64-shared.rpm
|
Found /usr/local/directadmin/custombuild/mysql/MariaDB-10.1.9-centos6-x86_64-common.rpm
|
Found /usr/local/directadmin/custombuild/mysql/MariaDB-10.1.9-centos6-x86_64-compat.rpm
|
Installing libjemalloc...
|
Found /usr/local/directadmin/custombuild/mysql/jemalloc-3.6.0-1.el6.x86_64.rpm
|
Found /usr/local/directadmin/custombuild/mysql/jemalloc-devel-3.6.0-1.el6.x86_64.rpm
|
warning: /usr/local/directadmin/custombuild/mysql/jemalloc-3.6.0-1.el6.x86_64.rpm: Header V4 DSA/SHA1 Signature, key ID 1bb943db: NOKEY
|
Preparing... ########################################### [100%]
|
1:jemalloc ########################################### [ 50%]
|
2:jemalloc-devel ########################################### [100%]
|
Stopping mysqld ...
|
Shutting down MySQL..................................... SUCCESS!
|
Upgrading MariaDB 10.0.22 to 10.1.9
|
warning: /etc/my.cnf.d/server.cnf saved as /etc/my.cnf.d/server.cnf.rpmsave
|
warning: MariaDB-10.1.9-centos6-x86_64-client.rpm: Header V4 DSA/SHA1 Signature, key ID 1bb943db: NOKEY
|
Preparing... ########################################### [100%]
|
1:MariaDB-compat ########################################### [ 17%]
|
2:MariaDB-common ########################################### [ 33%]
|
3:MariaDB-client ########################################### [ 50%]
|
4:MariaDB-server ########################################### [ 67%]
|
5:MariaDB-devel ########################################### [ 83%]
|
6:MariaDB-shared ########################################### [100%]
|
Starting MySQL.... ERROR!
|
Giving mysqld a few seconds to start up...
|
Version check failed. Got the following error when calling the 'mysql' command line client
|
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/lib/mysql/mysql.sock' (2 "No such file or directory")
|
FATAL ERROR: Upgrade failed
|
/usr/bin/mysqlcheck: Got error: 2002: Can't connect to local MySQL server through socket '/var/lib/mysql/mysql.sock' (2 "No such file or directory") when trying to connect
|
cp: `/usr/lib/libmysqlclient.so' and `/usr/lib/mysql/libmysqlclient.so' are the same file
|
Restarting MySQL.
|
ERROR! MySQL server PID file could not be found!
|
Starting MySQL... ERROR!
|
ERROR! Failed to restart server.
|
and mysql error log:
151125 17:54:18 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
|
/usr/sbin/mysqld: /usr/local/lib/libz.so.1: no version information available (required by /usr/sbin/mysqld)
|
2015-11-25 17:54:18 140379608573984 [Note] /usr/sbin/mysqld (mysqld 10.1.9-MariaDB) starting as process 11140 ...
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: Using mutexes to ref count buffer pool pages
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: The InnoDB memory heap is disabled
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: Memory barrier is not used
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: Compressed tables use zlib 1.2.3
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: Using Linux native AIO
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: Using CPU crc32 instructions
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: Initializing buffer pool, size = 128.0M
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: Completed initialization of buffer pool
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: Highest supported file format is Barracuda.
|
2015-11-25 17:54:19 140379608573984 [Warning] InnoDB: Resizing redo log from 2*16384 to 2*3072 pages, LSN=307161985788
|
2015-11-25 17:54:19 140379608573984 [Warning] InnoDB: Starting to delete and rewrite log files.
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: Setting log file ./ib_logfile101 size to 48 MB
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: Setting log file ./ib_logfile1 size to 48 MB
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
|
2015-11-25 17:54:19 140379608573984 [Warning] InnoDB: New log files created, LSN=307161986060
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: 128 rollback segment(s) are active.
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: Waiting for purge to start
|
2015-11-25 17:54:19 140379608573984 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.26-74.0 started; log sequence number 307161985788
|
2015-11-25 17:54:20 140378833417984 [Note] InnoDB: Dumping buffer pool(s) not yet started
|
2015-11-25 17:54:20 140379608573984 [Note] Plugin 'FEEDBACK' is disabled.
|
2015-11-25 17:54:20 140379608573984 [Note] Recovering after a crash using tc.log
|
2015-11-25 17:54:20 140379608573984 [ERROR] Recovery failed! You must enable exactly 3 storage engines that support two-phase commit protocol
|
2015-11-25 17:54:20 140379608573984 [ERROR] Crash recovery failed. Either correct the problem (if it's, for example, out of memory error) and restart, or delete tc log and start mysqld with --tc-heuristic-recover={commit|rollback}
|
2015-11-25 17:54:20 140379608573984 [ERROR] Can't init tc log
|
2015-11-25 17:54:20 140379608573984 [ERROR] Aborting
|
Attachments
Issue Links
- is blocked by
-
-
- Closed
-
Activity
Thanks for your feedback!
Removed tc.log as it wasn't deleted after stopping mysqld
Tried upgrading, now without errors. Checked the error log again, this was the result:
2015-11-27 23:32:30 140145192560672 [Note] /usr/sbin/mysqld (mysqld 10.1.9-MariaDB) starting as process 13300 ...
|
2015-11-27 23:32:30 140145192560672 [Note] InnoDB: Using mutexes to ref count buffer pool pages
|
2015-11-27 23:32:30 140145192560672 [Note] InnoDB: The InnoDB memory heap is disabled
|
2015-11-27 23:32:30 140145192560672 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
2015-11-27 23:32:30 140145192560672 [Note] InnoDB: Memory barrier is not used
|
2015-11-27 23:32:30 140145192560672 [Note] InnoDB: Compressed tables use zlib 1.2.3
|
2015-11-27 23:32:30 140145192560672 [Note] InnoDB: Using Linux native AIO
|
2015-11-27 23:32:30 140145192560672 [Note] InnoDB: Using CPU crc32 instructions
|
2015-11-27 23:32:30 140145192560672 [Note] InnoDB: Initializing buffer pool, size = 128.0M
|
2015-11-27 23:32:30 140145192560672 [Note] InnoDB: Completed initialization of buffer pool
|
2015-11-27 23:32:30 140145192560672 [Note] InnoDB: Highest supported file format is Barracuda.
|
2015-11-27 23:32:30 140145192560672 [Warning] InnoDB: Resizing redo log from 2*16384 to 2*3072 pages, LSN=311502829507
|
2015-11-27 23:32:30 140145192560672 [Warning] InnoDB: Starting to delete and rewrite log files.
|
2015-11-27 23:32:30 140145192560672 [Note] InnoDB: Setting log file ./ib_logfile101 size to 48 MB
|
2015-11-27 23:32:31 140145192560672 [Note] InnoDB: Setting log file ./ib_logfile1 size to 48 MB
|
2015-11-27 23:32:31 140145192560672 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
|
2015-11-27 23:32:31 140145192560672 [Warning] InnoDB: New log files created, LSN=311502829580
|
2015-11-27 23:32:31 140145192560672 [Note] InnoDB: 128 rollback segment(s) are active.
|
2015-11-27 23:32:31 140145192560672 [Note] InnoDB: Waiting for purge to start
|
2015-11-27 23:32:31 140145192560672 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.26-74.0 started; log sequence number 311502829507
|
2015-11-27 23:32:31 140144422156032 [Note] InnoDB: Dumping buffer pool(s) not yet started
|
2015-11-27 23:32:31 140145192560672 [Note] Plugin 'FEEDBACK' is disabled.
|
2015-11-27 23:32:31 140145192560672 [Note] Server socket created on IP: '::'.
|
2015-11-27 23:32:31 7f761866a700 InnoDB: Error: Column last_update in table "mysql"."innodb_table_stats" is INT UNSIGNED NOT NULL but should be BINARY(4) NOT NULL (type mismatch).
|
2015-11-27 23:32:31 7f761866a700 InnoDB: Error: Fetch of persistent statistics requested for table "mysql"."gtid_slave_pos" but the required system tables mysql.innodb_table_stats and mysql.innodb_index_stats are not present or have unexpected structure. Using transient stats instead.
|
2015-11-27 23:32:31 140145192560672 [Note] /usr/sbin/mysqld: ready for connections.
|
Version: '10.1.9-MariaDB' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server
|
2015-11-27 23:32:33 7f761866a700 InnoDB: Error: Column last_update in table "mysql"."innodb_table_stats" is INT UNSIGNED NOT NULL but should be BINARY(4) NOT NULL (type mismatch).
|
2015-11-27 23:32:33 7f761866a700 InnoDB: Error: Fetch of persistent statistics requested for table "spacepage_joomla"."j17_session" but the required system tables mysql.innodb_table_stats and mysql.innodb_index_stats are not present or have unexpected structure. Using transient stats instead.
|
2015-11-27 23:32:33 7f761866a700 InnoDB: Error: Column last_update in table "mysql"."innodb_table_stats" is INT UNSIGNED NOT NULL but should be BINARY(4) NOT NULL (type mismatch).
|
2015-11-27 23:32:33 7f761866a700 InnoDB: Error: Fetch of persistent statistics requested for table "spacepage_joomla"."j17_extensions" but the required system tables mysql.innodb_table_stats and mysql.innodb_index_stats are not present or have unexpected structure. Using transient stats instead.
|
2015-11-27 23:32:33 7f761866a700 InnoDB: Error: Column last_update in table "mysql"."innodb_table_stats" is INT UNSIGNED NOT NULL but should be BINARY(4) NOT NULL (type mismatch).
|
2015-11-27 23:32:33 7f761866a700 InnoDB: Error: Fetch of persistent statistics requested for table "spacepage_joomla"."j17_usergroups" but the required system tables mysql.innodb_table_stats and mysql.innodb_index_stats are not present or have unexpected structure. Using transient stats instead.
|
2015-11-27 23:32:33 7f761866a700 InnoDB: Error: Column last_update in table "mysql"."innodb_table_stats" is INT UNSIGNED NOT NULL but should be BINARY(4) NOT NULL (type mismatch).
|
2015-11-27 23:32:33 7f761866a700 InnoDB: Error: Fetch of persistent statistics requested for table "spacepage_joomla"."j17_viewlevels" but the required system tables mysql.innodb_table_stats and mysql.innodb_index_stats are not present or have unexpected structure. Using transient stats instead.
|
2015-11-27 23:32:33 7f761866a700 InnoDB: Error: Column last_update in table "mysql"."innodb_table_stats" is INT UNSIGNED NOT NULL but should be BINARY(4) NOT NULL (type mismatch).
|
2015-11-27 23:32:33 7f761866a700 InnoDB: Error: Fetch of persistent statistics requested for table "spacepage_joomla"."j17_languages" but the required system tables mysql.innodb_table_stats and mysql.innodb_index_stats are not present or have unexpected structure. Using transient stats instead.
|
2015-11-27 23:32:33 7f761866a700 InnoDB: Error: Column last_update in table "mysql"."innodb_table_stats" is INT UNSIGNED NOT NULL but should be BINARY(4) NOT NULL (type mismatch).
|
2015-11-27 23:32:33 7f761866a700 InnoDB: Error: Fetch of persistent statistics requested for table "spacepage_joomla"."j17_menu" but the required system tables mysql.innodb_table_stats and mysql.innodb_index_stats are not present or have unexpected structure. Using transient stats instead.
|
2015-11-27 23:32:33 7f761866a700 InnoDB: Error: Column last_update in table "mysql"."innodb_table_stats" is INT UNSIGNED NOT NULL but should be BINARY(4) NOT NULL (type mismatch).
|
2015-11-27 23:32:33 7f761866a700 InnoDB: Error: Fetch of persistent statistics requested for table "spacepage_joomla"."j17_sh404sef_aliases" but the required system tables mysql.innodb_table_stats and mysql.innodb_index_stats are not present or have unexpected structure. Using transient stats instead.
|
2015-11-27 23:32:37 7f761866a700 InnoDB: Error: Column last_update in table "mysql"."innodb_table_stats" is INT UNSIGNED NOT NULL but should be BINARY(4) NOT NULL (type mismatch).
|
2015-11-27 23:32:37 140145192249088 [Note] /usr/sbin/mysqld: Normal shutdown
|
|
|
2015-11-27 23:32:37 140145192249088 [Note] Event Scheduler: Purging the queue. 0 events
|
2015-11-27 23:32:37 140144401176320 [Note] InnoDB: FTS optimize thread exiting.
|
2015-11-27 23:32:37 140145192249088 [Note] InnoDB: Starting shutdown...
|
2015-11-27 23:32:39 140145192249088 [Note] InnoDB: Shutdown completed; log sequence number 311505291238
|
2015-11-27 23:32:39 140145192249088 [Note] /usr/sbin/mysqld: Shutdown complete
|
|
|
151127 23:32:39 mysqld_safe mysqld from pid file /var/lib/mysql/server.aegvzw.be.pid ended
|
151127 23:32:39 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
|
/usr/sbin/mysqld: /usr/local/lib/libz.so.1: no version information available (required by /usr/sbin/mysqld)
|
2015-11-27 23:32:39 140391067760672 [Note] /usr/sbin/mysqld (mysqld 10.1.9-MariaDB) starting as process 13493 ...
|
2015-11-27 23:32:39 140391067760672 [Note] InnoDB: Using mutexes to ref count buffer pool pages
|
2015-11-27 23:32:39 140391067760672 [Note] InnoDB: The InnoDB memory heap is disabled
|
2015-11-27 23:32:39 140391067760672 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
2015-11-27 23:32:39 140391067760672 [Note] InnoDB: Memory barrier is not used
|
2015-11-27 23:32:39 140391067760672 [Note] InnoDB: Compressed tables use zlib 1.2.3
|
2015-11-27 23:32:39 140391067760672 [Note] InnoDB: Using Linux native AIO
|
2015-11-27 23:32:39 140391067760672 [Note] InnoDB: Using CPU crc32 instructions
|
2015-11-27 23:32:39 140391067760672 [Note] InnoDB: Initializing buffer pool, size = 128.0M
|
2015-11-27 23:32:40 140391067760672 [Note] InnoDB: Completed initialization of buffer pool
|
2015-11-27 23:32:40 140391067760672 [Note] InnoDB: Highest supported file format is Barracuda.
|
2015-11-27 23:32:40 140391067760672 [Note] InnoDB: 128 rollback segment(s) are active.
|
2015-11-27 23:32:40 140391067760672 [Note] InnoDB: Waiting for purge to start
|
2015-11-27 23:32:40 140391067760672 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.26-74.0 started; log sequence number 311505291238
|
2015-11-27 23:32:40 140391067760672 [Note] Plugin 'FEEDBACK' is disabled.
|
2015-11-27 23:32:40 140390296450816 [Note] InnoDB: Dumping buffer pool(s) not yet started
|
2015-11-27 23:32:40 140391067760672 [Note] Server socket created on IP: '::'.
|
2015-11-27 23:32:40 140391067760672 [Note] /usr/sbin/mysqld: ready for connections.
|
Version: '10.1.9-MariaDB' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server
|
Also include two screenshots pre upgrade een post upgrade of SHOW ENGINES
Thanks a bunch!
Thanks.
With this set of engines on 10.0, you should not have had a tc.log at all. My best guess that it was an old one, created at some point (maybe long time ago) when some other engines were enabled. After the engines got disabled, and only one XA-capable engine left, 10.0 didn't care about the stale tc.log, but when you upgraded to 10.1, you encountered the problem MDEV-9214, which basically means 10.1 always cares about tc.log, even when it shouldn't.
In general, whenever you hit the problem, if you are only using one XA-capable engine, it should be safe to remove tc.log as the error message suggests.
I will set this bug report as blocked by MDEV-9214 for now.
vancanneyt,
Did you try to remove tc.log as the server log suggests?
If you didn't, please try to shut down 10.0.22 server gracefully, and if the tc.log is still in the datadir after that, remove it before you run upgrade.
The general problem is described here:
MDEV-8794.It caused a problem with upgrade to 10.1.8, so some changes were made here:
MDEV-9039.Apparently, there is still a combination of engines/parameters that is affected, it is not particularly surprising.
If you can, please run SHOW ENGINES before upgrade, on 10.0.22, and then after upgrade, on 10.1.9, so that we could understand how your instance got affected.
Thanks.