slave database mysql failed to start after reboot
Posted: Mon Jul 04, 2022 8:12 amI after I install the slave server.
I check the database and tested it by setting slave server from the system settings.
But what weird is I cannot query on mysql.user because i'm checking the slave user and the main databaser user if they exist on the slave mysq.user
I was getting these errors:
select * from mysql.user;
The user specified as a definer ('mariadb.sys'@'localhost')
after reboot the mysql server was not start automatically, I ran systemctl start mysql but it failed, then i ran mysqld_safe --user=root i get these errors on /var/log/mysql/mysqld.log
to fix this i ran chown -R mysql.mysql /var/lib/mysql
140630894916480 [ERROR] mysqld: File '/var/lib/mysql/mysql-bin.~rec~' not found (Errcode: 13 "Permission denied")
8:06:34 140630894916480 [ERROR] MYSQL_BIN_LOG::open_purge_index_file failed to open register file.
8:06:34 140630894916480 [ERROR] MYSQL_BIN_LOG::open_index_file failed to sync the index file.
8:06:34 140630894916480 [ERROR] Aborting
also this
Fatal error: Can't open and lock privilege tables: 'mysql.user' is not TABLE
but when I ran /usr/sbin/mysqld --skip-grant-tables --general-log --user=root // the putty window just stuck with this command so I open a new connection to the slave server
or /usr/sbin/mysqld --defaults-file=/etc/my.cnf --user=mysql --skip-grant-tables
then mysql command suddenly works but the status of systemctl status mysql is still inactive.
Im getting these logs
2022-07-04 8:50:37 140145106424704 [Note] Reading of all Master_info entries succeeded
2022-07-04 8:50:37 140145106424704 [Note] Added new Master_info '' to hash table
2022-07-04 8:50:37 140145106424704 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.2.32-MariaDB-log' socket: '/run/mysql/mysql.sock' port: 3306 SUSE package
2022-07-04 8:50:37 140140507637504 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000801' at position 54783010, relay log '/var/lib/mysql/mysql-relay-bin.000010' position: 508
2022-07-04 8:50:37 140140507944704 [Note] Slave I/O thread: connected to master 'xxxuserxxx_slave@192.168.3.3:3306',replication started in log 'mysql-bin.000801' at position 5478301
after that I can query on the database now using the mysql command on the mysql table and also asterisk table but when I ran the systemctl status mysql it is still down which is weird to me because i can still access the database
aded: loaded (/usr/lib/systemd/system/mariadb.service; enabled; vendor preset: disabled)
Active: failed (Result: exit-code) since Mon 2022-07-04 08:44:23 EDT; 9min ago
I check the show slave status, Everything is good. There is no last_error
Slave_IO_State | Master_Host | Master_User | Master_Port | Connect_Retry | Master_Log_File | Read_Master_Log_Pos | Relay_Log_File | Relay_Log_Pos | Relay_Mast>
+----------------------------------+-------------+---------------+-------------+---------------+------------------+---------------------+------------------------+---------------+----------->
| Waiting for master to send event | 192.168.3.3 | xxxuserxxx_slave | 3306 | 60 | mysql-bin.000801 | 77393831 | mysql-relay-bin.000012 | 22611094 | mysql-bin
Slave_IO_Running | Slave_SQL_Running | Replicate_Do_DB | Replicate_Ignore_DB | Replicate_Do_Table | Replicate_Ignore_Table | Replicate_Wild_Do_Table | Replicate_Wild_Ignore_Tab>
-----------+------------------+-------------------+-----------------+---------------------+--------------------+------------------------+-------------------------+-------------------------->
00801 | Yes | Yes | | | | | | >
-----------+------------------+-------------------+-----------------+---------------------+--------------------+------------------------+-------------------------+-------------------------
+------------+------------+--------------+---------------------+-----------------+-----------------+----------------+---------------+--------------------+--------------------+------------>
e | Last_Errno | Last_Error | Skip_Counter | Exec_Master_Log_Pos | Relay_Log_Space | Until_Condition | Until_Log_File | Until_Log_Pos | Master_SSL_Allowed | Master_SSL_CA_File | Master_SSL_>
--+------------+------------+--------------+---------------------+-----------------+-----------------+----------------+---------------+--------------------+--------------------+------------>
| 0 | | 0 | 79672236 | 24890087 | None | | 0 | No | | >
--+------------+------------+--------------+---------------------+-----------------+-----------------+----------------+---------------+--------------------+--------------------+------------
+-------------------------+-----------------------------+---------------+-----------+---------------------+--------------------------------------------------------------------->
Gtid_IO_Pos | Replicate_Do_Domain_Ids | Replicate_Ignore_Domain_Ids | Parallel_Mode | SQL_Delay | SQL_Remaining_Delay | Slave_SQL_Running_State >
-------------+-------------------------+-----------------------------+---------------+-----------+---------------------+--------------------------------------------------------------------->
| | | optimistic | 0 | NULL | Slave has read all relay log; waiting for the slave I/O thread to up>
-------------+-------------------------+-----------------------------+---------------+-----------+---------------------+---------------------------------------------------------------------
After all of that, I set again the slave server on system settings and it is working but every time I reboot the slave server same errors, so ill just going to redo the process.
I used vicibox-install script database Y and then slave Y then supplied our custom configuration for the database config.
more logs on /var/log/mysql/mysqld.log
Status information:
Current dir: /srv/mysql/data/
Running threads: 11 Cached threads: 1 Stack size: 299008
Key caches:
default
Buffer_size: 4294967296
Block_size: 1024
Division_limit: 100
Age_threshold: 300
Partitions: 64
blocks used: 48
not flushed: 0
w_requests: 1105
writes: 28
r_requests: 18234
reads: 61
handler status:
read_key: 76884
read_next: 364
read_rnd 3097
read_first: 53
write: 55382
delete 53277
update: 6018
Table status:
Opened tables: 53
Open tables: 28
Open files: 52
Open streams: 0
Alarm status:
Active alarms: 0
Max used alarms: 0
Next alarm time: 0
Memory status:
Non-mmapped space allocated from system: 140206080
Number of free chunks: 34568
Number of fastbin blocks: 15
Number of mmapped regions: 154
Space in mmapped regions: 164401152
Maximum total allocated space: 0
Space available in freed fastbin blocks: 832
Total allocated space: 85014880
Total free space: 55191200
Top-most, releasable space: 20056080
Estimated memory (with thread stack): 308195328
Global memory allocated by server: 4485955496
Memory allocated by threads: 423672
Events status:
LLA = Last Locked At LUA = Last Unlocked At
WOC = Waiting On Condition DL = Data Locked
The Event Scheduler is disabled
2022-07-04 9:18:24 139966504515328 [ERROR] Fatal error: Can't open and lock privilege tables: 'mysql.user' is not TABLE
Status information:
Current dir: /srv/mysql/data/
Running threads: 11 Cached threads: 0 Stack size: 299008
Key caches:
default
Buffer_size: 4294967296
Block_size: 1024
Division_limit: 100
Age_threshold: 300
Partitions: 64
blocks used: 52
not flushed: 0
w_requests: 1105
writes: 28
r_requests: 18247
reads: 65
handler status:
read_key: 76891
read_next: 365
read_rnd 3098
read_first: 55
write: 55388
delete 53282
update: 6020
Table status:
Opened tables: 56
Open tables: 0
Open files: 13
Open streams: 0
Alarm status:
Active alarms: 0
Max used alarms: 0
Next alarm time: 0
Memory status:
Non-mmapped space allocated from system: 140324864
Number of free chunks: 34634
Number of fastbin blocks: 51
Number of mmapped regions: 154
Space in mmapped regions: 164401152
Maximum total allocated space: 0
Space available in freed fastbin blocks: 2912
Total allocated space: 82984624
Total free space: 57340240
Top-most, releasable space: 20056080
Estimated memory (with thread stack): 308015104
Global memory allocated by server: 4483931856
Memory allocated by threads: 423672
Events status:
LLA = Last Locked At LUA = Last Unlocked At
WOC = Waiting On Condition DL = Data Locked
The Event Scheduler is disabled
2022-07-04 9:18:24 139966504515328 [ERROR] Fatal error: Can't open and lock privilege tables: 'mysql.user' is not TABLE
2022-07-04 10:37:42 139966408218368 [ERROR] mysqld: Can't find record in 'vicidial_hopper'
2022-07-04 10:37:42 139966408218368 [Warning] Slave SQL: Could not execute Update_rows_v1 event on table asterisk.vicidial_hopper; Can't find record in 'vicidial_hopper', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.000801, end_log_pos 244705230, Gtid 0-1-2063586003, Internal MariaDB error code: 1032
2022-07-04 10:37:46 139966408525568 [ERROR] mysqld: Can't find record in 'vicidial_hopper'
2022-07-04 10:37:46 139966408525568 [Warning] Slave SQL: Could not execute Update_rows_v1 event on table asterisk.vicidial_hopper; Can't find record in 'vicidial_hopper', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.000801, end_log_pos 244906455, Gtid 0-1-2063586482, Internal MariaDB error code: 1032
2022-07-04 10:37:48 139966408218368 [ERROR] mysqld: Can't find record in 'vicidial_hopper'
2022-07-04 10:37:48 139966408218368 [Warning] Slave SQL: Could not execute Update_rows_v1 event on table asterisk.vicidial_hopper; Can't find record in 'vicidial_hopper', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.000801, end_log_pos 245022840, Gtid 0-1-2063586772, Internal MariaDB error code: 1032
I check the database and tested it by setting slave server from the system settings.
But what weird is I cannot query on mysql.user because i'm checking the slave user and the main databaser user if they exist on the slave mysq.user
I was getting these errors:
select * from mysql.user;
The user specified as a definer ('mariadb.sys'@'localhost')
after reboot the mysql server was not start automatically, I ran systemctl start mysql but it failed, then i ran mysqld_safe --user=root i get these errors on /var/log/mysql/mysqld.log
to fix this i ran chown -R mysql.mysql /var/lib/mysql
140630894916480 [ERROR] mysqld: File '/var/lib/mysql/mysql-bin.~rec~' not found (Errcode: 13 "Permission denied")
8:06:34 140630894916480 [ERROR] MYSQL_BIN_LOG::open_purge_index_file failed to open register file.
8:06:34 140630894916480 [ERROR] MYSQL_BIN_LOG::open_index_file failed to sync the index file.
8:06:34 140630894916480 [ERROR] Aborting
also this
Fatal error: Can't open and lock privilege tables: 'mysql.user' is not TABLE
but when I ran /usr/sbin/mysqld --skip-grant-tables --general-log --user=root // the putty window just stuck with this command so I open a new connection to the slave server
or /usr/sbin/mysqld --defaults-file=/etc/my.cnf --user=mysql --skip-grant-tables
then mysql command suddenly works but the status of systemctl status mysql is still inactive.
Im getting these logs
2022-07-04 8:50:37 140145106424704 [Note] Reading of all Master_info entries succeeded
2022-07-04 8:50:37 140145106424704 [Note] Added new Master_info '' to hash table
2022-07-04 8:50:37 140145106424704 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.2.32-MariaDB-log' socket: '/run/mysql/mysql.sock' port: 3306 SUSE package
2022-07-04 8:50:37 140140507637504 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000801' at position 54783010, relay log '/var/lib/mysql/mysql-relay-bin.000010' position: 508
2022-07-04 8:50:37 140140507944704 [Note] Slave I/O thread: connected to master 'xxxuserxxx_slave@192.168.3.3:3306',replication started in log 'mysql-bin.000801' at position 5478301
after that I can query on the database now using the mysql command on the mysql table and also asterisk table but when I ran the systemctl status mysql it is still down which is weird to me because i can still access the database
aded: loaded (/usr/lib/systemd/system/mariadb.service; enabled; vendor preset: disabled)
Active: failed (Result: exit-code) since Mon 2022-07-04 08:44:23 EDT; 9min ago
I check the show slave status, Everything is good. There is no last_error
Slave_IO_State | Master_Host | Master_User | Master_Port | Connect_Retry | Master_Log_File | Read_Master_Log_Pos | Relay_Log_File | Relay_Log_Pos | Relay_Mast>
+----------------------------------+-------------+---------------+-------------+---------------+------------------+---------------------+------------------------+---------------+----------->
| Waiting for master to send event | 192.168.3.3 | xxxuserxxx_slave | 3306 | 60 | mysql-bin.000801 | 77393831 | mysql-relay-bin.000012 | 22611094 | mysql-bin
Slave_IO_Running | Slave_SQL_Running | Replicate_Do_DB | Replicate_Ignore_DB | Replicate_Do_Table | Replicate_Ignore_Table | Replicate_Wild_Do_Table | Replicate_Wild_Ignore_Tab>
-----------+------------------+-------------------+-----------------+---------------------+--------------------+------------------------+-------------------------+-------------------------->
00801 | Yes | Yes | | | | | | >
-----------+------------------+-------------------+-----------------+---------------------+--------------------+------------------------+-------------------------+-------------------------
+------------+------------+--------------+---------------------+-----------------+-----------------+----------------+---------------+--------------------+--------------------+------------>
e | Last_Errno | Last_Error | Skip_Counter | Exec_Master_Log_Pos | Relay_Log_Space | Until_Condition | Until_Log_File | Until_Log_Pos | Master_SSL_Allowed | Master_SSL_CA_File | Master_SSL_>
--+------------+------------+--------------+---------------------+-----------------+-----------------+----------------+---------------+--------------------+--------------------+------------>
| 0 | | 0 | 79672236 | 24890087 | None | | 0 | No | | >
--+------------+------------+--------------+---------------------+-----------------+-----------------+----------------+---------------+--------------------+--------------------+------------
+-------------------------+-----------------------------+---------------+-----------+---------------------+--------------------------------------------------------------------->
Gtid_IO_Pos | Replicate_Do_Domain_Ids | Replicate_Ignore_Domain_Ids | Parallel_Mode | SQL_Delay | SQL_Remaining_Delay | Slave_SQL_Running_State >
-------------+-------------------------+-----------------------------+---------------+-----------+---------------------+--------------------------------------------------------------------->
| | | optimistic | 0 | NULL | Slave has read all relay log; waiting for the slave I/O thread to up>
-------------+-------------------------+-----------------------------+---------------+-----------+---------------------+---------------------------------------------------------------------
After all of that, I set again the slave server on system settings and it is working but every time I reboot the slave server same errors, so ill just going to redo the process.
I used vicibox-install script database Y and then slave Y then supplied our custom configuration for the database config.
more logs on /var/log/mysql/mysqld.log
Status information:
Current dir: /srv/mysql/data/
Running threads: 11 Cached threads: 1 Stack size: 299008
Key caches:
default
Buffer_size: 4294967296
Block_size: 1024
Division_limit: 100
Age_threshold: 300
Partitions: 64
blocks used: 48
not flushed: 0
w_requests: 1105
writes: 28
r_requests: 18234
reads: 61
handler status:
read_key: 76884
read_next: 364
read_rnd 3097
read_first: 53
write: 55382
delete 53277
update: 6018
Table status:
Opened tables: 53
Open tables: 28
Open files: 52
Open streams: 0
Alarm status:
Active alarms: 0
Max used alarms: 0
Next alarm time: 0
Memory status:
Non-mmapped space allocated from system: 140206080
Number of free chunks: 34568
Number of fastbin blocks: 15
Number of mmapped regions: 154
Space in mmapped regions: 164401152
Maximum total allocated space: 0
Space available in freed fastbin blocks: 832
Total allocated space: 85014880
Total free space: 55191200
Top-most, releasable space: 20056080
Estimated memory (with thread stack): 308195328
Global memory allocated by server: 4485955496
Memory allocated by threads: 423672
Events status:
LLA = Last Locked At LUA = Last Unlocked At
WOC = Waiting On Condition DL = Data Locked
The Event Scheduler is disabled
2022-07-04 9:18:24 139966504515328 [ERROR] Fatal error: Can't open and lock privilege tables: 'mysql.user' is not TABLE
Status information:
Current dir: /srv/mysql/data/
Running threads: 11 Cached threads: 0 Stack size: 299008
Key caches:
default
Buffer_size: 4294967296
Block_size: 1024
Division_limit: 100
Age_threshold: 300
Partitions: 64
blocks used: 52
not flushed: 0
w_requests: 1105
writes: 28
r_requests: 18247
reads: 65
handler status:
read_key: 76891
read_next: 365
read_rnd 3098
read_first: 55
write: 55388
delete 53282
update: 6020
Table status:
Opened tables: 56
Open tables: 0
Open files: 13
Open streams: 0
Alarm status:
Active alarms: 0
Max used alarms: 0
Next alarm time: 0
Memory status:
Non-mmapped space allocated from system: 140324864
Number of free chunks: 34634
Number of fastbin blocks: 51
Number of mmapped regions: 154
Space in mmapped regions: 164401152
Maximum total allocated space: 0
Space available in freed fastbin blocks: 2912
Total allocated space: 82984624
Total free space: 57340240
Top-most, releasable space: 20056080
Estimated memory (with thread stack): 308015104
Global memory allocated by server: 4483931856
Memory allocated by threads: 423672
Events status:
LLA = Last Locked At LUA = Last Unlocked At
WOC = Waiting On Condition DL = Data Locked
The Event Scheduler is disabled
2022-07-04 9:18:24 139966504515328 [ERROR] Fatal error: Can't open and lock privilege tables: 'mysql.user' is not TABLE
2022-07-04 10:37:42 139966408218368 [ERROR] mysqld: Can't find record in 'vicidial_hopper'
2022-07-04 10:37:42 139966408218368 [Warning] Slave SQL: Could not execute Update_rows_v1 event on table asterisk.vicidial_hopper; Can't find record in 'vicidial_hopper', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.000801, end_log_pos 244705230, Gtid 0-1-2063586003, Internal MariaDB error code: 1032
2022-07-04 10:37:46 139966408525568 [ERROR] mysqld: Can't find record in 'vicidial_hopper'
2022-07-04 10:37:46 139966408525568 [Warning] Slave SQL: Could not execute Update_rows_v1 event on table asterisk.vicidial_hopper; Can't find record in 'vicidial_hopper', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.000801, end_log_pos 244906455, Gtid 0-1-2063586482, Internal MariaDB error code: 1032
2022-07-04 10:37:48 139966408218368 [ERROR] mysqld: Can't find record in 'vicidial_hopper'
2022-07-04 10:37:48 139966408218368 [Warning] Slave SQL: Could not execute Update_rows_v1 event on table asterisk.vicidial_hopper; Can't find record in 'vicidial_hopper', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.000801, end_log_pos 245022840, Gtid 0-1-2063586772, Internal MariaDB error code: 1032