[MDEV-16533] MariaDB can't find tables mysql.user and mysql.servers Created: 2018-06-20  Updated: 2018-07-22  Resolved: 2018-07-22

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - MyISAM
Affects Version/s: 10.2.15
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Glen Davis Assignee: Unassigned
Resolution: Incomplete Votes: 0
Labels: crash, need_feedback
Environment:

Fedora 28


Attachments: File plugin.MYI     File plugin.frm     File servers.MYI     File servers.frm    

 Description   

I've been running MariaDB for some time now without problem. I did a minor version upgrade from 10.2.14 to 10.2.15 and now it refuses to start. If I'm reading the error logs correctly, it can't find the tables mysql.user and mysql.servers. I have confirmed that the data files exist, are not corrupted, and they appear to have the proper permissions.

This is the dump from the error log. The references to the privilege tables are near the end.

2018-06-19 17:12:41 140244707127552 [Note] RocksDB: 2 column families found
2018-06-19 17:12:41 140244707127552 [Note] RocksDB: Column Families at start:
2018-06-19 17:12:41 140244707127552 [Note]   cf=default
2018-06-19 17:12:41 140244707127552 [Note]     write_buffer_size=67108864
2018-06-19 17:12:41 140244707127552 [Note]     target_file_size_base=67108864
2018-06-19 17:12:41 140244707127552 [Note]   cf=__system__
2018-06-19 17:12:41 140244707127552 [Note]     write_buffer_size=67108864
2018-06-19 17:12:41 140244707127552 [Note]     target_file_size_base=67108864
2018-06-19 17:12:41 140244707127552 [Note] RocksDB: Table_store: loaded DDL data for 0 tables
2018-06-19 17:12:41 140244707127552 [Note] RocksDB: global statistics using get_sched_indexer_t indexer
2018-06-19 17:12:41 140244707127552 [Note] MyRocks storage engine plugin has been successfully initialized.
Tue Jun 19 17:12:41 2018 PerconaFT recovery starting in env /var/lib/mysql/
Tue Jun 19 17:12:41 2018 PerconaFT recovery scanning backward from 1319
Tue Jun 19 17:12:41 2018 PerconaFT recovery bw_end_checkpoint at 1319 timestamp 1529453469731997 xid 1315 (bw_newer)
Tue Jun 19 17:12:41 2018 PerconaFT recovery bw_begin_checkpoint at 1315 timestamp 1529453469731991 (bw_between)
Tue Jun 19 17:12:41 2018 PerconaFT recovery turning around at begin checkpoint 1315 time 6
Tue Jun 19 17:12:41 2018 PerconaFT recovery starts scanning forward to 1319 from 1315 left 4 (fw_between)
Tue Jun 19 17:12:41 2018 PerconaFT recovery closing 2 dictionaries
Tue Jun 19 17:12:41 2018 PerconaFT recovery making a checkpoint
Tue Jun 19 17:12:41 2018 PerconaFT recovery done
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: Uses event mutexes
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: Compressed tables use zlib 1.2.11
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: Using Linux native AIO
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: Number of pools: 1
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: Using SSE2 crc32 instructions
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: Completed initialization of buffer pool
2018-06-19 17:12:41 140243754858240 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: Highest supported file format is Barracuda.
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: 128 out of 128 rollback segments are active.
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: Creating shared tablespace for temporary tables
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: Waiting for purge to start
2018-06-19 17:12:41 140244707127552 [Note] InnoDB: 5.7.22 started; log sequence number 26491335405
2018-06-19 17:12:41 140243746465536 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2018-06-19 17:12:41 140244707127552 [Note] Plugin 'FEEDBACK' is disabled.
2018-06-19 17:12:41 140244707127552 [ERROR] Could not open mysql.plugin table. Some plugins may be not loaded
2018-06-19 17:12:41 140244707127552 [Note] Recovering after a crash using tc.log
2018-06-19 17:12:41 140244707127552 [Note] Starting crash recovery...
2018-06-19 17:12:41 140244707127552 [Note] Crash recovery finished.
2018-06-19 17:12:41 140244707127552 [ERROR] Can't open and lock privilege tables: Table 'mysql.servers' doesn't exist
2018-06-19 17:12:41 140244707127552 [Note] Server socket created on IP: '::'.
2018-06-19 17:12:41 140244707127552 [ERROR] Fatal error: Can't open and lock privilege tables: Table 'mysql.user' doesn't exist

This the systemd output:

Starting MariaDB 10.2 database server...
mysql-prepare-db-dir[10435]: Database MariaDB is probably initialized in /var/lib/mysql already, nothing is done.
mysql-prepare-db-dir[10435]: If this is not the case, make sure the /var/lib/mysql is empty before running mysql-prepare-db-dir.
[Note] /usr/libexec/mysqld (mysqld 10.2.15-MariaDB) starting as process 10472 ...
systemd[1]: mariadb.service: Main process exited, code=exited, status=1/FAILURE
systemd[1]: mariadb.service: Failed with result 'exit-code'.
systemd[1]: Failed to start MariaDB 10.2 database server.

I've run myisamchk on all the tables in the data directory, and I've uninstalled and reinstalled the mariadb-server package. As far as I can tell it hasn't made a difference.



 Comments   
Comment by Alice Sherepa [ 2018-06-20 ]

Could you please upload full error log. Thanks!

Comment by Elena Stepanova [ 2018-06-20 ]

Also please check ownership and privileges on <datadir>/mysql/servers.*, <datadir>/mysql/plugin.* and <datadir>/mysql/user.*.
The errors you are getting are typical for the lack of access rights to these particular tables. plugin and servers are not fatal, but user is.

Comment by Glen Davis [ 2018-06-21 ]

Alice: The error log I uploaded is from a complete (attempted) start of the server. I moved the old log, tried launching the server and this error log was the result. Is there something more you want? Like the system error log?

Elena: ownership and privileges seem to be okay. This is what

ls -al plugin* servers* user*

prints:

-rw-rw----.  1 mysql mysql    1518 Jun 21 06:56 plugin.frm
-rw-rw----.  1 mysql mysql       0 Jun 21 06:56 plugin.MYD
-rw-rw----.  1 mysql mysql    1024 Jun 21 06:56 plugin.MYI
-rw-rw----.  1 mysql mysql    2703 Jun 21 06:56 servers.frm
-rw-r-----.  1 mysql mysql       0 Jun 19 22:36 servers.MYD
-rw-r-----.  1 mysql mysql    1024 Jun 20 08:03 servers.MYI
-rw-rw----.  1 mysql mysql    3191 Jun 21 06:56 user.frm
-rw-rw----.  1 mysql mysql    5816 Jun 21 06:56 user.MYD
-rw-rw----.  1 mysql mysql    4096 Jun 21 06:56 user.MYI

Comment by Elena Stepanova [ 2018-06-21 ]

For Fedora, whenever the question of access pops up, SELinux is the main suspect. Also, it's weird why permissions on servers.MY* would be different. File sizes look okay.
Can you attach the actual files servers.* and plugin.*, all 6 of them? Both tables are empty, so they can't contain any confidential information.

Comment by Glen Davis [ 2018-06-21 ]

I've uploaded four of them - I get an error when I try to upload the empty MYD files.

File "servers.MYD" was not uploaded
 
No data was sent for servers.MYD. The browser may not be able to read the file.

Comment by Elena Stepanova [ 2018-06-21 ]

These four work just fine for me. You can pack them all (including empty ones) into one archive, although I doubt that the problem is in empty ones.
Can you try to completely disable SELinux and check if the problem goes away?

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