origin/bb-10.4-release 0ede90dd316ee7c3e22b6c8cad5e39b5913e9eed 2023-08-08T13:24:23+05:30

Two sessions run concurrent some DDL/DML mix and the server crashes with

...

# 2023-08-08T03:09:37 [1270466] | [rr 1280990 111944]2023-08-08  3:08:32 0 [Warning] InnoDB: 2048 bytes should have been read. Only 0 bytes read. Retrying for the remaining bytes.

# 2023-08-08T03:09:37 [1270466] | [rr 1280990 111948]2023-08-08  3:08:32 0 [Warning] InnoDB: 2048 bytes should have been read. Only 0 bytes read. Retrying for the remaining bytes.

# 2023-08-08T03:09:37 [1270466] | [rr 1280990 111952]2023-08-08  3:08:32 0 [Warning] InnoDB: 2048 bytes should have been read. Only 0 bytes read. Retrying for the remaining bytes.

# 2023-08-08T03:09:37 [1270466] | [rr 1280990 111956]2023-08-08  3:08:32 0 [Warning] InnoDB: Retry attempts for reading partial data failed.

# 2023-08-08T03:09:37 [1270466] | [rr 1280990 111960]2023-08-08  3:08:32 0 [ERROR] InnoDB: Tried to read 2048 bytes at offset 40960, but was only able to read 0

# 2023-08-08T03:09:37 [1270466] | [rr 1280990 111964]2023-08-08  3:08:32 0 [ERROR] InnoDB: File (unknown): 'read' returned OS error 0. Cannot continue operation

# 2023-08-08T03:09:37 [1270466] | [rr 1280990 111978]230808  3:08:32 [rr 1280990 111981][ERROR] mysqld got signal 6 ;

# 2023-08-08T03:11:54 [1270466] | Thread 4 (Thread 1280990.1282409 (mysqld)):

# 2023-08-08T03:11:54 [1270466] | #0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=125271409890880) at ./nptl/pthread_kill.c:44

# 2023-08-08T03:11:54 [1270466] | #1  __pthread_kill_internal (signo=6, threadid=125271409890880) at ./nptl/pthread_kill.c:78

# 2023-08-08T03:11:54 [1270466] | #2  __GI___pthread_kill (threadid=125271409890880, signo=signo@entry=6) at ./nptl/pthread_kill.c:89

# 2023-08-08T03:11:54 [1270466] | #3  0x00002ac10cfb3476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26

# 2023-08-08T03:11:54 [1270466] | #4  0x00002ac10cf997f3 in __GI_abort () at ./stdlib/abort.c:79

# 2023-08-08T03:11:54 [1270466] | #5  0x000055e21084fefe in os_file_handle_error_cond_exit (name=<optimized out>, name@entry=0x0, operation=<optimized out>, operation@entry=0x55e210dd8674 "read", should_abort=should_abort@entry=true, on_error_silent=on_error_silent@entry=false) at /data/Server/bb-10.4-release/storage/innobase/os/os0file.cc:4777

# 2023-08-08T03:11:54 [1270466] | #6  0x000055e210852088 in os_file_read_page (type=..., file=84, buf=0x4d3878c36000, offset=<optimized out>, n=<optimized out>, o=o@entry=0x0, exit_on_err=true) at /data/Server/bb-10.4-release/storage/innobase/os/os0file.cc:4681

# 2023-08-08T03:11:54 [1270466] | #7  0x000055e210852142 in os_file_read_func (type=..., file=<optimized out>, buf=<optimized out>, offset=<optimized out>, n=<optimized out>) at /data/Server/bb-10.4-release/storage/innobase/os/os0file.cc:5074

# 2023-08-08T03:11:54 [1270466] | #8  0x000055e2108599fe in SimulatedAIOHandler::read (slot=<optimized out>, this=0x71ef05e309d0) at /data/Server/bb-10.4-release/storage/innobase/os/os0file.cc:6592

# 2023-08-08T03:11:54 [1270466] | #9  SimulatedAIOHandler::io (this=0x71ef05e309d0) at /data/Server/bb-10.4-release/storage/innobase/os/os0file.cc:6556

# 2023-08-08T03:11:54 [1270466] | #10 os_aio_simulated_handler (global_segment=global_segment@entry=2, m1=m1@entry=0x71ef05e30b18, m2=m2@entry=0x71ef05e30b20, type=type@entry=0x71ef05e30b40) at /data/Server/bb-10.4-release/storage/innobase/os/os0file.cc:6901

# 2023-08-08T03:11:54 [1270466] | #11 0x000055e210859b4c in os_aio_handler (segment=segment@entry=2, m1=m1@entry=0x71ef05e30b18, m2=m2@entry=0x71ef05e30b20, request=request@entry=0x71ef05e30b40) at /data/Server/bb-10.4-release/storage/innobase/os/os0file.cc:5308

# 2023-08-08T03:11:54 [1270466] | #12 0x000055e210b254fb in fil_aio_wait (segment=segment@entry=2) at /data/Server/bb-10.4-release/storage/innobase/fil/fil0fil.cc:4330

# 2023-08-08T03:11:54 [1270466] | #13 0x000055e21098609c in io_handler_thread (arg=<optimized out>) at /data/Server/bb-10.4-release/storage/innobase/srv/srv0start.cc:324

# 2023-08-08T03:11:54 [1270466] | #14 0x00002ac10d005b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442

# 2023-08-08T03:11:54 [1270466] | #15 0x00002ac10d096bb4 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100

sdp:/data1/results/1691486849/TBR-1988$ _RR_TRACE_DIR=./1/rr rr replay --mark-stdio

I hit that problem several times. The RQG runs were in all cases with --mysqld=--innodb-buffer-pool-size=5M.

RQG

===

# git clone https://github.com/mleich1/rqg --branch <pick the right branch> RQG

#

# GIT_SHOW: HEAD -> master, origin/master, origin/HEAD 499e4ae7d70fcc3937bbc302bd22e8e95826ab57 2023-08-08T10:55:43+02:00

# rqg.pl  : Version 4.3.0 (2023-06)

#

# $RQG_HOME/rqg.pl \

# --grammar=conf/mariadb/table_stress_innodb_nocopy1.yy \

# --gendata=conf/mariadb/table_stress.zz \

# --gendata_sql=conf/mariadb/table_stress.sql \

# --mysqld=--transaction-isolation=REPEATABLE-READ \

# --validator=SelectStability \

# --mysqld=--loose-innodb_lock_schedule_algorithm=fcfs \

# --mysqld=--loose-idle_write_transaction_timeout=0 \

# --mysqld=--loose-idle_transaction_timeout=0 \

# --mysqld=--loose-idle_readonly_transaction_timeout=0 \

# --mysqld=--connect_timeout=60 \

# --mysqld=--interactive_timeout=28800 \

# --mysqld=--slave_net_timeout=60 \

# --mysqld=--net_read_timeout=30 \

# --mysqld=--net_write_timeout=60 \

# --mysqld=--loose-table_lock_wait_timeout=50 \

# --mysqld=--wait_timeout=28800 \

# --no_mask \

# --queries=10000000 \

# --seed=random \

# --reporters=None \

# --reporters=ErrorLog \

# --reporters=Deadlock \

# --validators=None \

# --mysqld=--log_output=none \

# --mysqld=--log_bin_trust_function_creators=1 \

# --mysqld=--loose-debug_assert_on_not_freed_memory=0 \

# --engine=InnoDB \

# --restart_timeout=240 \

# --mysqld=--plugin-load-add=file_key_management.so \

# --mysqld=--loose-file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \

# --mysqld=--plugin-load-add=provider_lzo.so \

# --mysqld=--plugin-load-add=provider_bzip2.so \

# --mysqld=--plugin-load-add=provider_lzma.so \

# --mysqld=--plugin-load-add=provider_snappy.so \

# --mysqld=--plugin-load-add=provider_lz4.so \

# --mysqld=--loose-innodb_compression_level=1 \

# --duration=300 \

# --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \

# --mysqld=--lock-wait-timeout=86400 \

# --mysqld=--innodb-lock-wait-timeout=50 \

# --mysqld=--sql_mode=STRICT_TRANS_TABLES,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION \

# --mysqld=--innodb_file_per_table=1 \

# --mysqld=--loose-innodb_read_only_compressed=OFF \

# --mysqld=--innodb_stats_persistent=on \

# --mysqld=--innodb_adaptive_hash_index=off \

# --mysqld=--innodb_random_read_ahead=ON \

# --mysqld=--log-bin \

# --mysqld=--sync-binlog=1 \

# --mysqld=--loose-innodb_evict_tables_on_commit_debug=off \

# --mysqld=--loose-max-statement-time=30 \

# --threads=2 \

# --mysqld=--innodb-use-native-aio=0 \

# --mysqld=--loose-gdb \

# --mysqld=--loose-debug-gdb \

# --rr=Extended \

# --rr_options=--chaos --wait \

# --mysqld=--innodb_undo_log_truncate=OFF \

# --mysqld=--loose_innodb_change_buffering=all \

# --mysqld=--innodb_rollback_on_timeout=OFF \

# --mysqld=--innodb_page_size=4K \

# --mysqld=--innodb-buffer-pool-size=5M \

# <local settings>