[MDEV-22679] Upgrade form Percona XtraDB Cluster 5.7 fails Created: 2020-05-23  Updated: 2021-04-04  Resolved: 2021-04-04

Status: Closed
Project: MariaDB Server
Component/s: Platform Debian
Affects Version/s: 10.5
Fix Version/s: 10.5.9

Type: Bug Priority: Minor
Reporter: Otto Kekäläinen Assignee: Otto Kekäläinen
Resolution: Fixed Votes: 0
Labels: None

Attachments: PNG File Screenshot from 2021-04-04 09-41-37.png    
Issue Links:
Duplicate
duplicates MDEV-22678 Upgrade from MySQL Community Edition ... Closed
PartOf
is part of MDEV-22322 Percona Server -> Mariadb Upgrades Open

 Description   

I tested upgrading from Percona XtraDB Cluster 5.7 to MariaDB 10.5 head. It fails due to issues in restarting the server. I suspect something is conflicting in the config and that fixing MDEV-19933 (which as had a PR pending for a while) probably sorts this out as well.

Log https://salsa.debian.org/mariadb-team/mariadb-server/-/jobs/756114:

Setting up mariadb-server-10.5 (1:10.5.4+maria~sid) ...
 invoke-rc.d: could not determine current runlevel
 Stopping MariaDB database server: mysqld.
 invoke-rc.d: could not determine current runlevel
 Starting MariaDB database server: mysqld . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . failed!
 invoke-rc.d: initscript mariadb, action "start" failed.

Steps to reproduce:

percona-xtradb-5.7 to mariadb-10.5 upgrade:
  stage: upgrade extras
  dependencies:
    - build
  image: debian:buster
  artifacts:
    when: always
    name: "$CI_BUILD_NAME"
    paths:
      - ${WORKING_DIR}/debug
  script:
    - sed -i "s/101/0/g" -i /usr/sbin/policy-rc.d # Enable automatic restarts from maint scripts
    - cd ${WORKING_DIR} # Don't repeat this step, it's just cd ./debian/output
    - apt-get update
    - apt-get install --no-install-recommends --yes gpg gpg-agent dirmngr ca-certificates # Bare minimal (<4MB) for apt-key to work
    - apt-key adv --recv-keys --keyserver hkps://keyserver.ubuntu.com:443 9334A25F8507EFA5
    - echo 'deb https://repo.percona.com/apt/ buster main' > /etc/apt/sources.list.d/mysql.list
    - apt-get update
    - apt-get install -y percona-xtradb-cluster-57
    # Verify installation of MySQL
    - dpkg -l | grep -iE 'maria|mysql|galera'
    - service mysql status
    - mysql --skip-column-names -e "SELECT @@version, @@version_comment"
    - mysql -e "SELECT Host,User,plugin,authentication_string FROM user;" mysql
    - mysql -e "SELECT * FROM plugin;" mysql
    - echo 'SHOW DATABASES;' | mysql
    # Install MariaDB built in this commit
    - sed 's/buster/sid/g' -i /etc/apt/sources.list # Enable next Debian release
    - sed '/sid-updates/d' -i /etc/apt/sources.list # Remove repositories that don't exist for Sid
    - sed '/security/d' -i /etc/apt/sources.list # Remove repositories that don't exist for Sid
    - apt-get update; apt-get install -y apt # Uprade minimal stack first
    - apt-get install -o Dpkg::Options::=--force-confnew -y ./*.deb || true # Allow to proceed so debug artifacts get collected
    # Verify installation of MariaDB built in this commit
    - dpkg -l | grep -iE 'maria|mysql|galera'
    - mariadb --version # Client version
    - service mysql status
    - mkdir -p debug # Ensure dir exists before using it
    - echo 'SHOW DATABASES;' | mariadb # List databases before upgrade are still there
    - mariadb -e "create database test; use test; create table t(a int primary key) engine=innodb; insert into t values (1); select * from t; drop table t; drop database test;" # Test InnoDB works



 Comments   
Comment by Otto Kekäläinen [ 2020-06-27 ]

This issue should be fixed and tested in parallel with MySQL Community 5.7 upgrade issue https://jira.mariadb.org/browse/MDEV-22678

Comment by Otto Kekäläinen [ 2020-08-03 ]

Can faust help here and figure out what are the manual steps needed to be able to upgrade from Percona XtraDB Cluster 5.7 to MariaDB 10.5 so that we can then plan how to automate it?

Comment by Faustin Lammler [ 2020-09-03 ]

otto, I have also a problem when upgrading from xtradb 5.7 to mariadb 10.5, see bellow (unable to start mariadb).

Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [ERROR] InnoDB: Unable to lock ./ibdata1 error: 11
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [Note] InnoDB: Check that you do not already have another mysqld process using the same InnoDB data or log files.
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [Note] InnoDB: Unable to open the first data file
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [ERROR] InnoDB: Operating system error number 11 in a file operation.
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [ERROR] InnoDB: Error number 11 means 'Resource temporarily unavailable'
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [ERROR] InnoDB: Cannot open datafile './ibdata1'
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [ERROR] InnoDB: Could not open or create the system tablespace. If you tried to add new data files to the system tablespace, and it failed here, you should now edit innodb_data_file_path in my.cnf back to what it was, and remove the new ibdata files InnoDB created in this failed attempt. InnoDB only wrote those files full of zeros, but did not yet use them in any way. But be careful: do not remove old data files which contain your precious data!
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [ERROR] InnoDB: Plugin initialization aborted with error Cannot open a file
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [Note] InnoDB: Starting shutdown...
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [ERROR] Plugin 'InnoDB' init function returned error.
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [Note] Plugin 'FEEDBACK' is disabled.
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [ERROR] Could not open mysql.plugin table: "Unknown storage engine 'InnoDB'". Some plugins may be not loaded
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [ERROR] Unknown/unsupported storage engine: InnoDB
Sep  3 10:52:39 debian10 mariadbd[8897]: 2020-09-03 10:52:39 0 [ERROR] Aborting

Then, if I try to start mariadb (systemctl start mariadb):

Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] /usr/sbin/mariadbd (mysqld 10.5.5-MariaDB-1:10.5.5+maria~buster) starting as process 9009 ...
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Warning] Could not increase number of max_open_files to more than 16384 (request: 32186)
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Using Linux native AIO
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Uses event mutexes
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Number of pools: 1
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Using SSE4.2 crc32 instructions
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] mariadbd: O_TMPFILE is not supported on /tmp (disabling future attempts)
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Completed initialization of buffer pool
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Upgrading redo log: 100663296 bytes; LSN=2636859
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Starting to delete and rewrite log file.
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Setting log file ./ib_logfile101 size to 100663296 bytes
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: New log file created, LSN=2636859
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: 128 rollback segments are active.
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Creating shared tablespace for temporary tables
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: 10.5.5 started; log sequence number 2635910; transaction id 1283
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] Plugin 'FEEDBACK' is disabled.
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [ERROR] mariadbd: Can't open shared library '/usr/lib/mysql/plugin/auth_socket.so' (errno: 2, cannot open shared object file: No such file or directory)
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] Server socket created on IP: '127.0.0.1'.
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] InnoDB: Buffer pool(s) load completed at 200903 16:15:52
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [ERROR] Missing system table mysql.roles_mapping; please run mysql_upgrade to create it
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [ERROR] Incorrect definition of table mysql.event: expected column 'sql_mode' at position 14 to have type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','IGNORE_BAD_TABLE_OPTIONS','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SUBTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANSI','NO_AUTO_VALUE_ON_ZERO','NO_BACKSLASH_ESCAPES','STRICT_TRANS_TABLES','STRICT_ALL_TABLES','NO_ZERO_IN_DATE','NO_ZERO_DATE','INVALID_DATES','ERROR_FOR_DIVISION_BY_ZERO','TRADITIONAL','NO_AUTO_CREATE_USER','HIGH_NOT_PRECEDENCE','NO_ENGINE_SUBSTITUTION','PAD_CHAR_TO_FULL_LENGTH','EMPTY_STRING_IS_NULL','SIMULTANEOUS_ASSIGNMENT'), found type set('REAL_AS_FLOAT','PIPES_AS_CONCAT','ANSI_QUOTES','IGNORE_SPACE','NOT_USED','ONLY_FULL_GROUP_BY','NO_UNSIGNED_SUBTRACTION','NO_DIR_IN_CREATE','POSTGRESQL','ORACLE','MSSQL','DB2','MAXDB','NO_KEY_OPTIONS','NO_TABLE_OPTIONS','NO_FIELD_OPTIONS','MYSQL323','MYSQL40','ANSI','NO_AUTO_VALUE_ON_ZERO','NO_B
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [ERROR] mariadbd: Event Scheduler: An error occurred when initializing system tables. Disabling the Event Scheduler.
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 1 [Warning] Failed to load slave replication state from table mysql.gtid_slave_pos: 1146: Table 'mysql.gtid_slave_pos' doesn't exist
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] Reading of all Master_info entries succeeded
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] Added new Master_info '' to hash table
Sep  3 16:15:52 debian10 mariadbd[9009]: 2020-09-03 16:15:52 0 [Note] /usr/sbin/mariadbd: ready for connections.
Sep  3 16:15:52 debian10 mariadbd[9009]: Version: '10.5.5-MariaDB-1:10.5.5+maria~buster'  socket: '/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
Sep  3 16:15:52 debian10 systemd[1]: Started MariaDB 10.5.5 database server.
Sep  3 16:15:52 debian10 /etc/mysql/debian-start[9030]: Upgrading MySQL tables if necessary.
Sep  3 16:15:52 debian10 /etc/mysql/debian-start[9033]: Looking for 'mysql' as: /usr/bin/mysql
Sep  3 16:15:52 debian10 /etc/mysql/debian-start[9033]: Looking for 'mysqlcheck' as: /usr/bin/mysqlcheck
Sep  3 16:15:52 debian10 /etc/mysql/debian-start[9033]: Version check failed. Got the following error when calling the 'mysql' command line client
Sep  3 16:15:52 debian10 /etc/mysql/debian-start[9033]: ERROR 1524 (HY000): Plugin 'auth_socket' is not loaded
Sep  3 16:15:52 debian10 /etc/mysql/debian-start[9033]: FATAL ERROR: Upgrade failed
Sep  3 16:15:52 debian10 /etc/mysql/debian-start[9043]: Checking for insecure root accounts.
Sep  3 16:15:52 debian10 debian-start[9028]: ERROR 1524 (HY000): Plugin 'auth_socket' is not loaded

Comment by Otto Kekäläinen [ 2020-09-03 ]

Thanks!

This is also a auth_socket issue and so far a mystery why the normal
system_tables_fix.sql does not run or does not apply.

Comment by Otto Kekäläinen [ 2020-09-17 ]

The Percona upgrade path seems to fail due to the same root reason as MDEV-22678. Fixing MDEV-22678 would also fix this issue.

Comment by Otto Kekäläinen [ 2020-09-22 ]

Re-opening. Let's keep this open until "Upgrade form Percona XtraDB Cluster 5.7" works. Part of https://jira.mariadb.org/browse/MDEV-22315 tracking all upgrades that they are tested and confirmed to work.

Comment by Otto Kekäläinen [ 2020-10-01 ]

While MDEV-22678 was now fixed, Percona.com upgrades still fail for the same code/commit:

MySQL.com works: https://salsa.debian.org/mariadb-team/mariadb-10.5/-/jobs/1040660
Percona.com fails: https://salsa.debian.org/mariadb-team/mariadb-10.5/-/jobs/1040661

I will need to debug this further:

dpkg: error processing package mariadb-server-10.5 (--configure):
1054 installed mariadb-server-10.5 package post-installation script subprocess returned error exit status 7

Comment by Otto Kekäläinen [ 2020-10-02 ]

Failure with `export DEBIAN_SCRIPT_DEBUG=1` active:

+ '[' -f /var/lib/mysql/auto.cnf ']'
+ '[' -f /var/lib/mysql/mysql/user.MYD ']'
+ '[' '!' lsof -nt /var/lib/mysql/mysql/user.MYD ']'
+ '[' '!' -f /var/lib/mysql/undo_001 ']'
+ echo 'UPDATE mysql.user SET plugin='\''unix_socket'\'' WHERE plugin='\''auth_socket'\'';'
+ /usr/sbin/mariadbd --skip-innodb --key_buffer_size=0 --default-storage-engine=MyISAM --bootstrap
dpkg: error processing package mariadb-server-10.5 (--configure):
 installed mariadb-server-10.5 package post-installation script subprocess returned error exit status 7
dpkg: dependency problems prevent configuration of mariadb-server:
 mariadb-server depends on mariadb-server-10.5 (>= 1:10.5.5-2+salsaci); however:
  Package mariadb-server-10.5 is not configured yet.
...
 
 
# tail /var/log/mysqld.log 
2020-10-02  8:00:22 0 [Warning] No argument was provided to --log-bin and neither --log-basename or --log-bin-index where used;  This may cause repliction to break when this server acts as a master and has its hostname changed! Please use '--log-basename=d925739d9e4b' or '--log-bin=mysqld-bin' to avoid this problem.
2020-10-02  8:00:22 0 [Note] Plugin 'InnoDB' is disabled.
2020-10-02  8:00:22 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-10-02  8:00:22 0 [ERROR] /usr/sbin/mariadbd: unknown variable 'pxc_strict_mode=ENFORCING'
2020-10-02  8:00:22 0 [ERROR] Aborting
 
 
/etc/mysql# grep -rF pxc_strict_mode *
percona-xtradb-cluster.conf.d/wsrep.cnf:#pxc_strict_mode allowed values: DISABLED,PERMISSIVE,ENFORCING,MASTER
percona-xtradb-cluster.conf.d/wsrep.cnf:pxc_strict_mode=ENFORCING
 
 
# ls -la /etc/alternatives/my.cnf
lrwxrwxrwx 1 root root 37 Oct  2 07:57 /etc/alternatives/my.cnf -> /etc/mysql/percona-xtradb-cluster.cnf
 
 
# cat /etc/mysql/percona-xtradb-cluster.cnf
#
# The Percona XtraDB Cluster 5.7 configuration file.
#
#
# * IMPORTANT: Additional settings that can override those from this file!
#   The files must end with '.cnf', otherwise they'll be ignored.
#   Please make any edits and changes to the appropriate sectional files
#   included below.
#
!includedir /etc/mysql/conf.d/
!includedir /etc/mysql/percona-xtradb-cluster.conf.d/

The root cause here is that the command `update-alternatives --install /etc/mysql/my.cnf my.cnf /etc/mysql/mariadb.cnf 200` does not register the new my.cnf as the priority number is too low. I'll figure out a way to force it now.

Comment by Otto Kekäläinen [ 2021-04-04 ]

I fixed this in a3448b2395a4f7aff62f8bab70797a6f928d626f.

Ever since the Salsa-CI tests have ensured that Percona upgrades continue to work and don't regress:

Generated at Thu Feb 08 09:16:37 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.