[MDEV-22678] Upgrade from MySQL Community Edition fails with "Plugin 'auth_socket' is not loaded" Created: 2020-05-23  Updated: 2020-12-08  Resolved: 2020-09-30

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

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

Issue Links:
Duplicate
is duplicated by MDEV-22679 Upgrade form Percona XtraDB Cluster 5... Closed
PartOf
is part of MDEV-22315 MySQL -> MariaDB upgrades Open

 Description   

Tested upgrading from MySQL Community Edition 5.7 to latest MariaDB 10.5 head. Otherwise it went well, but after the upgrade the server fails to accept connections from root as the auth_socket -> unix_socket that is supposed to be run by mysql_upgrade has not happened (fixed https://github.com/mariadb/server/commit/c1bdf62452139e9310d3234266802748ba4c74b8, part of https://jira.mariadb.org/browse/MDEV-11170).

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

$ service mysql status
1117 /usr/bin/mysqladmin: connect to server at 'localhost' failed
1118 error: 'Plugin 'auth_socket' is not loaded'

Upgrade from MySQL 5.7 in Debian works just fine and the auth_socket rename runs correctly: https://salsa.debian.org/mariadb-team/mariadb-server/-/jobs/756107



 Comments   
Comment by Otto Kekäläinen [ 2020-05-23 ]

Error log shows that the upgrade has not run properly:

2020-05-22 21:25:37 0 [Note] InnoDB: 10.5.4 started; log sequence number 2635084; transaction id 2307
2020-05-22 21:25:37 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2020-05-22 21:25:37 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-05-22 21:25:37 0 [Warning] mysqld: GSSAPI plugin : default principal 'mariadb/0109ee8b8a2c@' not found in keytab
2020-05-22 21:25:37 0 [ERROR] mysqld: Server GSSAPI error (major 851968, minor 2529639093) : gss_acquire_cred failed -Unspecified GSS failure.  Minor code may provide more information. Keytab FILE:/etc/krb5.keytab is nonexistent or empty. 
2020-05-22 21:25:37 0 [ERROR] Plugin 'gssapi' init function returned error.
2020-05-22 21:25:37 0 [ERROR] mysqld: Can't open shared library '/usr/lib/mysql/plugin/auth_socket.so' (errno: 2, cannot open shared object file: No such file or directory)
2020-05-22 21:25:37 0 [Note] Server socket created on IP: '::'.
2020-05-22 21:25:37 0 [ERROR] Missing system table mysql.roles_mapping; please run mysql_upgrade to create it
2020-05-22 21:25:37 0 [Note] InnoDB: Buffer pool(s) load completed at 200522 21:25:37
2020-05-22 21:25:37 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','N...
2020-05-22 21:25:37 0 [ERROR] mysqld: Event Scheduler: An error occurred when initializing system tables. Disabling the Event Scheduler.
2020-05-22 21:25:37 1 [Warning] Failed to load slave replication state from table mysql.gtid_slave_pos: 1146: Table 'mysql.gtid_slave_pos' doesn't exist
2020-05-22 21:25:37 0 [Note] Reading of all Master_info entries succeeded
2020-05-22 21:25:37 0 [Note] Added new Master_info '' to hash table
2020-05-22 21:25:37 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.5.4-MariaDB-1:10.5.4+maria~sid'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution

However, one cannot simply run `mysql_upgrade` since it requires a server to be running and access to it, which is blocked by the `'Plugin 'auth_socket' is not loaded'` error.. I did not manually test restarting server with `--skip-grant-tables`, but asking users to do it manually isn't the correct solution either.

Comment by Otto Kekäläinen [ 2020-05-28 ]

I can probably fix this myself if you give some pointers on how to debug from now on.

Comment by Sergei Golubchik [ 2020-05-29 ]

I think for a fix you can try --bootstrap mode, something like (simplified)

echo "UPDATE mysql.user SET plugin='unix_socket' WHERE plugin='auth_socket';"|mysqld --bootstrap

The actual change would probably use not the above simplified command, but already existing MYSQL_BOOTSTRAP invocation in the mariadb-server postinst script.

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

TODO: Test if this is needed and if MySQL 8.0 has by default another alter method: https://github.com/MariaDB/server/pull/1458

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 MySQL Community Edition 5.7 to MariaDB 10.5 so that we can then plan how to automate it?

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

OK, started looking at this again. The tip you gave serg for the SQL part is identical to what we have been doing since https://github.com/MariaDB/server/commit/c1bdf62452139e9310d3234266802748ba4c74b8 in order to get MySQL 5.7 upgrades working in Debian.

Piping it to `mysqld --bootstrap` (or `mariadbd` now in 10.5) does not help. Server prints out this and stays stuck there:

# echo "UPDATE mysql.user SET plugin='unix_socket' WHERE plugin='auth_socket';"|mariadbd --bootstrap
2020-08-30 18:42:04 0 [Note] mariadbd (mysqld 10.5.5-MariaDB-1~exp1) starting as process 7716 ...
2020-08-30 18:42:04 0 [Warning] Plugin 'OQGRAPH' is of maturity level gamma while the server is stable
2020-08-30 18:42:04 0 [Warning] Plugin 'SPIDER' is of maturity level gamma while the server is stable
2020-08-30 18:42:04 0 [Note] InnoDB: Using Linux native AIO
2020-08-30 18:42:04 0 [Note] InnoDB: Uses event mutexes
2020-08-30 18:42:04 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2020-08-30 18:42:04 0 [Note] InnoDB: Number of pools: 1
2020-08-30 18:42:04 0 [Note] InnoDB: Using SSE4.2 crc32 instructions
2020-08-30 18:42:04 0 [Note] mariadbd: O_TMPFILE is not supported on /tmp (disabling future attempts)
2020-08-30 18:42:04 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
2020-08-30 18:42:04 0 [Note] InnoDB: Completed initialization of buffer pool
2020-08-30 18:42:04 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-08-30 18:42:04 0 [Note] InnoDB: 128 rollback segments are active.
2020-08-30 18:42:04 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-08-30 18:42:04 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-08-30 18:42:04 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-08-30 18:42:04 0 [Note] InnoDB: 10.5.5 started; log sequence number 2724672; transaction id 2307
2020-08-30 18:42:04 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2020-08-30 18:42:04 0 [Note] RocksDB: 2 column families found
2020-08-30 18:42:04 0 [Note] RocksDB: Column Families at start:
2020-08-30 18:42:04 0 [Note]   cf=default
2020-08-30 18:42:04 0 [Note]     write_buffer_size=67108864
2020-08-30 18:42:04 0 [Note]     target_file_size_base=67108864
2020-08-30 18:42:04 0 [Note]   cf=__system__
2020-08-30 18:42:04 0 [Note]     write_buffer_size=67108864
2020-08-30 18:42:04 0 [Note]     target_file_size_base=67108864
2020-08-30 18:42:04 0 [Note] InnoDB: Buffer pool(s) load completed at 200830 18:42:04
2020-08-30 18:42:05 0 [Note] RocksDB: Table_store: loaded DDL data for 0 tables
2020-08-30 18:42:05 0 [Note] RocksDB: global statistics using get_sched_indexer_t indexer
2020-08-30 18:42:05 0 [Note] MyRocks storage engine plugin has been successfully initialized.
2020-08-30 18:42:05 0 [Note] CONNECT: Version 1.07.0001 November 12, 2019
2020-08-30 18:42:05 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-08-30 18:42:05 0 [Warning] mariadbd: GSSAPI plugin : default principal 'mariadb/285309741d63@' not found in keytab
2020-08-30 18:42:05 0 [ERROR] mariadbd: Server GSSAPI error (major 851968, minor 2529639093) : gss_acquire_cred failed -Unspecified GSS failure.  Minor code may provide more information. Keytab FILE:/etc/krb5.keytab is nonexistent or empty. 
2020-08-30 18:42:05 0 [ERROR] Plugin 'gssapi' init function returned error.
2020-08-30 18:42:05 0 [Note] Recovering after a crash using tc.log
2020-08-30 18:42:05 0 [Note] Starting crash recovery...
2020-08-30 18:42:05 0 [Note] Crash recovery finished.

When you think about this, the problem is probably deeper since the `mysql_system_tables_fix.sh` is always run during initial start and the plugin rename did not have an effect on that run, and it does not have either when run manually, so most likely the root cause is something deeper.

Something is quite different for MySQL 5.7 when installed from `https://repo.mysql.com/` than when installed from Debian/Ubuntu repositories.

Does cvicentiu have suggestions what to look for?

Comment by Daniel Black [ 2020-09-03 ]

5.7 testing

 $ mkdir /tmp/mdata; /usr/local/mysql-5.7.31-linux-glibc2.12-x86_64/bin/mysqld --no-defaults --basedir=/usr/local/mysql-5.7.31-linux-glibc2.12-x86_64 --datadir=/tmp/mdata --initialize
 
# take note of password
 
$ /usr/local/mysql-5.7.31-linux-glibc2.12-x86_64/bin/mysqld --no-defaults --basedir=/usr/local/mysql-5.7.31-linux-glibc2.12-x86_64 --datadir=/tmp/mdata --skip-networking --socket=/tmp/mysql.sock --verbose
 
$ /usr/local/mysql-5.7.31-linux-glibc2.12-x86_64/bin/mysql -u root  -p'u3iSumu(/t;9' -S /tmp/mysql.sock
 
mysql>  ALTER USER  root@localhost identified by 'bob';
Query OK, 0 rows affected (0.00 sec)
 
mysql> install plugin auth_socket soname 'auth_socket.so';
Query OK, 0 rows affected (0.00 sec)
 
mysql>  create user dan@localhost identified with auth_socket;
Query OK, 0 rows affected (0.00 sec)
 
mysql> grant all on *.* to  dan@localhost with grant option;
Query OK, 0 rows affected (0.00 sec)
 
mysql> show plugins;
.... didn't list the gssapi plugin.

gss plugin eror - was unclear if this was from the previous mysql install

Looking at /usr/local/mysql-5.7.31-linux-glibc2.12-x86_64/lib/plugin/ the only other auth plugin was ldap.

attempt migration

$   cp -a /tmp/mdata /tmp/migratefrommdata
 
$ sql/mysqld --no-defaults --skip-networking --datadir=/tmp/migratefrommdata --socket /tmp/mars.sock --lc-messages-dir=${PWD}/sql/share --verbose
2020-09-03 11:29:47 0 [Note] sql/mysqld (mysqld 10.5.6-MariaDB) starting as process 1886140 ...
2020-09-03 11:29:47 0 [Note] InnoDB: Using Linux native AIO
2020-09-03 11:29:47 0 [Note] InnoDB: Uses event mutexes
2020-09-03 11:29:47 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2020-09-03 11:29:47 0 [Note] InnoDB: Number of pools: 1
2020-09-03 11:29:47 0 [Note] InnoDB: Using SSE4.2 crc32 instructions
2020-09-03 11:29:47 0 [Note] mysqld: O_TMPFILE is not supported on /tmp (disabling future attempts)
2020-09-03 11:29:47 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
2020-09-03 11:29:47 0 [Note] InnoDB: Completed initialization of buffer pool
2020-09-03 11:29:47 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-09-03 11:29:47 0 [Note] InnoDB: Upgrading redo log: 100663296 bytes; LSN=2720120
2020-09-03 11:29:47 0 [Note] InnoDB: Starting to delete and rewrite log file.
2020-09-03 11:29:47 0 [Note] InnoDB: Setting log file ./ib_logfile101 size to 100663296 bytes
2020-09-03 11:29:47 0 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2020-09-03 11:29:47 0 [Note] InnoDB: New log file created, LSN=2720120
2020-09-03 11:29:47 0 [Note] InnoDB: 128 rollback segments are active.
2020-09-03 11:29:47 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-09-03 11:29:47 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-09-03 11:29:47 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-09-03 11:29:47 0 [Note] InnoDB: 10.5.6 started; log sequence number 2720108; transaction id 1286
2020-09-03 11:29:47 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-09-03 11:29:47 0 [Note] InnoDB: Loading buffer pool(s) from /tmp/migratefrommdata/ib_buffer_pool
2020-09-03 11:29:47 0 [ERROR] mysqld: Can't open shared library '/usr/local/mysql/lib/plugin/auth_socket.so' (errno: 2, cannot open shared object file: No such file or directory)
2020-09-03 11:29:47 0 [Note] InnoDB: Buffer pool(s) load completed at 200903 11:29:47
2020-09-03 11:29:47 0 [ERROR] Missing system table mysql.roles_mapping; please run mysql_upgrade to create it
2020-09-03 11:29:47 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
2020-09-03 11:29:47 0 [ERROR] mysqld: Event Scheduler: An error occurred when initializing system tables. Disabling the Event Scheduler.
2020-09-03 11:29:47 1 [Warning] Failed to load slave replication state from table mysql.gtid_slave_pos: 1146: Table 'mysql.gtid_slave_pos' doesn't exist
2020-09-03 11:29:47 0 [Note] Reading of all Master_info entries succeeded
2020-09-03 11:29:47 0 [Note] Added new Master_info '' to hash table
2020-09-03 11:29:47 0 [Note] sql/mysqld: ready for connections.
Version: '10.5.6-MariaDB'  socket: '/tmp/mars.sock'  port: 0  MariaDB Server
 
$ client/mysql -S /tmp/mars.sock 
ERROR 1524 (HY000): Plugin 'auth_socket' is not loaded
 
~/repos/build-mariadb-server-10.5 
$ client/mysql -S /tmp/mars.sock -u root
ERROR 1045 (28000): Access denied for user 'root'@'localhost' (using password: NO)
 
~/repos/build-mariadb-server-10.5 
$ client/mysql -S /tmp/mars.sock -u root -pbob
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 5
Server version: 10.5.6-MariaDB MariaDB Server
 
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
 
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
 
MariaDB [(none)]> show create user dan@localhost;
+----------------------------------------------------------+
| CREATE USER for dan@localhost                            |
+----------------------------------------------------------+
| CREATE USER `dan`@`localhost` IDENTIFIED VIA auth_socket |
+----------------------------------------------------------+
1 row in set (0.000 sec)
$ client/mysql_upgrade -u root -pbob  -S /tmp/mars.sock 
MariaDB upgrade detected
Phase 1/7: Checking and upgrading mysql database
Processing databases
mysql
mysql.columns_priv                                 OK
mysql.db                                           OK
mysql.engine_cost                                  OK
mysql.event                                        OK
mysql.func                                         OK
mysql.gtid_executed                                OK
mysql.help_category                                OK
mysql.help_keyword                                 OK
mysql.help_relation                                OK
mysql.help_topic                                   OK
mysql.innodb_index_stats                           OK
mysql.innodb_table_stats                           OK
mysql.ndb_binlog_index                             OK
mysql.plugin                                       OK
mysql.proc                                         OK
mysql.procs_priv                                   OK
mysql.proxies_priv                                 OK
mysql.server_cost                                  OK
mysql.servers                                      OK
mysql.slave_master_info                            OK
mysql.slave_relay_log_info                         OK
mysql.slave_worker_info                            OK
mysql.tables_priv                                  OK
mysql.time_zone                                    OK
mysql.time_zone_leap_second                        OK
mysql.time_zone_name                               OK
mysql.time_zone_transition                         OK
mysql.time_zone_transition_type                    OK
mysql.user                                         OK
Upgrading from a version before MariaDB-10.1
Phase 2/7: Installing used storage engines
Checking for tables with unknown storage engine
Phase 3/7: Fixing views from mysql
sys.host_summary
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.host_summary_by_file_io
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.host_summary_by_file_io_type
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.host_summary_by_stages
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.host_summary_by_statement_latency
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.host_summary_by_statement_type
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.innodb_buffer_stats_by_schema
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.innodb_buffer_stats_by_table
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.innodb_lock_waits
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.io_by_thread_by_latency
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.io_global_by_file_by_bytes
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.io_global_by_file_by_latency
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.io_global_by_wait_by_bytes
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.io_global_by_wait_by_latency
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.latest_file_io
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.memory_by_host_by_current_bytes
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.memory_by_thread_by_current_bytes
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.memory_by_user_by_current_bytes
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.memory_global_by_current_bytes
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.memory_global_total
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.metrics
Error    : Unknown column 'information_schema.INNODB_METRICS.STATUS' in 'field list'
Error    : View 'sys.metrics' references invalid table(s) or column(s) or function(s) or definer/invoker of view lack rights to use them
error    : Corrupt
sys.processlist
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.ps_check_lost_instrumentation                  OK
sys.schema_auto_increment_columns                  OK
sys.schema_index_statistics
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.schema_object_overview                         OK
sys.schema_redundant_indexes                       OK
sys.schema_table_lock_waits
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.schema_table_statistics
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.schema_table_statistics_with_buffer
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.schema_tables_with_full_table_scans
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.schema_unused_indexes                          OK
sys.session
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.session_ssl_status                             OK
sys.statement_analysis
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.statements_with_errors_or_warnings
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.statements_with_full_table_scans
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.statements_with_runtimes_in_95th_percentile
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.statements_with_sorting
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.statements_with_temp_tables
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.user_summary
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.user_summary_by_file_io
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.user_summary_by_file_io_type
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.user_summary_by_stages
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.user_summary_by_statement_latency
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.user_summary_by_statement_type
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.version                                        OK
sys.wait_classes_global_by_avg_latency
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.wait_classes_global_by_latency
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.waits_by_host_by_latency
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.waits_by_user_by_latency
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.waits_global_by_latency
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.x$host_summary                                 OK
sys.x$host_summary_by_file_io                      OK
sys.x$host_summary_by_file_io_type                 OK
sys.x$host_summary_by_stages                       OK
sys.x$host_summary_by_statement_latency            OK
sys.x$host_summary_by_statement_type               OK
sys.x$innodb_buffer_stats_by_schema                OK
sys.x$innodb_buffer_stats_by_table                 OK
sys.x$innodb_lock_waits                            OK
sys.x$io_by_thread_by_latency                      OK
sys.x$io_global_by_file_by_bytes                   OK
sys.x$io_global_by_file_by_latency                 OK
sys.x$io_global_by_wait_by_bytes                   OK
sys.x$io_global_by_wait_by_latency                 OK
sys.x$latest_file_io                               OK
sys.x$memory_by_host_by_current_bytes              OK
sys.x$memory_by_thread_by_current_bytes            OK
sys.x$memory_by_user_by_current_bytes              OK
sys.x$memory_global_by_current_bytes               OK
sys.x$memory_global_total                          OK
sys.x$processlist                                  OK
sys.x$ps_digest_95th_percentile_by_avg_us          OK
sys.x$ps_digest_avg_latency_distribution           OK
sys.x$ps_schema_table_statistics_io
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.x$schema_flattened_keys                        OK
sys.x$schema_index_statistics                      OK
sys.x$schema_table_lock_waits
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.x$schema_table_statistics
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.x$schema_table_statistics_with_buffer
Error    : Column count of mysql.proc is wrong. Expected 21, found 20. Created with MariaDB 50731, now running 100506. Please use mariadb-upgrade to fix this error
error    : Corrupt
sys.x$schema_tables_with_full_table_scans          OK
sys.x$session                                      OK
sys.x$statement_analysis                           OK
sys.x$statements_with_errors_or_warnings           OK
sys.x$statements_with_full_table_scans             OK
sys.x$statements_with_runtimes_in_95th_percentile  OK
sys.x$statements_with_sorting                      OK
sys.x$statements_with_temp_tables                  OK
sys.x$user_summary                                 OK
sys.x$user_summary_by_file_io                      OK
sys.x$user_summary_by_file_io_type                 OK
sys.x$user_summary_by_stages                       OK
sys.x$user_summary_by_statement_latency            OK
sys.x$user_summary_by_statement_type               OK
sys.x$wait_classes_global_by_avg_latency           OK
sys.x$wait_classes_global_by_latency               OK
sys.x$waits_by_host_by_latency                     OK
sys.x$waits_by_user_by_latency                     OK
sys.x$waits_global_by_latency                      OK
Phase 4/7: Running 'mysql_fix_privilege_tables'
Phase 5/7: Fixing table and database names
Phase 6/7: Checking and upgrading tables
Processing databases
information_schema
performance_schema
sys
sys.sys_config                                     OK
Phase 7/7: Running 'FLUSH PRIVILEGES'
OK
 
MariaDB [(none)]> show create user dan@localhost;
+----------------------------------------------------------+
| CREATE USER for dan@localhost                            |
+----------------------------------------------------------+
| CREATE USER `dan`@`localhost` IDENTIFIED VIA unix_socket |
+----------------------------------------------------------+
1 row in set (0.000 sec)
$ client/mysql -S /tmp/mars.sock 
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 23
Server version: 10.5.6-MariaDB MariaDB Server
 
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
 
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
 
MariaDB [(none)]> select current_user();
+----------------+
| current_user() |
+----------------+
| dan@localhost  |
+----------------+

attempt migration in --bootstrap

/tmp 
$ rm -rf /tmp/migratefrommdata
 
/tmp 
$   cp -a /tmp/mdata /tmp/migratefrommdata
 
$  echo "UPDATE mysql.user SET plugin='unix_socket' WHERE plugin='auth_socket';" | sql/mariadbd --no-defaults --bootstrap  --skip-networking --datadir=/tmp/migratefrommdata --socket /tmp/mars.sock --lc-messages-dir=${PWD}/sql/share --verbose
2020-09-03 11:37:49 0 [Note] sql/mariadbd (mysqld 10.5.6-MariaDB) starting as process 1887038 ...
2020-09-03 11:37:49 0 [Note] InnoDB: Using Linux native AIO
2020-09-03 11:37:49 0 [Note] InnoDB: Uses event mutexes
2020-09-03 11:37:49 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2020-09-03 11:37:49 0 [Note] InnoDB: Number of pools: 1
2020-09-03 11:37:49 0 [Note] InnoDB: Using SSE4.2 crc32 instructions
2020-09-03 11:37:49 0 [Note] mariadbd: O_TMPFILE is not supported on /tmp (disabling future attempts)
2020-09-03 11:37:49 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
2020-09-03 11:37:49 0 [Note] InnoDB: Completed initialization of buffer pool
2020-09-03 11:37:49 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-09-03 11:37:49 0 [Note] InnoDB: Upgrading redo log: 100663296 bytes; LSN=2720120
2020-09-03 11:37:49 0 [Note] InnoDB: Starting to delete and rewrite log file.
2020-09-03 11:37:49 0 [Note] InnoDB: Setting log file ./ib_logfile101 size to 100663296 bytes
2020-09-03 11:37:49 0 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2020-09-03 11:37:49 0 [Note] InnoDB: New log file created, LSN=2720120
2020-09-03 11:37:49 0 [Note] InnoDB: 128 rollback segments are active.
2020-09-03 11:37:49 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-09-03 11:37:49 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-09-03 11:37:49 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-09-03 11:37:49 0 [Note] InnoDB: 10.5.6 started; log sequence number 2720108; transaction id 1286
2020-09-03 11:37:49 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-09-03 11:37:49 0 [Note] InnoDB: Loading buffer pool(s) from /tmp/migratefrommdata/ib_buffer_pool
 
$ sql/mysqld --no-defaults --skip-networking --datadir=/tmp/migratefrommdata --socket /tmp/mars.sock --lc-messages-dir=${PWD}/sql/share --verbose
2020-09-03 11:38:12 0 [Note] sql/mysqld (mysqld 10.5.6-MariaDB) starting as process 1887071 ...
2020-09-03 11:38:12 0 [Note] InnoDB: Using Linux native AIO
2020-09-03 11:38:12 0 [Note] InnoDB: Uses event mutexes
2020-09-03 11:38:12 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2020-09-03 11:38:12 0 [Note] InnoDB: Number of pools: 1
2020-09-03 11:38:12 0 [Note] InnoDB: Using SSE4.2 crc32 instructions
2020-09-03 11:38:12 0 [Note] mysqld: O_TMPFILE is not supported on /tmp (disabling future attempts)
2020-09-03 11:38:12 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
2020-09-03 11:38:12 0 [Note] InnoDB: Completed initialization of buffer pool
2020-09-03 11:38:12 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-09-03 11:38:12 0 [Note] InnoDB: 128 rollback segments are active.
2020-09-03 11:38:12 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-09-03 11:38:12 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-09-03 11:38:12 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-09-03 11:38:12 0 [Note] InnoDB: 10.5.6 started; log sequence number 2724648; transaction id 1286
2020-09-03 11:38:12 0 [Note] InnoDB: Loading buffer pool(s) from /tmp/migratefrommdata/ib_buffer_pool
2020-09-03 11:38:12 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-09-03 11:38:12 0 [ERROR] mysqld: Can't open shared library '/usr/local/mysql/lib/plugin/auth_socket.so' (errno: 2, cannot open shared object file: No such file or directory)
2020-09-03 11:38:12 0 [Note] InnoDB: Buffer pool(s) load completed at 200903 11:38:12
2020-09-03 11:38:12 0 [ERROR] Missing system table mysql.roles_mapping; please run mysql_upgrade to create it
2020-09-03 11:38:12 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
2020-09-03 11:38:12 0 [ERROR] mysqld: Event Scheduler: An error occurred when initializing system tables. Disabling the Event Scheduler.
2020-09-03 11:38:12 1 [Warning] Failed to load slave replication state from table mysql.gtid_slave_pos: 1146: Table 'mysql.gtid_slave_pos' doesn't exist
2020-09-03 11:38:12 0 [Note] Reading of all Master_info entries succeeded
2020-09-03 11:38:12 0 [Note] Added new Master_info '' to hash table
2020-09-03 11:38:12 0 [Note] sql/mysqld: ready for connections.
Version: '10.5.6-MariaDB'  socket: '/tmp/mars.sock'  port: 0  MariaDB Server
 
$ client/mysql -S /tmp/mars.sock 
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 3
Server version: 10.5.6-MariaDB MariaDB Server
 
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
 
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
 
MariaDB [(none)]> select current_user();
+----------------+
| current_user() |
+----------------+
| dan@localhost  |
+----------------+
1 row in set (0.000 sec)
 
MariaDB [(none)]> show plugins
...
| unix_socket                   | ACTIVE   | AUTHENTICATION     | NULL    | GPL     |
 

So even without an mysql_upgrade the unix socket authentication worked. Oddly the startup looked for a shared library but still worked with it inbuilt.

otto this looks totally like the gssapi plugin is installed as a package. loaded by default without a valid configuraiton, which is causing the bootstrap not to process the SQL passed to it.

If you are running a start with `mysql_system_tables_fix.sql` a `FLUSH PRIVILEGES` or restart needs to happen before the changes to the user table are picked up.

Comment by Daniel Black [ 2020-09-03 ]

Please check without the mariadb-plugin-gssapi-server installed, or include a valid configuration in its install.

Comment by Daniel Black [ 2020-09-03 ]

Also to check the upgrade of a unix auth user - you need to create one https://salsa.debian.org/mariadb-team/mariadb-server/-/blob/10.5-no-cs/debian/salsa-ci.yml#L546

"create user ${USER}@localhost identified with auth_socket";

And test laster

mysql -u $USER -e "SELECT CURRENT_USER(); SHOW GRANTS;"

Comment by Faustin Lammler [ 2020-09-03 ]

otto, here are the steps to test upgrade from mysql 5.7 to mariadb 10.5.

Install mysql 5.7:

sudo apt install wget
wget https://dev.mysql.com/get/mysql-apt-config_0.8.15-1_all.deb
sudo apt install ./mysql-apt-config_0.8.15-1_all.deb
sudo apt-key adv --keyserver keys.gnupg.net --recv-keys 8C718D3B5072E1F5
sudo apt update
sudo apt install mysql-community-server
sudo mysql
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 4
Server version: 5.7.31 MySQL Community Server (GPL)
 
Copyright (c) 2000, 2020, Oracle and/or its affiliates. All rights reserved.
 
Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.
 
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
 
mysql>

Install mariadb 10.5:

sudo apt-get install software-properties-common dirmngr
sudo apt-key adv --fetch-keys 'https://mariadb.org/mariadb_release_signing_key.asc'
sudo add-apt-repository 'deb [arch=amd64,i386,ppc64el] https://ftp.igh.cnrs.fr/pub/mariadb/repo/10.5/debian stretch main'
sudo apt update
sudo apt upgrade
sudo apt install mariadb-server

Stop mariadb and apply serg SQL command:

sudo systemctl stop mariadb
echo "UPDATE mysql.user SET plugin='unix_socket' WHERE plugin='auth_socket';" | sudo mysqld --bootstrap
2020-09-03  9:51:18 0 [Note] mysqld (mysqld 10.5.5-MariaDB-1:10.5.5+maria~stretch) starting as process 9893 ...
2020-09-03  9:51:18 0 [Note] InnoDB: Using Linux native AIO
2020-09-03  9:51:18 0 [Note] InnoDB: Uses event mutexes
2020-09-03  9:51:18 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
2020-09-03  9:51:18 0 [Note] InnoDB: Number of pools: 1
2020-09-03  9:51:18 0 [Note] InnoDB: Using SSE4.2 crc32 instructions
2020-09-03  9:51:18 0 [Note] mysqld: O_TMPFILE is not supported on /tmp (disabling future attempts)
2020-09-03  9:51:18 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
2020-09-03  9:51:18 0 [Note] InnoDB: Completed initialization of buffer pool
2020-09-03  9:51:18 0 [Note] InnoDB: page_cleaner coordinator priority: -20
2020-09-03  9:51:18 0 [Note] InnoDB: 128 rollback segments are active.
2020-09-03  9:51:18 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-09-03  9:51:18 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-09-03  9:51:18 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-09-03  9:51:18 0 [Note] InnoDB: 10.5.5 started; log sequence number 2725684; transaction id 1795
2020-09-03  9:51:18 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-09-03  9:51:18 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2020-09-03  9:51:18 0 [Note] InnoDB: Buffer pool(s) load completed at 200903  9:51:18
sudo systemctl start mariadb
sudo mariadb
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 3
Server version: 10.5.5-MariaDB-1:10.5.5+maria~stretch mariadb.org binary distribution
 
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
 
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
 
MariaDB [(none)]>

So unless I missed something, serg suggestion is perfectly working (mariadb should be stopped before though).

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

Thanks for the research danblack and faust]!

The gssapi plugin is included and installed in the same exact way in all the other pipelines as well. Interesting that your conclusion here points to it. I will do some testing with that in mind.

We already have the patch https://github.com/MariaDB/server/commit/c1bdf62452139e9310d3234266802748ba4c74b8 and it successfully applies then MySQL 5.7 in Debian is upgraded to MariaDB 10.5. However it does not seem to apply for this MySQL 5.7 from MySQL.com repos. faust] got it working manually, but it is still a bug why it does not work automatically as it does otherwise.

I will do some more testing.

Comment by Faustin Lammler [ 2020-09-03 ]

I have followed exact same steps for Debian Buster (I didn't know 5.7 was available for Buster too). And same result.

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

Removing gsapi* packages for being present in the installation process did not have any effect.

Manually stopping mariadbd after installation, running bootstrap with manual command as scripts/mysql_system_tables_fix.sql is supposed to do, and then starting the server and accessing it worked. So we can conclude that there is nothing inherently incompatible, it is just a bug around why https://github.com/MariaDB/server/commit/c1bdf62452139e9310d3234266802748ba4c74b8 does not run properly during the installation phase when upgrading on MySQL.com packages.

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

Comment from robertbindar
> Hi @Otto Kekäläinen ! I tried to see if this happens on fresh debug build of mariadb 10.5 and mysql 5.7 and I can't reproduce it, everything seems to work fine. Is it happening only if you download the binaries from mysql website?

You can see the full log at https://salsa.debian.org/mariadb-team/mariadb-server/-/jobs/756107 and the code that produced that test case at https://salsa.debian.org/mariadb-team/mariadb-server/-/blob/0ab5f76e02f9d856e504a9e23e226f547009bb68/debian/salsa-ci.yml#L830-880

Almost indentical test case code and result also at https://salsa.debian.org/mariadb-team/mariadb-10.5/-/jobs/972770

You should easily be able to reproduce this in Docker.

Comment by Daniel Black [ 2020-09-11 ]

Salsa output would be significantly easier to follow if DEBIAN_SCRIPT_DEBUG was set.

afaik looking at this:

  • mysql_upgrade is the executable that causes the auth plugin to change
  • this is in debian-start.inc.sh
  • this is called in debian-start and most notably the upgrade is performed in the background making any further test on this subject to race conditions.
  • there will be no output in the mariadb sysv init script as all the scripts direct this to logger

Recommend using SHOW PLUGINS as this shows all the active/inactive internal plug ins.

The "Almost identical test case" is also subject to the same race condition.

Was the "sleep 5" https://salsa.debian.org/mariadb-team/mariadb-10.5/-/jobs/972770#L1045 trying to get past this? You probably should have something more rugged.

There is no logger output artefacts that would show at what point in time the mysql_upgrade was executed, or indeed its failures. This would be useful.

On https://salsa.debian.org/mariadb-team/mariadb-10.5/-/jobs/972770

  • service mysql status failed with

    service mysql status

    /usr/bin/mysqladmin: connect to server at 'localhost' failed
    error: 'Plugin 'auth_socket' is not loaded'
    

Given the mysqladmin uses /etc/mysql/debian.cnf and the saved artefacts have an empty /etc/mysql/debian.cnf (except for an "# Automaticly generated...") a default root, no password is being used.

So in conclusion /etc/mysql/debian.cnf is empty, so the mysql_upgrade is running on the default root user. As the root user in the datadir is still has the old mysql auth_socket plugin, it can't authenticate, so it can't upgrade.

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

Thanks danblack for debugging more. I don't think the problem is in the maintainer scripts, as they are identical in the Debian/Ubuntu mysql-5.7 upgrades. There is something different about the MySQL.com version in regards to mysql_upgrade and mysql_install_db. I did however add verbosity about the install scripts in https://salsa.debian.org/mariadb-team/mariadb-10.5/-/commit/bd6d3deccda6462498bad4469961fb0604f41700 to test it.

The "sleep 5" was temporary. Cannot find the commit blame right now, but they have been removed in the Debian.org packaging now.

> So in conclusion /etc/mysql/debian.cnf is empty, so the mysql_upgrade is running on the default root user. As the root user in the datadir is still has the old mysql auth_socket plugin, it can't authenticate, so it can't upgrade.

This is identical to the case in Debian/Ubuntu repository upgrades and the change run by https://github.com/MariaDB/server/commit/c1bdf62452139e9310d3234266802748ba4c74b8 applies no matter what the debian.cnf contents are (and they are nowaydas always empty, which is correct, as the auth_socket/unix_socket is used). The root cause for MySQL.com repository upgrades failing must be something else.

Comment by Daniel Black [ 2020-09-11 ]

mysql_system_tables_fix.sql is baked into mysql_upgrade (via mysql_fix_privilege_tables_sql.c). So this is where it takes effect. And without authentication, it cannot take effect.

Where are you assuming mysql_system_tables_fix.sql is run from?

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

From https://salsa.debian.org/mariadb-team/mariadb-10.5/-/jobs/991029/raw (Ubuntu mysql-5.7 to mariadb-10.5 upgrade)

...
++ /etc/mysql/debian-start
+ output=
+ '[' -n '' ']'
Looking for 'mysql' as: /usr/bin/mysql
Looking for 'mysqlcheck' as: /usr/bin/mysqlcheck
Setting up mariadb-plugin-oqgraph (1:10.5.5-1~exp1) ...
Setting up mariadb-server (1:10.5.5-1~exp1) ...
MariaDB upgrade detected
Phase 1/7: Checking and upgrading mysql database
Setting up mariadb-plugin-spider (1:10.5.5-1~exp1) ...
Processing databases
mysql
mysql.columns_priv                                 OK
mysql.db                                           OK
mysql.engine_cost                                  OK
mysql.event                                        OK
mysql.func                                         OK
...

-> Upgrade works, as expected.

From https://salsa.debian.org/mariadb-team/mariadb-10.5/-/jobs/991034/raw (mysql.com mysql-5.7 upgrade to mariadb-10.5)

...
++ /etc/mysql/debian-start
+ output=
+ '[' -n '' ']'
Looking for 'mysql' as: /usr/bin/mysql
Looking for 'mysqlcheck' as: /usr/bin/mysqlcheck
Setting up mariadb-server (1:10.5.5-1~exp1) ...
Setting up python3-mysqldb (1.3.10-2) ...
Version check failed. Got the following error when calling the 'mysql' command line client
ERROR 1524 (HY000): Plugin 'auth_socket' is not loaded
FATAL ERROR: Upgrade failed
...

-> Upgrade fails.

That 'Version check failed' is from mysql_upgrade.c. So clearly mysql_upgrade runs but for some reason it fails..

Inside check_version_match() we have:

  if (run_query("show variables like 'version'",
                &ds_version, FALSE) ||
      extract_variable_from_show(&ds_version, version_str))

So is the code expecting the mysql connection to work before the upgrade was run? Why does it need a working mysql client connection just to check the version?

Comment by Daniel Black [ 2020-09-11 ]

Yes, mysql_upgrade needs a connection. The version check is to test that the mysql_upgrade client version matches the server version.

Fixing the mysql_fix_privilege_tables tables also uses a connection.

Yes, the connection is expected to work before the upgrade.

See Sergei's first comment here.

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

It seems a bit stupid that the database needs an upgrade before it can run, yet to run the upgrade you need to initiate it from a client connect (and the upgrade is not run by the database itself), and the client connection cannot work unless the database has been upgraded first.

I found out now the root cause to this problem. In Debian.org/Ubuntu.com MySQL installs a debian-sys-maint user is set:

5.7.21-1ubuntu1	(Ubuntu)
$ mysql -e "SELECT Host,User,plugin,authentication_string FROM user;" mysql
Host	User	plugin	authentication_string
localhost	root	auth_socket	
localhost	mysql.session	mysql_native_password	*THISISNOTAVALIDPASSWORDTHATCANBEUSEDHERE
localhost	mysql.sys	mysql_native_password	*THISISNOTAVALIDPASSWORDTHATCANBEUSEDHERE
localhost	debian-sys-maint	mysql_native_password	*76B3652286F557212D34EE61DAD4CA84229D5B4A

In the MySQL.com installs it is not set:

5.7.31	MySQL Community Server (GPL)
$ mysql -e "SELECT Host,User,plugin,authentication_string FROM user;" mysql
Host	User	plugin	authentication_string
localhost	root	auth_socket	
localhost	mysql.session	mysql_native_password	*THISISNOTAVALIDPASSWORDTHATCANBEUSEDHERE
localhost	mysql.sys	mysql_native_password	*THISISNOTAVALIDPASSWORDTHATCANBEUSEDHERE

The Debian.org/Ubuntu.com upgrades rely on using this debian-maint-user and in mysql.com installs it is missing, thus the mysql_upgrade run fails.

We need a way to run the database upgrade at lest for this specific plugin name that does not depend on a client connection. A full mysqld --bootstrap is probably not viable, because we don't know what else the mysqld daemon would cause when it starts in bootstrap mode in production all of a sudden.

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

Can we do some "binary sed" directly on the user.frm file to change s/auth_socket/unix_socket/g?

Or can the server be patched to translate auth_socker to unix_socket on the fly instead of failing on it?

Comment by Daniel Black [ 2020-09-13 ]

Second one sounds safer.

I've also looked briefly to at it might be possible to do minimal a mysql_upgrade linked to the embedded mysql server library(with ---bootstrap --skip-innodb), that can be run as part of the postinst or a pre-server start script.

Comment by Daniel Black [ 2020-09-21 ]

In the interest of time, the original Sergei suggested solution was implemented. A linked mysql_upgrade to the mysql server would of been large indistinguishable in practice to the work around provided. --skip-innodb was chosen as only the myisam based mysql.user table is changed. key-buffersize is set to 0 as no secondary use of keys occurs and in some scenarios where myisam is dominate this may be large memory useage.

Two major checks for reviews/merge:

  • is this the right debian location to place the hook?
  • Is the mysql-5.7 detection mechanism subject to false positives or negatives. The fast positive will be largely a noop so its less important.

cause:
https://github.com/mysql/mysql-server/blob/5.7/packaging/deb-in/mysql-packagesource-server.postinst.in#L80

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

Should we remove https://github.com/mariadb/server/commit/c1bdf62452139e9310d3234266802748ba4c74b8 then since it does not always work, and we manually need to boostrap the server anyway and run the same SQL statement?

What about RPM packages? The fix now suggested is purely a Debian maintainer script based workaround. While I do understand how it runs and fixes the issue with a quick instance of the server in bootstrap mode I still feel this is very unelegant. Why can't the actual mysqld server fix itself?

We just need to rename one plugin name, how hard can that be to do inside the server so we get rid of all the extra management of remembering to run extra upgrade steps and taking care an excess mysqld/mariadbd instance is not restarted too often?

Comment by Daniel Black [ 2020-09-29 ]

c1bdf62452139e9310d3234266802748ba4c74b8 works when an auth is available. So its useful when ordinary ordinary users have auth_socket that needs to be changed and there is an admin user.

MDEV-21411 is a task for an inplace upgrade that will work for this as well.

Its only Debian mysql packages that install the auth socket https://github.com/mysql/mysql-server/blob/5.7/packaging/deb-in/extra/mysql-helpers#L159, well done on being a trend setter

I comprehend the minimisation of startups, I'm trying to get back to MDEV-23494 to fix the multiple start ups in container implementations to do all the things that mysql_install_db doesn't (and hence requiring multiple startups there unconditionally).

Debian has one conditional start of mariadbd --bootstrap where I put a reasonable effort into minimizing time and other behaviours. While I appreciate that you desired something more elegant, at the moment there are more significant inelegant problems to solve.

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

Tested and confirmed to work in https://salsa.debian.org/mariadb-team/mariadb-10.5/-/jobs/1040660

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