[Current thread is 1 (Thread 0x7f507c15f700 (LWP 30081))]
(gdb) bt
#0 __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
#1 0x0000562a6133b21e in my_write_core (sig=sig@entry=6) at /test/10.5_dbg/mysys/stacktrace.c:518
#2 0x0000562a60ae108f in handle_fatal_signal (sig=6) at /test/10.5_dbg/sql/signal_handler.cc:329
#3 <signal handler called>
#4 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
#5 0x00007f507a8a3801 in __GI_abort () at abort.c:79
#6 0x0000562a610f73e8 in ut_dbg_assertion_failed (expr=expr@entry=0x562a6174c238 "os_thread_count <= srv_max_n_threads", file=file@entry=0x562a6174c208 "/test/10.5_dbg/storage/innobase/os/os0thread.cc", line=line@entry=146) at /test/10.5_dbg/storage/innobase/ut/ut0dbg.cc:60
#7 0x0000562a60f79921 in os_thread_create_func (func=func@entry=0x562a61223333 <fil_crypt_thread(void*)>, arg=arg@entry=0x0, thread_id=thread_id@entry=0x7f507c15d8d8) at /test/10.5_dbg/storage/innobase/os/os0thread.cc:146
#8 0x0000562a612221c8 in fil_crypt_set_thread_cnt (new_cnt=10000) at /test/10.5_dbg/storage/innobase/fil/fil0crypt.cc:2133
#9 0x0000562a60e94a01 in innodb_encryption_threads_update (save=0x7f504e8743b0) at /test/10.5_dbg/storage/innobase/handler/ha_innodb.cc:18812
#10 0x0000562a60851585 in sys_var_pluginvar::global_update (this=0x7f5079f785f0, thd=0x7f504e815088, var=0x7f504e874390) at /test/10.5_dbg/sql/sql_plugin.cc:3584
#11 0x0000562a6074f9e2 in sys_var::update (this=0x7f5079f785f0, thd=0x7f504e815088, var=0x7f504e874390) at /test/10.5_dbg/sql/set_var.cc:207
#12 0x0000562a6074ff0b in set_var::update (this=<optimized out>, thd=<optimized out>) at /test/10.5_dbg/sql/set_var.cc:859
#13 0x0000562a607512c8 in sql_set_variables (thd=thd@entry=0x7f504e815088, var_list=var_list@entry=0x7f504e819fa0, free=free@entry=true) at /test/10.5_dbg/sql/set_var.cc:746
#14 0x0000562a6083a50c in mysql_execute_command (thd=thd@entry=0x7f504e815088) at /test/10.5_dbg/sql/sql_parse.cc:4976
#15 0x0000562a608449d1 in mysql_parse (thd=thd@entry=0x7f504e815088, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7f507c15e450, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:7953
#16 0x0000562a60830719 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7f504e815088, packet=packet@entry=0x7f504e867089 "SET @@GLOBAL.innodb_encryption_threads=10000", packet_length=packet_length@entry=44, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:1839
#17 0x0000562a6082ef6f in do_command (thd=0x7f504e815088) at /test/10.5_dbg/sql/sql_parse.cc:1358
#18 0x0000562a60989a53 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x7f5052c433a8, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1422
#19 0x0000562a60989d82 in handle_one_connection (arg=arg@entry=0x7f5052c433a8) at /test/10.5_dbg/sql/sql_connect.cc:1319
#20 0x0000562a60dea080 in pfs_spawn_thread (arg=0x7f5079c45888) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
#21 0x00007f507b5866db in start_thread (arg=0x7f507c15f700) at pthread_create.c:463
#22 0x00007f507a98488f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
axel Marko informs me that a bug fix is trivial once he has some reasonable suggestion for a limit. Would you have a recommendation from your experience? Thank you!
Roel Van de Paar
added a comment - axel Marko informs me that a bug fix is trivial once he has some reasonable suggestion for a limit. Would you have a recommendation from your experience? Thank you!
From the discussion with marko in Slack it seems as if this background thread does nothing more than marking pages as dirty so they would be picked up by the checkpointing mechanism and (re)encrypted. I fail to see why one would need multiple such threads at all. The encryption itself and the IO would be the bottleneck of that background operation.
I will however do some testing to find out if multiple such threads do any good.
Axel Schwenke
added a comment - From the discussion with marko in Slack it seems as if this background thread does nothing more than marking pages as dirty so they would be picked up by the checkpointing mechanism and (re)encrypted. I fail to see why one would need multiple such threads at all. The encryption itself and the IO would be the bottleneck of that background operation.
I will however do some testing to find out if multiple such threads do any good.
# mysqld options required for replay: --innodb-encryption-threads=10000
Leads to another double assert:
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x0 thread_stack 0x49000
2020-04-25 00:45:25 0x7fccc113f700 InnoDB: Assertion failure in file /test/10.5_dbg/storage/innobase/include/sync0arr.ic line 82
InnoDB: Failing assertion: *cell != NULL
InnoDB: We intentionally generate a memory trap.
[...]
2020-04-25 00:45:25 0x7fccc6f03700 InnoDB: Assertion failure in file /test/10.5_dbg/storage/innobase/include/sync0arr.ic line 82
InnoDB: Failing assertion: *cell != NULL
InnoDB: We intentionally generate a memory trap.
[...]
Roel Van de Paar
added a comment - - edited This testcase;
# mysqld options required for replay: --innodb-encryption-threads=10000
Leads to another double assert:
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x0 thread_stack 0x49000
2020-04-25 00:45:25 0x7fccc113f700 InnoDB: Assertion failure in file /test/10.5_dbg/storage/innobase/include/sync0arr.ic line 82
InnoDB: Failing assertion: *cell != NULL
InnoDB: We intentionally generate a memory trap.
[...]
2020-04-25 00:45:25 0x7fccc6f03700 InnoDB: Assertion failure in file /test/10.5_dbg/storage/innobase/include/sync0arr.ic line 82
InnoDB: Failing assertion: *cell != NULL
InnoDB: We intentionally generate a memory trap.
[...]
Produces the issue quicker without CLI/Server hangs.
Roel Van de Paar
added a comment - This testcase:
SET @@GLOBAL.innodb_encryption_threads=255;
SET @@GLOBAL.innodb_encryption_threads=1000;
SET @@GLOBAL.innodb_encryption_threads=10000;
Produces the issue quicker without CLI/Server hangs.
ERROR 2013 (HY000): Lost connection to MySQL server during query
Roel Van de Paar
added a comment - - edited Discussing with Axel. Test done (and same result for innodb_sync_array_size=1000);
10.5.3>SELECT @@GLOBAL.innodb_sync_array_size;
+---------------------------------+
| @@GLOBAL.innodb_sync_array_size |
+---------------------------------+
| 10 |
+---------------------------------+
1 row in set (0.000 sec)
10.5.3>SET @@GLOBAL.innodb_encryption_threads=10000;
ERROR 2013 (HY000): Lost connection to MySQL server during query
That backtrace from Roel hints that the number of innodb_encryption_threads counts against the number of sync array slots (srv_max_n_threads). Having too many innodb_encryption_threads would just fill the sync array and eventuelly overflow it and then crash the server. The limit for innodb_encryption_threads should hence depend on srv_max_n_threads. It should probably be no larger than 1/10th of it or the encryption threads would disrupt normal operations.
Now I see in MDEV-14462 and friends that srv_max_n_threads is about to be removed. So I wonder how much sense such a solution would make.
Axel Schwenke
added a comment - That backtrace from Roel hints that the number of innodb_encryption_threads counts against the number of sync array slots (srv_max_n_threads). Having too many innodb_encryption_threads would just fill the sync array and eventuelly overflow it and then crash the server. The limit for innodb_encryption_threads should hence depend on srv_max_n_threads. It should probably be no larger than 1/10th of it or the encryption threads would disrupt normal operations.
Now I see in MDEV-14462 and friends that srv_max_n_threads is about to be removed. So I wonder how much sense such a solution would make.
I would prefer an exact proposal, so that I do not have to investigate too much myself. Now that innodb_sync_array_size was mentioned, I see that its minimum value is 1. Does that minimum value cause crashes if encryption is not involved?
Marko Mäkelä
added a comment - I would prefer an exact proposal, so that I do not have to investigate too much myself. Now that innodb_sync_array_size was mentioned, I see that its minimum value is 1. Does that minimum value cause crashes if encryption is not involved?
for i in 1 4 16 64; do ./mtr --mysqld=--innodb-encryption-threads=$i encryption.encrypt_and_grep; done
innodb_encryption_threads
time/s
1
21.142
4
19.345
16
17.817
64
17.821
This was on a system with 2×10 CPU cores, or 40 threads in total with hyperthreading.
I also tried innodb_encryption_threads=255 and innodb_sync_array_size=1 without any problem. The test execution time was about the same as with innodb_encryption_threads=16.
Based on this experiment, I think that 255 would be a reasonable upper limit.
Marko Mäkelä
added a comment - I performed a quick benchmark myself. I believe that this test keeps the server idle while the files are being encrypted in the background.
diff --git a/mysql-test/suite/encryption/t/encrypt_and_grep.opt b/mysql-test/suite/encryption/t/encrypt_and_grep.opt
index c50ec719307..ed6cbd72b49 100644
--- a/mysql-test/suite/encryption/t/encrypt_and_grep.opt
+++ b/mysql-test/suite/encryption/t/encrypt_and_grep.opt
@@ -1,7 +1,6 @@
--innodb-encrypt-tables=ON
--innodb-encrypt-log=ON
--innodb-encryption-rotate-key-age=15
---innodb-encryption-threads=4
--innodb-tablespaces-encryption
for i in 1 4 16 64; do ./mtr --mysqld=--innodb-encryption-threads=$i encryption.encrypt_and_grep; done
innodb_encryption_threads
time/s
1
21.142
4
19.345
16
17.817
64
17.821
This was on a system with 2×10 CPU cores, or 40 threads in total with hyperthreading.
I also tried innodb_encryption_threads=255 and innodb_sync_array_size=1 without any problem. The test execution time was about the same as with innodb_encryption_threads=16 .
Based on this experiment, I think that 255 would be a reasonable upper limit.
marko the innodb_sync_array_size variable is misnamed. This variable does not set the size of the sync array, but in how many partitions it is split (to reduce mutex contention). The crash with very big innodb_encryption_threads happens because each such thread allocates one slot in the sync array. Then the array overflows eventually.
The sync array is statically sized using srv_max_n_threads. I could not find where this in turn is set, but it must be somewhere when InnoDB is initialized. Probably related to max_connections? In any case there is an implied relationship between the size of the sync array and the number of threads in InnoDB. It was just never foreseen that there could be a huge number of internal threads using the sync array. IMHO the whole logic for determining the size of the sync array should be checked and fixed.
Axel Schwenke
added a comment - marko the innodb_sync_array_size variable is misnamed. This variable does not set the size of the sync array, but in how many partitions it is split (to reduce mutex contention). The crash with very big innodb_encryption_threads happens because each such thread allocates one slot in the sync array. Then the array overflows eventually.
The sync array is statically sized using srv_max_n_threads . I could not find where this in turn is set, but it must be somewhere when InnoDB is initialized. Probably related to max_connections ? In any case there is an implied relationship between the size of the sync array and the number of threads in InnoDB. It was just never foreseen that there could be a huge number of internal threads using the sync array. IMHO the whole logic for determining the size of the sync array should be checked and fixed.
axel, sorry, I missed your comment until now. In MDEV-21452 (MariaDB 10.6), we reduced the sync arrays to a single 64-bit std::atomic integer that roughly keeps track of the longest wait on dict_sys.mutex and allows innodb_fatal_semaphore_wait_threshold to be enforced on that single mutex (which usually is participating in all "long semaphore waits" that I can remember). RW-locks will be either native ones (MDEV-24167) or futex-based, and the shared/update/exclusive locks for index trees or buffer pool blocks (MDEV-24142) are based on futex, or a mutex and condition variables.
After MDEV-21452 in 10.6, the encryption threads are constantly sleeping and waking up. The reason for this is the I/O throttling: fil_crypt_find_space_to_rotate() would first potentially wait in fil_crypt_alloc_iops(), and at the end, invoke fil_crypt_return_iops() to interrupt the sleep of any other threads that are waiting in fil_crypt_alloc_iops(). The assumption seems to be that there are plenty of tablespaces that need key rotation. It would appear that when there is no work to do, the threads would be waking up unnecessarily.
I repeated my previous benchmark, on 10.5 and 10.6, both compiled with the following:
This was with 10.5 e8217d070fc3e60870131615a48515836c773b07 and 10.6 af1335c2d6c3f3d656e4227bc0c925c5f7051d7e.
So, we still seem to have some benefit from multiple threads. But, what if we use innodb_encryption_threads=1 (there is a single buf_flush_page_cleaner thread that does the actual work, after all) and a larger value of innodb_encryption_rotation_iops?
innodb_encryption_rotation_iops
10.5 time/s
10.6 time/s
100
9436
9548
400
9134
9235
1000
9139
9242
1600
9340
9141
6400
9237
9035
10000
9133
9138
100000
9237
9136
1000000
9248
9134
There is some random variation in the numbers, but we still seem to benefit from multiple threads that are dirtying the pages concurrently.
Marko Mäkelä
added a comment - axel , sorry, I missed your comment until now. In MDEV-21452 (MariaDB 10.6), we reduced the sync arrays to a single 64-bit std::atomic integer that roughly keeps track of the longest wait on dict_sys.mutex and allows innodb_fatal_semaphore_wait_threshold to be enforced on that single mutex (which usually is participating in all "long semaphore waits" that I can remember). RW-locks will be either native ones ( MDEV-24167 ) or futex-based, and the shared/update/exclusive locks for index trees or buffer pool blocks ( MDEV-24142 ) are based on futex, or a mutex and condition variables.
After MDEV-21452 in 10.6, the encryption threads are constantly sleeping and waking up. The reason for this is the I/O throttling: fil_crypt_find_space_to_rotate() would first potentially wait in fil_crypt_alloc_iops() , and at the end, invoke fil_crypt_return_iops() to interrupt the sleep of any other threads that are waiting in fil_crypt_alloc_iops() . The assumption seems to be that there are plenty of tablespaces that need key rotation. It would appear that when there is no work to do, the threads would be waking up unnecessarily.
I repeated my previous benchmark, on 10.5 and 10.6, both compiled with the following:
cmake -DCMAKE_BUILD_TYPE=RelWithDebInfo -DPLUGIN_PERFSCHEMA=NO
innodb_encryption_threads
10.5 time/s
10.6 time/s
1
9435
9641
4
9243
8959
16
9225
7452
64
9014
7594
This was with 10.5 e8217d070fc3e60870131615a48515836c773b07 and 10.6 af1335c2d6c3f3d656e4227bc0c925c5f7051d7e.
So, we still seem to have some benefit from multiple threads. But, what if we use innodb_encryption_threads=1 (there is a single buf_flush_page_cleaner thread that does the actual work, after all) and a larger value of innodb_encryption_rotation_iops ?
innodb_encryption_rotation_iops
10.5 time/s
10.6 time/s
100
9436
9548
400
9134
9235
1000
9139
9242
1600
9340
9141
6400
9237
9035
10000
9133
9138
100000
9237
9136
1000000
9248
9134
There is some random variation in the numbers, but we still seem to benefit from multiple threads that are dirtying the pages concurrently.
axel Marko informs me that a bug fix is trivial once he has some reasonable suggestion for a limit. Would you have a recommendation from your experience? Thank you!