InnoDB: Operating system error number 21 in a file operation. | abort in os_file_read_func

[Roel Van de Paar]

Thread 1 (LWP 16791):
+bt
#0 0x0000003fde20c69c in pthread_kill () from /lib64/libpthread.so.0
#1 0x0000000000661fae in handle_fatal_signal (sig=6) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/signal_handler.cc:251
#2 <signal handler called>
#3 0x0000003fdde328a5 in raise () from /lib64/libc.so.6
#4 0x0000003fdde34085 in abort () from /lib64/libc.so.6
#5 0x0000000000983648 in os_file_read_func (file=77, buf=0x7f711c015250, offset=0, n=<optimized out>, trx=0x0) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/storage/innobase/os/os0file.cc:2821
#6 0x00000000009720d3 in pfs_os_file_read_func (src_line=286, src_file=0xbe5b58 "/bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/storage/innobase/log/log0online.cc", trx=0x0, n=4096, offset=0, buf=0x7f711c015250, file=77) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/storage/innobase/include/os0file.ic:262
#7 log_online_read_bitmap_page (bitmap_file=0x7f712bfbbb40, page=0x7f711c015250 "H\a", checksum_ok=0x7f712bfbbad8) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/storage/innobase/log/log0online.cc:286
#8 0x0000000000974fc5 in log_online_bitmap_iterator_next (i=0x7f712bfbbb20) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/storage/innobase/log/log0online.cc:1706
#9 0x000000000094b428 in i_s_innodb_changed_pages_fill (thd=0x2ec3900, tables=<optimized out>, cond=0x0) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/storage/innobase/handler/i_s.cc:8207
#10 0x0000000000708a5c in do_fill_table (join_table=<optimized out>, table_list=0x7f711c006188, thd=0x2ec3900) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_show.cc:7682
#11 get_schema_tables_result (join=0x7f711c02ec78, executed_place=PROCESSED_BY_JOIN_EXEC) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_show.cc:7783
#12 0x00000000006fd0ed in JOIN::prepare_result (this=0x7f711c02ec78, columns_list=<optimized out>) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_select.cc:823
#13 0x00000000006bd73f in JOIN::exec (this=0x7f711c02ec78) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_executor.cc:116
#14 0x00000000007d5099 in subselect_single_select_engine::exec (this=0x7f711c006868) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/item_subselect.cc:2771
#15 0x00000000007d69d4 in Item_subselect::exec (this=0x7f711c0066f8) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/item_subselect.cc:641
#16 0x00000000007d3ac5 in Item_in_subselect::val_bool (this=0x7f711c0066f8) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/item_subselect.cc:1399
#17 0x00000000005ced65 in Item_in_optimizer::val_int (this=0x7f711c02f130) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/item_cmpfunc.cc:2104
#18 0x00000000005b739c in Item::val_bool (this=0x7f711c02f130) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/item.cc:203
#19 0x00000000005ce04f in Item_func_not::val_int (this=0x7f711c0068a0) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/item_cmpfunc.cc:290
#20 0x00000000006bc8e9 in evaluate_join_record (join=0x7f711c02e620, join_tab=<optimized out>) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_executor.cc:1458
#21 0x00000000006bd101 in sub_select (join=0x7f711c02e620, join_tab=0x7f711c02ff00, end_of_records=<optimized out>) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_executor.cc:1273
#22 0x00000000006bd90a in do_select (join=0x7f711c02e620) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_executor.cc:930
#23 JOIN::exec (this=0x7f711c02e620) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_executor.cc:191
#24 0x00000000006ff300 in mysql_execute_select (free_join=true, select_lex=0x2ec6398, thd=0x2ec3900) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_select.cc:1101
#25 mysql_select (thd=0x2ec3900, tables=0x7f711c004f28, wild_num=1, fields=..., conds=0x7f711c0068a0, order=<optimized out>, group=0x2ec6498, having=0x0, select_options=2147781376, result=0x7f711c006ba8, unit=0x2ec5d50, select_lex=0x2ec6398) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_select.cc:1222
#26 0x00000000006ffb77 in handle_select (thd=0x2ec3900, result=0x7f711c006ba8, setup_tables_done_option=0) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_select.cc:111
#27 0x00000000006daf9d in execute_sqlcom_select (thd=0x2ec3900, all_tables=0x7f711c004f28) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_parse.cc:5280
#28 0x00000000006de510 in mysql_execute_command (thd=0x2ec3900) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_parse.cc:2749
#29 0x00000000006e1598 in mysql_parse (thd=0x2ec3900, rawbuf=<optimized out>, length=49044616, parser_state=<optimized out>) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_parse.cc:6451
#30 0x00000000006e2451 in dispatch_command (command=COM_QUERY, thd=0x2ec3900, packet=0x2ec7841 "", packet_length=174) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_parse.cc:1376
#31 0x00000000006b009f in do_handle_one_connection (thd_arg=<optimized out>) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_connect.cc:1615
#32 0x00000000006b0177 in handle_one_connection (arg=<optimized out>) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/sql/sql_connect.cc:1526
#33 0x00000000009195a9 in pfs_spawn_thread (arg=0x2e9a150) at /bzr/QA-5.6.11_opt/Percona-Server-5.6.11-alpha60.3/storage/perfschema/pfs.cc:1853
#34 0x0000003fde207851 in start_thread () from /lib64/libpthread.so.0
#35 0x0000003fddee890d in clone () from /lib64/libc.so.6

[Roel Van de Paar (roel11)]

2013-05-29 22:12:52 16627 [Note] /ssd/Percona-Server-5.6.11-alpha60.3-363.Linux.x86_64/bin/mysqld: ready for connections.
Version: '5.6.11-alpha60.3-log' socket: '/ssd/244301/current1_7/tmp/master.sock' port: 13120 Percona Server with XtraDB (GPL), Release alpha60.3, Revision 363
2013-05-29 22:15:20 16627 [Warning] InnoDB: changed page bitmap file './ib_modified_log_1_0.xdb' does not contain a complete run at the end.

2013-05-29 22:15:35 16627 [Warning] InnoDB: error opening the changed page bitmap './ib_modified_log_1_0.xdb'

2013-05-29 22:16:37 16627 [ERROR] InnoDB: Tried to read 4096 bytes at offset 0. Was only able to read 0.
2013-05-29 22:16:37 7f712bfbe700 InnoDB: Operating system error number 21 in a file operation.
InnoDB: Error number 21 means 'Is a directory'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
InnoDB: Fatal error: cannot read from file. OS error number 21.
2013-05-29 22:16:37 7f712bfbe700 InnoDB: Assertion failure in thread 140124045960960 in file os0file.cc line 2821
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
19:16:37 UTC - mysqld got signal 6 ;

[Roel Van de Paar (roel11)]

[roel@qaserver 244301]$ cat cmd87
ps -ef | grep 'cmdrun_87' | grep -v grep | awk '{print $2}' | xargs sudo kill -9
rm -Rf /hdd/ssd/244301/cmdrun_87
mkdir /hdd/ssd/244301/cmdrun_87
cd /ssd/randgen
bash -c "set -o pipefail; perl runall.pl --queries=100000000 --seed=16999 --duration=120 --querytimeout=60 --short_column_names --reporter=Shutdown,Backtrace,QueryTimeout,ErrorLog,ErrorLogAlarm --mysqld=--log-output=none --mysqld=--sql_mode=ONLY_FULL_GROUP_BY --grammar=conf/percona_qa/5.6/5.6.yy --gendata=conf/percona_qa/5.6/5.6.zz --basedir=/ssd/Percona-Server-5.6.11-alpha60.3-363.Linux.x86_64 --threads=25 --views --notnull --validator=Transformer --mysqld=--slow_query_log --mysqld=--innodb_track_changed_pages=1 --mysqld=--innodb_max_bitmap_file_size=4097 --mysqld=--innodb_changed_pages=ON --mysqld=--innodb_max_changed_pages=2 --mysqld=--innodb_flush_method=O_DSYNC --mtr-build-thread=725 --mask=12946 --vardir1=/hdd/ssd/244301/cmdrun_87 > /hdd/ssd/244301/cmdrun87.log 2>&1"

[Laurynas Biveinis (laurynas-biveinis)]

Looks like a combination of an empty/truncated/corrupted bitmap file and I_S query. Will see through the code review and check server data dir if available.

[Roel Van de Paar (roel11)]

iirc, this error may have been seen quite regularly in runs.

[Laurynas Biveinis (laurynas-biveinis)]

Not a single bitmap file here. Must check the crashing query on such dir.

[Laurynas Biveinis (laurynas-biveinis)]

Removing 56qual because the issue most likely will be present across all the versions.

[Laurynas Biveinis (laurynas-biveinis)]

Unable to reproduce. I need a core dump with its binaries. (Comment #8 has one dump, but without bins).

[Roel Van de Paar (roel11)]

I am seeing the " [Warning] InnoDB: error opening the changed page bitmap './ib_modified_log_1_0.xdb' also without an eventual crash;

2014-06-26 12:21:09 23989 [Note] Execution of init_file '/ssd/randgen/conf/percona_qa/5.6/TokuDB.sql' ended.
2014-06-26 12:21:09 23989 [Note] /ssd/Percona-Server-5.6.19-rel67.0-618.Linux.x86_64-debug/bin/mysqld: ready for connections.
Version: '5.6.19-67.0-debug-log' socket: '/ssd/939551/current1_1/tmp/master.sock' port: 13000 Percona Server (GPL), Release 67.0, Revision 618, DEBUG BINARY
2014-06-26 12:21:24 23989 [Warning] InnoDB: Setting thread 24035 nice to -6 failed, current nice 0, errno 13
2014-06-26 12:21:25 23989 [Warning] InnoDB: Setting thread 24040 nice to -2 failed, current nice 12, errno 13
2014-06-26 12:21:25 23989 [Warning] InnoDB: Setting thread 24039 nice to -2 failed, current nice 12, errno 13
2014-06-26 12:21:25 23989 [Warning] InnoDB: Setting thread 24040 nice to -19 failed, current nice 12, errno 13
2014-06-26 12:21:25 23989 [Warning] InnoDB: Setting thread 24039 nice to -19 failed, current nice 12, errno 13
2014-06-26 12:21:25 23989 [Warning] InnoDB: Setting thread 24021 nice to -20 failed, current nice 0, errno 13
2014-06-26 12:21:34 23989 [Warning] InnoDB: error opening the changed page bitmap './ib_modified_log_1_0.xdb'

2014-06-26 12:21:34 23989 [Warning] InnoDB: Setting thread 24040 nice to -1 failed, current nice 12, errno 13
2014-06-26 12:21:34 23989 [Warning] InnoDB: Setting thread 24039 nice to -1 failed, current nice 12, errno 13
2014-06-26 12:21:36 23989 [Warning] InnoDB: Setting thread 24034 nice to 9 failed, current nice 17, errno 13
[...more of the same...]
2014-06-26 12:26:06 23989 [Warning] InnoDB: Setting thread 24021 nice to -9 failed, current nice 19, errno 13
2014-06-26 12:26:06 23989 [Warning] InnoDB: Setting thread 24021 nice to -1 failed, current nice 19, errno 13
2014-06-26 12:26:06 23989 [Warning] InnoDB: Setting thread 24021 nice to 6 failed, current nice 19, errno 13
2014-06-26 12:26:06 23989 [Warning] InnoDB: Setting thread 24021 nice to -1 failed, current nice 19, errno 13
2014-06-26 12:26:06 23989 [Warning] InnoDB: changed page bitmap file './ib_modified_log_1_0.xdb' does not contain a complete run at the end.

2014-06-26 12:26:06 23989 [Warning] InnoDB: Setting thread 24034 nice to -12 failed, current nice 19, errno 13
2014-06-26 12:26:06 23989 [Warning] InnoDB: Setting thread 24021 nice to -19 failed, current nice 19, errno 13
[...more of the same...]
2014-06-26 12:26:08 23989 [Warning] InnoDB: Setting thread 24021 nice to -10 failed, current nice 19, errno 13
2014-06-26 12:26:08 23989 [Warning] InnoDB: Setting thread 24040 nice to -10 failed, current nice 19, errno 13
2014-06-26 12:26:08 23989 [Warning] InnoDB: Setting thread 24039 nice to -10 failed, current nice 19, errno 13
2014-06-26 12:26:08 23989 [Warning] InnoDB: error opening the changed page bitmap './ib_modified_log_1_0.xdb'

2014-06-26 12:26:08 23989 [Warning] InnoDB: Setting thread 24035 nice to -8 failed, current nice 19, errno 13
2014-06-26 12:26:08 23989 [Warning] InnoDB: Setting thread 24035 nice to 7 failed, current nice 19, errno 13

[Roel Van de Paar (roel11)]

Laurynas, can you maybe make a patch - based on this source: http://jenkins.percona.com/job/percona-server-5.6-source-tarballs/84/artifact/percona-server-5.6.19-67.0.tar.gz - that includes an ASSERT at the point when the "[Warning] InnoDB: error opening the changed page bitmap" error is shown? Would this be a good way of going about this one?

[Roel Van de Paar (roel11)]

I can repeat the error with this cmd file on fusion1, using the same build as mentioned in #13.

[roel@fusion1 939551]$ cat cmd9
if [ -r /usr/lib64/libjemalloc.so.1 ]; then export LD_PRELOAD=/usr/lib64/libjemalloc.so.1
elif [ -r /usr/lib/x86_64-linux-gnu/libjemalloc.so.1 ]; then export LD_PRELOAD=/usr/lib/x86_64-linux-gnu/libjemalloc.so.1
else echo 'Error: jemalloc not found, please install it first'; exit 1; fi
ps -ef | grep 'rundir1_9' | grep -v grep | awk '{print $2}' | xargs sudo kill -9 > /dev/null 2>&1
rm -Rf /ssd/939551/rundir1_9
rm -Rf /ssd/939551/rundir1_9_epoch
mkdir /ssd/939551/rundir1_9
cd /ssd/randgen
bash -c "set -o pipefail; perl /ssd/randgen/runall.pl --queries=100000000 --seed=1855 --duration=300 --querytimeout=60 --short_column_names --reporter=Shutdown,Backtrace,QueryTimeout,ErrorLog,ErrorLogAlarm --mysqld=--log-output=none --mysqld=--sql_mode=ONLY_FULL_GROUP_BY --mysqld=--plugin-load=tokudb=ha_tokudb.so --mysqld=--init-file=/ssd/randgen/conf/percona_qa/5.6/TokuDB.sql --mysqld=--utility-user-password=test --grammar=conf/percona_qa/5.6/5.6.yy --gendata=conf/percona_qa/5.6/5.6.zz3 --threads=10 --no-mask --basedir=/ssd/Percona-Server-5.6.19-rel67.0-618.Linux.x86_64-debug --mysqld=--innodb_change_buffering=none --mysqld=--innodb_changed_pages=ON --mysqld=--innodb_flush_log_at_trx_commit=0 --mysqld=--innodb_log_buffer_size=10485761 --mysqld=--innodb_log_files_in_group=10 --mysqld=--innodb_max_bitmap_file_size=9223372036854770000 --mysqld=--innodb_max_changed_pages=100 --mysqld=--innodb_track_changed_pages=1 --mysqld=--innodb-buffer-pool-populate --mysqld=--loose-readonly-key-cache-division-limit=1 --mysqld=--query_cache_type=1 --mysqld=--readonly-loose-max-connect-errors=0 --mysqld=--skip-innodb_doublewrite --mysqld=--slow_query_log --mysqld=--transaction-isolation=READ-UNCOMMITTED --mysqld=--userstat --mysqld=--utility-user-password=test --mysqld=--utility-user-schema-access=mysqlinformation_schema --mysqld=--hidden-key-buffer-size=1 --mysqld=--innodb_purge_threads=4 --mysqld=--innodb_adaptive_hash_index_partitions=16 --mtr-build-thread=705 --mask=52408 --vardir1=/ssd/939551/rundir1_9 > /ssd/939551/cmd9.log 2>&1"
tail -n1 /ssd/939551/cmd9.log

[Roel Van de Paar (roel11)]

Actually, correction, using the build I am about to add/upload (it's the binary version of the same)

[Laurynas Biveinis (laurynas-biveinis)]

By code review this might happen if PURGE/RESET is issued in parallel with I_S.I_C_P query. The fix would be to make any and all I/O error in the I_C_P reader non-fatal and assume that the bitmaps might disappear at any moment. The warnings printed in that case are valid and will stay.

[Krunal Bauskar (krunal-bauskar)]

May be related to .. https://bugs.launchpad.net/percona-server/+bug/1498891 ... error -code is different but the error message or operational environment (involvement of bitmap files) is common.

[Roel Van de Paar (roel11)]

I re-ran the testcase from #14 and got a hang + crash

[...]
2015-10-24 02:09:20 31504 [Warning] InnoDB: Setting thread 32255 nice to -11 failed, current nice 19, errno 13
2015-10-24 02:09:23 31504 [Warning] InnoDB: Setting thread 32256 nice to -11 failed, current nice 19, errno 13
2015-10-24 02:09:23 31504 [Warning] InnoDB: Setting thread 32255 nice to -11 failed, current nice 19, errno 13
InnoDB: sync levels should be > 800 but a level is 175
Mutex '&log_bmp_sys->mutex'
InnoDB: Locked mutex: addr 0x7f0e90606460 thread 139701316347648 file /mnt/workspace/percona-server-5.6-binaries-debug-yassl-new/label_exp/centos6-64/percona-server-5.6.25-73.2/storage/innobase/log/log0online.cc line 1801
InnoDB: sync_thread_levels_g(array, 800) does not hold!
2015-10-24 02:09:23 7f0ebf55e700 InnoDB: Assertion failure in thread 139701316347648 in file sync0sync.cc line 1280
[...]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f0e6dc8f010): SHOW GLOBAL STATUS LIKE 'MAX_STATEMENT_TIME_SET_FAILED'
Connection ID (thread ID): 13
Status: NOT_KILLED

Core looks corrupted. Plenty of disk space.

Reading symbols from /sda/Percona-Server-5.6.25-rel73.2-f9f2b02.Linux.x86_64-debug/bin/mysqld...done.
BFD: Warning: /sda/939551/rundir1_9/./master-data/core.31504.1000.1000.6.1445641763.mysqld is truncated: expected core file size >= 3202265088, found: 1469190144.
[New LWP 22505]
[...]
[New LWP 22619]
Cannot access memory at address 0x7f0ebf6d61e8
Cannot access memory at address 0x7f0ebf6d61e0
(gdb) bt
+bt
#0 0x00007f0ebf06f771 in ?? ()
Cannot access memory at address 0x7f0ebf559ff8

[roel@localhost rundir1_9]$ df -h | grep sda
/dev/sda 881G 205G 632G 25% /sda

[Roel Van de Paar (roel11)]

The crash listed in #20 happened on a very loaded server. When the server is not loaded, the run repeatedly completes without crashing.

[Roel Van de Paar (roel11)]

Tried getting mysqld for old core file in #8... (Core was generated by `/ssd/Percona-Server-5.6.11-alpha60.3-363.Linux.x86_64/bin/mysqld --no-defaults'. - thanks Nickolay). Regrettably, not available anymore.

[Nickolay Ihalainen (ihanick)]

It's not possible to reproduce this bug in recent versions of Percona Server 5.6 and 5.5, it's fixed by:
https://bugs.launchpad.net/percona-server/+bug/1342494

Basically, the problem happens if a single bitmap file was removed in the middle of select query from information_schema.innodb_changed_pages delete could be done with RESET CHANGED_PAGE_BITMAPS; or purge command.

I have emulated deletion with:
os_file_delete_if_exists(innodb_file_bmp_key, "ib_modified_log_1_0.xdb");

inside log_online_setup_bitmap_file_range function.

The line should be added around:
/* 2nd pass: get the file names in the file_seq_num order */

but before
while (!os_file_readdir_next_file(srv_data_home, bitmap_dir,
       &bitmap_dir_file_info)) {

This will force bitmap iterator files structure to contain all zeros
around: /* 2nd pass: get the file names in the file_seq_num order */
 memset(bitmap_files->files, 0,
        bitmap_files->count * sizeof(bitmap_files->files[0]));

In debug mode inconsistency will be found with bitmap_files->files[0].seq_num check:

#ifdef UNIV_DEBUG
 if (!bitmap_files->files[0].seq_num) {

  log_online_diagnose_inconsistent_dir(bitmap_files);
  return FALSE;
 }
 ut_ad(bitmap_files->files[0].seq_num == first_file_seq_num);
 {
  size_t i;
  for (i = 1; i < bitmap_files->count; i++) {
   if (!bitmap_files->files[i].seq_num) {
    break;
   }
   ut_ad(bitmap_files->files[i].seq_num
         > bitmap_files->files[i - 1].seq_num);
   ut_ad(bitmap_files->files[i].start_lsn
         >= bitmap_files->files[i - 1].start_lsn);
  }
 }
#endif

In fresh percona server builds
this code is no longer debug-only:

 if (!bitmap_files->files[0].seq_num
     || bitmap_files->files[0].seq_num != first_file_seq_num) {

  log_online_diagnose_inconsistent_dir(bitmap_files);
  return FALSE;
 }

And it's not possible to crash mysqld by deleting bitmap file at certain point of time.

The change was done at 06069d9e342bcb3277fccf586cc6b9181c98536c

-#ifdef UNIV_DEBUG
- if (!bitmap_files->files[0].seq_num) {
+ if (!bitmap_files->files[0].seq_num
+ || bitmap_files->files[0].seq_num != first_file_seq_num) {

                log_online_diagnose_inconsistent_dir(bitmap_files);
                return FALSE;
        }
- ut_ad(bitmap_files->files[0].seq_num == first_file_seq_num);
+

Why we are seeing "system error number 21"?

https://launchpadlibrarian.net/143030765/gdb_87_210613-2239_FULL.txt
#9 0x000000000094b428
in_files = {
            count = 1,
            files = 0x7f711c01c720
          },
          in_i = 0,
          in = {
            name = "./\000

MySQL is trying to read "./" and It's only a single file in our list (count=1).
If there is a single file it could be opened at the end of log_online_bitmap_iterator_init function by log_online_open_bitmap_file_read_only.

This function contains a debug-only check: ut_ad(name[0] != '\0');
and this function adding srv_data_home to filename. In our case srv_data_home = "./", thus the file name should be "\0".

The file name is filled by log_online_setup_bitmap_file_range, the count variable is also filled by this function.
The function reads directory twice and ...

[Laurynas Biveinis (laurynas-biveinis)]

Roel, #20 looks like a separate bug if you manage to catch it.

Now closing this as a duplicate of bug 1342494, thanks Nickolay for analysis.