Details
-
Bug
-
Status: Closed (View Workflow)
-
Minor
-
Resolution: Duplicate
-
10.5.21
-
None
Description
by MariaDB 10.5 I did such operations as follows:
Step 1. Start mysqld Process Normally
Step 2. Start SECOND mysqld Process with same datadir
(sure it's a mistaken operation)
Step 3. SECOND mysqld Process starts with failure
Step 4. normally shutdown mysqld in step1
Step 5. start mysqld Process Again
the consequence is,
when I restart the mysqld process, initialization failed:
[ERROR] InnoDB: Missing FILE_CHECKPOINT at 208901216 between the checkpoint 208901216 and the end 208901228.
In our Community, there are already well established solutions like "set forced recovery" and "delete redelog file". Also after 10.8, there are implementations like
https://mariadb.com/kb/en/innodb-errors-cant-start-mariadb-after-unexpected-shutdown/
In this implementation, InnoDB will no longer attempt to recreate a missing log file.
IMO, there are other root causes which could be fixed. That is:
By second failing start of mysqld process, InnoDB still Started and update a new LSN.(that is the end LSN ,e.g. 208901228 in the log above)
When starting second process, we see logs as follows:
ysqld: Can't lock aria control file '/u04/l00634606/maria/community/inst/data/aria_log_control' for exclusive use, error: 11. Will retry for 30 seconds
2023-07-17 14:53:48 0 [ERROR] mysqld: Got error 'Could not get an exclusive lock; file is probably in use by another process' when trying to use aria control file '/u04/l00634606/maria/community/inst/data/aria_log_control'
2023-07-17 14:53:48 0 [ERROR] Plugin 'Aria' init function returned error.
2023-07-17 14:53:48 0 [ERROR] Plugin 'Aria' registration as a STORAGE ENGINE failed.
2023-07-17 14:53:48 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2023-07-17 14:53:48 0 [Note] InnoDB: Uses event mutexes
2023-07-17 14:53:48 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2023-07-17 14:53:48 0 [Note] InnoDB: Number of pools: 1
2023-07-17 14:53:48 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
2023-07-17 14:53:48 0 [Note] InnoDB: Using Linux native AIO
2023-07-17 14:53:48 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
2023-07-17 14:53:48 0 [Note] InnoDB: Completed initialization of buffer pool
2023-07-17 14:53:48 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=208901204,208901204
2023-07-17 14:53:48 0 [Note] InnoDB: 128 rollback segments are active.
2023-07-17 14:53:50 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2023-07-17 14:53:50 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2023-07-17 14:53:50 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2023-07-17 14:53:50 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2023-07-17 14:53:50 0 [Note] InnoDB: 10.5.16 started; log sequence number 208901216; transaction id 220191
This log shows, the initialization of plugin aria failed due to control file.
But this plugin initialization failure does not stop the InnoDB initialization and updating of LSN.
Another log (after grep) in attached image may be intuitive:
the first mysqld starting at 16:12:20 is OK. LSN = 3548314272
Then I start second mysqld from 16:13:20 to 16:16:20.The LSN from the log always increase by12 .But when I normally shutdown at16:16:32 the LSN in shutdown log is still 3548314272.
Finally in error log at16:16:49 , the missing logs are from 3548314272, to those LSN logged between 16:13:20 to 16:16:20.
I think it will be better if InnoDB has the same file lock check as aria control when a mysqld is already running.
Attachments
Issue Links
- duplicates
-
MDEV-31568 innodb protection against dual processes accessing data insufficient
- Closed