Re: Failed to start mysql due to start_lsn and ens_lsn issue

[Jakub Lopuszanski]

One more intriguing part of this puzzle is that:

#innodb_redo/#ib_redo27250:
00000030: 0000 0008 0000 0000 0000 0000 0000 0000 ................

#innodb_redo/#ib_redo27249:
00000030: 0000 0000 0000 0000 0000 0000 0000 0000 ................

This 8 means LOG_HEADER_FLAG_FILE_FULL (a constant which is defined as 4, but the way we encode the flags is https://github.com/mysql/mysql-server/blob/mysql-8.0.30/storage/innobase/log/log0files_io.cc#L533-L541 such that we subtract 1).

This means that InnoDB did not consider #ib_redo27249 file full yet. The reason this is interesting, is because for ib_redo27250 to loose its "_tmp" suffix, we had to call log_mark_file_as_in_use() on it, which is called from log_files_create_file() which is called from log_files_produce_file() just a line before calling log_files_mark_current_file_as_full(), which leaves a very short window of time for observing such state (assuming fsync() works correctly, that is..) because right after log_files_mark_current_file_as_full() we call log_files_update_current_file_low() which closes old file, which should fsync it.

It really looks like something is wrong with fsync().