[MDEV-9101] Limit size of created disk temporary files and tables - Jira

Details

Type: New Feature
Status: Closed (View Workflow)
Priority: Critical
Resolution: Fixed
Fix Version/s: 11.5.1
Component/s: Admin statements, Configuration, Variables
Labels:
- Preview_11.5
- triage

Description

Add a variable (max-tmp-table-disk-space) to limit the total temporary disk space used by internal temporary tables created during query execution.

When the internal in-memory temporary table is oversize and converting to MyISAM/Aria table to store on disk, this option will limit the max space of tmp_dir. If a new disk temporary table will cause tmp_dir over the limitation, then this query will return an error.

As part of this task we should also add a status variable for temporary disk space usage and also add this to information_schema.processlist.

What should be monitored:

Temporary files created by filesort and replication buffers and
sorting in engines as part of alter table, repair table, optimize table.
The first 2 are relative easy to do, the later a bit harder.
On disk internal temporary tables (MyISAM or Aria). These are relatively
easy to handle.

Explicit defined temporary tables (CREATE TEMPORARY TABLE) will
not be part of this work as this should be regarded to be a normal table.
(Any user can create and drop tables any time).
However any on disk temporary table disk space should also be possible to monitor, possible with another status variable.

First implementation:
-Two new variables:

max_tmp_space_usage : Limits the the temporary space allowance per user
max_total_space_file_usage: Limits the temporary space allowance for all users.

The temporary space is counted for:

All sql level temporary files. This includes sorts for filesort, transaction temporary space, analyze etc. It does not include engine internal files used for repair, alter table, index presorting etc.
All internal on disk temporary tables created as part of resolving a SELECT, multi-source update etc.

Attachments

- Sort By Name
- Sort By Date
- Ascending
- Descending
- Thumbnails
- List
- Download All

mdev9101-2.test
60 kB
2024-01-05 13:29
mdev9101-3.test
8 kB
2024-01-05 17:50
mdev9101-4.test
69 kB
2024-01-05 18:39
mdev9101-5.test
59 kB
2024-01-08 19:31

Issue Links

causes

MDEV-33680 Server hangs or assertion fails upon SELECT with limited max_tmp_space_usage

Closed

MDEV-33686 No warning is produced upon startup with incorrect values of max-total-tmp-space-usage or max-tmp-space-usage

Open

MDEV-33715 max_tmp_space_usage description is ambiguous

Open

MDEV-33751 Assertion `thd' failed in int temp_file_size_cb_func(tmp_file_tracking*, int)

Closed

MDEV-34016 Assertion `info->key_del_used == 0' failed in maria_close with limited tmp space

Closed

MDEV-34054 Memory leak in Window_func_runner::exec after encountering "temporary space limit reached" error

Closed

MDEV-34060 Unexpected behavior upon reading I_S.ALL_PLUGINS under limited tmp space

Closed

MDEV-34142 Server crashes in create_internal_tmp_table with low tmp space limit

Closed

MDEV-34149 Corruption-like errors are produced when temporary space limit is reached

Closed

MDEV-34150 Assertion failure in Diagnostics_area::set_error_status upon binary logging hitting tmp space limit

Closed

MDEV-34965 Wrong variable names for temporary space usage in documentation

Closed

MDEV-35541 UBSAN: runtime error: addition of unsigned offset to X overflowed to Y in my_b_flush_io_cache

Open

MDEV-35592 ERROR 1062 (23000): Duplicate entry 'NULL' for key 'key0' on CONCAT in sub-query

In Progress

relates to

MDEV-32616 Temporary file space monitoring

Closed

MDEV-32053 New features requested by customer on 2023-08-28

Open

(8 causes, 2 relates to)

Activity

Ascending order - Click to sort in descending order

Valerii Kravchuk added a comment - 2022-10-20 12:26

We have to define the unit of measurement and range of possible values of suggested max_tmp_table_disk_space variable. One can assume that it's in bytes etc, but it may make more sense to define it in percents of free (or total) tmpdir disk space that may be used.

Valerii Kravchuk added a comment - 2022-10-20 12:26 We have to define the unit of measurement and range of possible values of suggested max_tmp_table_disk_space variable. One can assume that it's in bytes etc, but it may make more sense to define it in percents of free (or total) tmpdir disk space that may be used.

Michael Widenius added a comment - 2023-12-27 13:13

For the first version the value will be in bytes as this is needed for testing.
When 'auto' variables are introduced, one should be able to say something like
--tpm-file-usage=auto(30%).

Michael Widenius added a comment - 2023-12-27 13:13 For the first version the value will be in bytes as this is needed for testing. When 'auto' variables are introduced, one should be able to say something like --tpm-file-usage=auto(30%).

Michael Widenius added a comment - 2023-12-29 11:33 - edited

Code is in bb-11.5-monty
Here is the commit message:
~~MDEV-9101~~ Limit size of created disk temporary files and tables

Two new variables added:

max_tmp_space_usage : Limits the the temporary space allowance per user
max_total_tmp_space_usage: Limits the temporary space allowance for
all users.

New status variables: tmp_space_used & max_tmp_space_used
New field in information_schema.process_list: TMP_SPACE_USED

The temporary space is counted for:

All SQL level temporary files. This includes files for filesort,
transaction temporary space, analyze, binlog_stmt_cache etc.
It does not include engine internal temporary files used for repair,
alter table, index pre sorting etc.
All internal on disk temporary tables created as part of resolving a
SELECT, multi-source update etc.

Special cases:

When doing a commit, the last flush of the binlog_stmt_cache
will not cause an error even if the temporary space limit is exceeded.
This is to avoid giving errors on commit. This means that a user
can temporary go over the limit with up to binlog_stmt_cache_size.

Noteworthy issue:

One has to be careful when using small values for max_tmp_space_limit
together with binary logging and with non transactional tables.
If a the binary log entry for the query is bigger than
binlog_stmt_cache_size and one hits the limit of max_tmp_space_limit
when flushing the entry to disk, the query will abort and the
binary log will not contain the last changes to the table.
This is also true for all Aria tables!
One way to avoid it is to use @@binlog_format=statement for
queries that updates a lot of rows.

Implementation:

All writes to temporary files or internal temporary tables, that
increases the file size, are routed through temp_file_size_cb_func()
which updates and checks the temp space usage.
Most of the temporary file monitoring is done inside IO_CACHE.
Temporary file monitoring is done inside the Aria engine.
MY_TRACK and MY_TRACK_WITH_LIMIT are new flags for ini_io_cache().
MY_TRACK means that we track the file usage. TRACK_WITH_LIMIT means
that we track the file usage and we give an error if the limit is
breached. This is used to not give an error on commit when
binlog_stmp_cache is flushed.
global_tmp_space_used contains the total tmp space used so far.
This is needed quickly check against max_total_tmp_space_usage.
Temporary space errors are using EE_LOCAL_TMP_SPACE_FULL and
handler errors are using HA_ERR_LOCAL_TMP_SPACE_FULL.
This is needed until we move general errors to it's own error space
so that they cannot conflict with system error numbers.
Return value of my_chsize() and mysql_file_chsize() has changed
so that -1 is returned in the case my_chsize() could not decrease
the file size (very unlikely and will not happen on modern systems).
All calls to _chsize() are updated to check for > 0 as the error
condition.
At the destruction of THD we check that THD::tmp_file_space == 0
At server end we check that global_tmp_space_used == 0
As a precaution against errors in the tmp_space_used code, one can set
max_tmp_space_usage and max_total_tmp_space_usage to 0 to disable
the tmp space quota errors.
truncate_io_cache() function added.
Aria tables using static or dynamic row length are registered in 8K
increments to avoid some calls to update_tmp_file_size().

Other things:

Ensure that all handler errors are registered. Before, some engine
errors could be printed as "Unknown error".

Michael Widenius added a comment - 2023-12-29 11:33 - edited Code is in bb-11.5-monty Here is the commit message: MDEV-9101 Limit size of created disk temporary files and tables Two new variables added: max_tmp_space_usage : Limits the the temporary space allowance per user max_total_tmp_space_usage: Limits the temporary space allowance for all users. New status variables: tmp_space_used & max_tmp_space_used New field in information_schema.process_list: TMP_SPACE_USED The temporary space is counted for: All SQL level temporary files. This includes files for filesort, transaction temporary space, analyze, binlog_stmt_cache etc. It does not include engine internal temporary files used for repair, alter table, index pre sorting etc. All internal on disk temporary tables created as part of resolving a SELECT, multi-source update etc. Special cases: When doing a commit, the last flush of the binlog_stmt_cache will not cause an error even if the temporary space limit is exceeded. This is to avoid giving errors on commit. This means that a user can temporary go over the limit with up to binlog_stmt_cache_size. Noteworthy issue: One has to be careful when using small values for max_tmp_space_limit together with binary logging and with non transactional tables. If a the binary log entry for the query is bigger than binlog_stmt_cache_size and one hits the limit of max_tmp_space_limit when flushing the entry to disk, the query will abort and the binary log will not contain the last changes to the table. This is also true for all Aria tables! One way to avoid it is to use @@binlog_format=statement for queries that updates a lot of rows. Implementation: All writes to temporary files or internal temporary tables, that increases the file size, are routed through temp_file_size_cb_func() which updates and checks the temp space usage. Most of the temporary file monitoring is done inside IO_CACHE. Temporary file monitoring is done inside the Aria engine. MY_TRACK and MY_TRACK_WITH_LIMIT are new flags for ini_io_cache(). MY_TRACK means that we track the file usage. TRACK_WITH_LIMIT means that we track the file usage and we give an error if the limit is breached. This is used to not give an error on commit when binlog_stmp_cache is flushed. global_tmp_space_used contains the total tmp space used so far. This is needed quickly check against max_total_tmp_space_usage. Temporary space errors are using EE_LOCAL_TMP_SPACE_FULL and handler errors are using HA_ERR_LOCAL_TMP_SPACE_FULL. This is needed until we move general errors to it's own error space so that they cannot conflict with system error numbers. Return value of my_chsize() and mysql_file_chsize() has changed so that -1 is returned in the case my_chsize() could not decrease the file size (very unlikely and will not happen on modern systems). All calls to _chsize() are updated to check for > 0 as the error condition. At the destruction of THD we check that THD::tmp_file_space == 0 At server end we check that global_tmp_space_used == 0 As a precaution against errors in the tmp_space_used code, one can set max_tmp_space_usage and max_total_tmp_space_usage to 0 to disable the tmp space quota errors. truncate_io_cache() function added. Aria tables using static or dynamic row length are registered in 8K increments to avoid some calls to update_tmp_file_size(). Other things: Ensure that all handler errors are registered. Before, some engine errors could be printed as "Unknown error".

Michael Widenius added a comment - 2023-12-30 13:04

Instructions for testing:

The new code will monitor all internal temporary files and tables used indirectly by queries. This includes also any 'disk overflow' of the transaction buffer. If the session or global temporary space limit is reached the query will abort with an error like "Local temporary space limit reached" or "Global temporary space limit reached".
The main thing is to look for asserts as the code has several new DBUG_ASSERT that should hit if anything goes wrong. The asserts are in:
When a temporary file/table grows
When a THD (connection) is deleted
When the server ends.
DDL's (including REPAIR) should not be affected by these limits.
COMMIT should not be affected by these limits (This is the only case when a user can temporary go over the limit with up to binlog_stmt_cache_size bytes).

Things to test (with limited values for @@session.max_tmp_space_usage and @@global.max_total_tmp_space_usage and tmp_memory_table_size (32K for the least on):

Queries that uses filesort or internal temporary tables
Group by/ORDER BY
Sub queries (as these can be stored in temporary tables).
Big transactions with binlog_format=row, binary log on and a small value for binlog_stmt_cache_size (which forces the binary logged transactions to disk).

The main thing that can go 'wrong' for a user is that if the tmp space accounting goes wrong.
If this happens, then the user will get an error for any query that uses a temporary file or temporary table or alternately the size of temporary file/temporary tables he can create gets smaller and smaller.
There are asserts that ensures that the first case should not happen at any time. The second case will be detected by asserts at connection close or server end.

On can check the current state of temporary space usage with:
show session status like "tmp_space_used";
show session status like "max_tmp_space_used";
show global status like "tmp_space_used";
show global status like "max_tmp_space_used";

main/tmp_space_usage.test contains the basic tests that tests most of these conditions.

Michael Widenius added a comment - 2023-12-30 13:04 Instructions for testing: The new code will monitor all internal temporary files and tables used indirectly by queries. This includes also any 'disk overflow' of the transaction buffer. If the session or global temporary space limit is reached the query will abort with an error like "Local temporary space limit reached" or "Global temporary space limit reached". The main thing is to look for asserts as the code has several new DBUG_ASSERT that should hit if anything goes wrong. The asserts are in: When a temporary file/table grows When a THD (connection) is deleted When the server ends. DDL's (including REPAIR) should not be affected by these limits. COMMIT should not be affected by these limits (This is the only case when a user can temporary go over the limit with up to binlog_stmt_cache_size bytes). Things to test (with limited values for @@session.max_tmp_space_usage and @@global.max_total_tmp_space_usage and tmp_memory_table_size (32K for the least on): Queries that uses filesort or internal temporary tables Group by/ORDER BY Sub queries (as these can be stored in temporary tables). Big transactions with binlog_format=row, binary log on and a small value for binlog_stmt_cache_size (which forces the binary logged transactions to disk). The main thing that can go 'wrong' for a user is that if the tmp space accounting goes wrong. If this happens, then the user will get an error for any query that uses a temporary file or temporary table or alternately the size of temporary file/temporary tables he can create gets smaller and smaller. There are asserts that ensures that the first case should not happen at any time. The second case will be detected by asserts at connection close or server end. On can check the current state of temporary space usage with: show session status like "tmp_space_used"; show session status like "max_tmp_space_used"; show global status like "tmp_space_used"; show global status like "max_tmp_space_used"; main/tmp_space_usage.test contains the basic tests that tests most of these conditions.

Elena Stepanova added a comment - 2024-01-02 12:44

The variables cannot be set to 32K, the minimal value, at least on my 64-bit build, is 64K (or zero).
Unfortunately if a lower value is set upon startup, no warning is written to the error log, the value is silently adjusted to 0, which may remain unnoticed.
If the value is set at runtime, a warning is produced.

Elena Stepanova added a comment - 2024-01-02 12:44 The variables cannot be set to 32K, the minimal value, at least on my 64-bit build, is 64K (or zero). Unfortunately if a lower value is set upon startup, no warning is written to the error log, the value is silently adjusted to 0, which may remain unnoticed. If the value is set at runtime, a warning is produced.

Elena Stepanova added a comment - 2024-01-02 15:24 - edited

--source include/have_sequence.inc

SET max_tmp_space_usage= 64*1024;

CREATE OR REPLACE TABLE t (a INT, b INT);

INSERT INTO t SELECT seq, seq FROM seq_1_to_100000;

ALTER TABLE t ORDER BY a, b;

# Cleanup

DROP TABLE t;

bb-11.5-monty a348b87e59b861467df20ad0e0060d53afd03258
mariadbd: /data/bld/bb-11.5-monty/sql/handler.cc:7372: int handler::ha_external_lock(THD*, int): Assertion `inited == NONE \|\| table->open_by_handler' failed.
240102 17:23:27 [ERROR] mysqld got signal 6 ;

#8 0x00007f9cbee45395 in __assert_fail_base (fmt=0x7f9cbefb9a90 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x560a18a12b00 "inited == NONE \|\| table->open_by_handler", file=file@entry=0x560a18a08860 "/data/bld/bb-11.5-monty/sql/handler.cc", line=line@entry=7372, function=function@entry=0x560a18a12960 "int handler::ha_external_lock(THD*, int)") at ./assert/assert.c:92
#9 0x00007f9cbee53e32 in __GI___assert_fail (assertion=0x560a18a12b00 "inited == NONE \|\| table->open_by_handler", file=0x560a18a08860 "/data/bld/bb-11.5-monty/sql/handler.cc", line=7372, function=0x560a18a12960 "int handler::ha_external_lock(THD*, int)") at ./assert/assert.c:101
#10 0x0000560a16d61971 in handler::ha_external_lock (this=0x61d0002328b8, thd=0x62c0000c0218, lock_type=2) at /data/bld/bb-11.5-monty/sql/handler.cc:7372
#11 0x0000560a160dc2f6 in handler::ha_external_unlock (this=0x61d0002328b8, thd=0x62c0000c0218) at /data/bld/bb-11.5-monty/sql/handler.h:3557
#12 0x0000560a170be569 in unlock_external (thd=0x62c0000c0218, table=0x60700001e7c8, count=1) at /data/bld/bb-11.5-monty/sql/lock.cc:744
#13 0x0000560a170bbc57 in mysql_unlock_tables (thd=0x62c0000c0218, sql_lock=0x60700001e798, free_lock=true) at /data/bld/bb-11.5-monty/sql/lock.cc:435
#14 0x0000560a170bba90 in mysql_unlock_tables (thd=0x62c0000c0218, sql_lock=0x60700001e798) at /data/bld/bb-11.5-monty/sql/lock.cc:418
#15 0x0000560a1622f647 in close_thread_tables (thd=0x62c0000c0218) at /data/bld/bb-11.5-monty/sql/sql_base.cc:966
#16 0x0000560a1622e864 in close_thread_tables_for_query (thd=0x62c0000c0218) at /data/bld/bb-11.5-monty/sql/sql_base.cc:795
#17 0x0000560a163ff558 in mysql_execute_command (thd=0x62c0000c0218, is_called_from_prepared_stmt=false) at /data/bld/bb-11.5-monty/sql/sql_parse.cc:5881
#18 0x0000560a1640c23b in mysql_parse (thd=0x62c0000c0218, rawbuf=0x6290000e6238 "ALTER TABLE t ORDER BY a, b", length=27, parser_state=0x7f9cb50ff9f0) at /data/bld/bb-11.5-monty/sql/sql_parse.cc:7800
#19 0x0000560a163e3844 in dispatch_command (command=COM_QUERY, thd=0x62c0000c0218, packet=0x629000249219 "ALTER TABLE t ORDER BY a, b", packet_length=27, blocking=true) at /data/bld/bb-11.5-monty/sql/sql_parse.cc:1893
#20 0x0000560a163e057c in do_command (thd=0x62c0000c0218, blocking=true) at /data/bld/bb-11.5-monty/sql/sql_parse.cc:1406
#21 0x0000560a168b24f5 in do_handle_one_connection (connect=0x608000002eb8, put_in_cache=true) at /data/bld/bb-11.5-monty/sql/sql_connect.cc:1419
#22 0x0000560a168b1eb6 in handle_one_connection (arg=0x608000002e38) at /data/bld/bb-11.5-monty/sql/sql_connect.cc:1321
#23 0x0000560a174da918 in pfs_spawn_thread (arg=0x617000005b98) at /data/bld/bb-11.5-monty/storage/perfschema/pfs.cc:2201
#24 0x00007f9cbeea8044 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#25 0x00007f9cbef2861c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Update: The assertion failure was fixed, the ALTER query fails with (41): Local temporary space limit reached instead.

Elena Stepanova added a comment - 2024-01-02 15:24 - edited --source include/have_sequence.inc SET max_tmp_space_usage= 64*1024; CREATE OR REPLACE TABLE t (a INT , b INT ); INSERT INTO t SELECT seq, seq FROM seq_1_to_100000; ALTER TABLE t ORDER BY a, b; # Cleanup DROP TABLE t; bb-11.5-monty a348b87e59b861467df20ad0e0060d53afd03258 mariadbd: /data/bld/bb-11.5-monty/sql/handler.cc:7372: int handler::ha_external_lock(THD*, int): Assertion `inited == NONE || table->open_by_handler' failed. 240102 17:23:27 [ERROR] mysqld got signal 6 ; #8 0x00007f9cbee45395 in __assert_fail_base (fmt=0x7f9cbefb9a90 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x560a18a12b00 "inited == NONE || table->open_by_handler", file=file@entry=0x560a18a08860 "/data/bld/bb-11.5-monty/sql/handler.cc", line=line@entry=7372, function=function@entry=0x560a18a12960 "int handler::ha_external_lock(THD*, int)") at ./assert/assert.c:92 #9 0x00007f9cbee53e32 in __GI___assert_fail (assertion=0x560a18a12b00 "inited == NONE || table->open_by_handler", file=0x560a18a08860 "/data/bld/bb-11.5-monty/sql/handler.cc", line=7372, function=0x560a18a12960 "int handler::ha_external_lock(THD*, int)") at ./assert/assert.c:101 #10 0x0000560a16d61971 in handler::ha_external_lock (this=0x61d0002328b8, thd=0x62c0000c0218, lock_type=2) at /data/bld/bb-11.5-monty/sql/handler.cc:7372 #11 0x0000560a160dc2f6 in handler::ha_external_unlock (this=0x61d0002328b8, thd=0x62c0000c0218) at /data/bld/bb-11.5-monty/sql/handler.h:3557 #12 0x0000560a170be569 in unlock_external (thd=0x62c0000c0218, table=0x60700001e7c8, count=1) at /data/bld/bb-11.5-monty/sql/lock.cc:744 #13 0x0000560a170bbc57 in mysql_unlock_tables (thd=0x62c0000c0218, sql_lock=0x60700001e798, free_lock=true) at /data/bld/bb-11.5-monty/sql/lock.cc:435 #14 0x0000560a170bba90 in mysql_unlock_tables (thd=0x62c0000c0218, sql_lock=0x60700001e798) at /data/bld/bb-11.5-monty/sql/lock.cc:418 #15 0x0000560a1622f647 in close_thread_tables (thd=0x62c0000c0218) at /data/bld/bb-11.5-monty/sql/sql_base.cc:966 #16 0x0000560a1622e864 in close_thread_tables_for_query (thd=0x62c0000c0218) at /data/bld/bb-11.5-monty/sql/sql_base.cc:795 #17 0x0000560a163ff558 in mysql_execute_command (thd=0x62c0000c0218, is_called_from_prepared_stmt=false) at /data/bld/bb-11.5-monty/sql/sql_parse.cc:5881 #18 0x0000560a1640c23b in mysql_parse (thd=0x62c0000c0218, rawbuf=0x6290000e6238 "ALTER TABLE t ORDER BY a, b", length=27, parser_state=0x7f9cb50ff9f0) at /data/bld/bb-11.5-monty/sql/sql_parse.cc:7800 #19 0x0000560a163e3844 in dispatch_command (command=COM_QUERY, thd=0x62c0000c0218, packet=0x629000249219 "ALTER TABLE t ORDER BY a, b", packet_length=27, blocking=true) at /data/bld/bb-11.5-monty/sql/sql_parse.cc:1893 #20 0x0000560a163e057c in do_command (thd=0x62c0000c0218, blocking=true) at /data/bld/bb-11.5-monty/sql/sql_parse.cc:1406 #21 0x0000560a168b24f5 in do_handle_one_connection (connect=0x608000002eb8, put_in_cache=true) at /data/bld/bb-11.5-monty/sql/sql_connect.cc:1419 #22 0x0000560a168b1eb6 in handle_one_connection (arg=0x608000002e38) at /data/bld/bb-11.5-monty/sql/sql_connect.cc:1321 #23 0x0000560a174da918 in pfs_spawn_thread (arg=0x617000005b98) at /data/bld/bb-11.5-monty/storage/perfschema/pfs.cc:2201 #24 0x00007f9cbeea8044 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442 #25 0x00007f9cbef2861c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81 Update: The assertion failure was fixed, the ALTER query fails with (41): Local temporary space limit reached instead.

Elena Stepanova added a comment - 2024-01-05 13:30

This has been fixed, but since a test case couldn't be added to the regression suite, I'll keep the original draft one here for the record: mdev9101-2.test.

bb-11.5-monty 4ded10401
mariadbd: /data/bld/bb-11.5-monty-asan/sql/log_cache.h:270: void binlog_cache_data::truncate(my_off_t, bool): Assertion `res == 0' failed.
240105 15:13:22 [ERROR] mysqld got signal 6 ;

#9 0x00007fe9f2e53e32 in __GI___assert_fail (assertion=0x5604e70f5ba0 "res == 0", file=0x5604e70f57c0 "/data/bld/bb-11.5-monty-asan/sql/log_cache.h", line=270, function=0x5604e70f5be0 "void binlog_cache_data::truncate(my_off_t, bool)") at ./assert/assert.c:101
#10 0x00005604e56de2e8 in binlog_cache_data::truncate (this=0x61b0000b0050, pos=65247, reset_cache=false) at /data/bld/bb-11.5-monty-asan/sql/log_cache.h:270
#11 0x00005604e56dda3a in binlog_cache_data::restore_prev_position (this=0x61b0000b0050) at /data/bld/bb-11.5-monty-asan/sql/log_cache.h:129
#12 0x00005604e5698990 in binlog_truncate_trx_cache (thd=0x62c0002c0218, cache_mngr=0x61b0000afe98, all=false) at /data/bld/bb-11.5-monty-asan/sql/log.cc:1907
#13 0x00005604e569b4f1 in binlog_rollback (hton=0x615000001998, thd=0x62c0002c0218, all=false) at /data/bld/bb-11.5-monty-asan/sql/log.cc:2270
#14 0x00005604e535ab73 in ha_rollback_trans (thd=0x62c0002c0218, all=false) at /data/bld/bb-11.5-monty-asan/sql/handler.cc:2274
#15 0x00005604e4f1f5ec in trans_rollback_stmt (thd=0x62c0002c0218) at /data/bld/bb-11.5-monty-asan/sql/transaction.cc:535
#16 0x00005604e4a254d3 in mysql_execute_command (thd=0x62c0002c0218, is_called_from_prepared_stmt=false) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:5868
#17 0x00005604e4a3223b in mysql_parse (thd=0x62c0002c0218, rawbuf=0x6290006f9238 "/* WRK-1 QNO 37307 */ INSERT INTO partsupp ( ps_partkey, ps_suppkey, ps_availqty, ps_supplycost, ps_comment ) SELECT 219, ps_suppkey, ps_availqty, ps_supplycost, ps_comment FROM partsupp WHERE ps_sup"..., length=281, parser_state=0x7fe9de2c59f0) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:7800
#18 0x00005604e4a09844 in dispatch_command (command=COM_QUERY, thd=0x62c0002c0218, packet=0x6290006ef219 "/* WRK-1 QNO 37307 */ INSERT INTO partsupp ( ps_partkey, ps_suppkey, ps_availqty, ps_supplycost, ps_comment ) SELECT 219, ps_suppkey, ps_availqty, ps_supplycost, ps_comment FROM partsupp WHERE ps_sup"..., packet_length=281, blocking=true) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:1893
#19 0x00005604e4a0657c in do_command (thd=0x62c0002c0218, blocking=true) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:1406
#20 0x00005604e4ed84f5 in do_handle_one_connection (connect=0x608000003eb8, put_in_cache=true) at /data/bld/bb-11.5-monty-asan/sql/sql_connect.cc:1419
#21 0x00005604e4ed7eb6 in handle_one_connection (arg=0x608000003eb8) at /data/bld/bb-11.5-monty-asan/sql/sql_connect.cc:1321
#22 0x00005604e5b00a50 in pfs_spawn_thread (arg=0x61700000a518) at /data/bld/bb-11.5-monty-asan/storage/perfschema/pfs.cc:2201
#23 0x00007fe9f2ea8044 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#24 0x00007fe9f2f2861c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Elena Stepanova added a comment - 2024-01-05 13:30 This has been fixed, but since a test case couldn't be added to the regression suite, I'll keep the original draft one here for the record: mdev9101-2.test . bb-11.5-monty 4ded10401 mariadbd: /data/bld/bb-11.5-monty-asan/sql/log_cache.h:270: void binlog_cache_data::truncate(my_off_t, bool): Assertion `res == 0' failed. 240105 15:13:22 [ERROR] mysqld got signal 6 ; #9 0x00007fe9f2e53e32 in __GI___assert_fail (assertion=0x5604e70f5ba0 "res == 0", file=0x5604e70f57c0 "/data/bld/bb-11.5-monty-asan/sql/log_cache.h", line=270, function=0x5604e70f5be0 "void binlog_cache_data::truncate(my_off_t, bool)") at ./assert/assert.c:101 #10 0x00005604e56de2e8 in binlog_cache_data::truncate (this=0x61b0000b0050, pos=65247, reset_cache=false) at /data/bld/bb-11.5-monty-asan/sql/log_cache.h:270 #11 0x00005604e56dda3a in binlog_cache_data::restore_prev_position (this=0x61b0000b0050) at /data/bld/bb-11.5-monty-asan/sql/log_cache.h:129 #12 0x00005604e5698990 in binlog_truncate_trx_cache (thd=0x62c0002c0218, cache_mngr=0x61b0000afe98, all=false) at /data/bld/bb-11.5-monty-asan/sql/log.cc:1907 #13 0x00005604e569b4f1 in binlog_rollback (hton=0x615000001998, thd=0x62c0002c0218, all=false) at /data/bld/bb-11.5-monty-asan/sql/log.cc:2270 #14 0x00005604e535ab73 in ha_rollback_trans (thd=0x62c0002c0218, all=false) at /data/bld/bb-11.5-monty-asan/sql/handler.cc:2274 #15 0x00005604e4f1f5ec in trans_rollback_stmt (thd=0x62c0002c0218) at /data/bld/bb-11.5-monty-asan/sql/transaction.cc:535 #16 0x00005604e4a254d3 in mysql_execute_command (thd=0x62c0002c0218, is_called_from_prepared_stmt=false) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:5868 #17 0x00005604e4a3223b in mysql_parse (thd=0x62c0002c0218, rawbuf=0x6290006f9238 "/* WRK-1 QNO 37307 */ INSERT INTO partsupp ( ps_partkey, ps_suppkey, ps_availqty, ps_supplycost, ps_comment ) SELECT 219, ps_suppkey, ps_availqty, ps_supplycost, ps_comment FROM partsupp WHERE ps_sup"..., length=281, parser_state=0x7fe9de2c59f0) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:7800 #18 0x00005604e4a09844 in dispatch_command (command=COM_QUERY, thd=0x62c0002c0218, packet=0x6290006ef219 "/* WRK-1 QNO 37307 */ INSERT INTO partsupp ( ps_partkey, ps_suppkey, ps_availqty, ps_supplycost, ps_comment ) SELECT 219, ps_suppkey, ps_availqty, ps_supplycost, ps_comment FROM partsupp WHERE ps_sup"..., packet_length=281, blocking=true) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:1893 #19 0x00005604e4a0657c in do_command (thd=0x62c0002c0218, blocking=true) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:1406 #20 0x00005604e4ed84f5 in do_handle_one_connection (connect=0x608000003eb8, put_in_cache=true) at /data/bld/bb-11.5-monty-asan/sql/sql_connect.cc:1419 #21 0x00005604e4ed7eb6 in handle_one_connection (arg=0x608000003eb8) at /data/bld/bb-11.5-monty-asan/sql/sql_connect.cc:1321 #22 0x00005604e5b00a50 in pfs_spawn_thread (arg=0x61700000a518) at /data/bld/bb-11.5-monty-asan/storage/perfschema/pfs.cc:2201 #23 0x00007fe9f2ea8044 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442 #24 0x00007fe9f2f2861c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Elena Stepanova added a comment - 2024-01-05 17:51 - edited

mdev9101-3.test

bb-11.5-monty db02271baeabb196e66421626d85333289caca6e
2024-01-05 19:44:21 4 [ERROR] mariadbd: Got error '200 "Local temporary space limit reached"' for '#sql-temptable-200541-4-51.MAI'
mariadbd: /data/bld/bb-11.5-monty-asan/storage/maria/ma_blockrec.h:143: ma_recordpos: Assertion `dir_entry <= 255' failed.
240105 19:44:21 [ERROR] mysqld got signal 6 ;

#9 0x00007f812e053e32 in __GI___assert_fail (assertion=0x5643577c6240 "dir_entry <= 255", file=0x5643577c6280 "/data/bld/bb-11.5-monty-asan/storage/maria/ma_blockrec.h", line=143, function=0x5643577cc200 <__PRETTY_FUNCTION__.33> "ma_recordpos") at ./assert/assert.c:101
#10 0x0000564355f25e54 in ma_recordpos (page=8, dir_entry=16383) at /data/bld/bb-11.5-monty-asan/storage/maria/ma_blockrec.h:143
#11 0x0000564355f44aa7 in read_next_extent (info=0x6290003a7218, extent=0x7f811fb20ae0, end_of_data=0x7f811fb20a80) at /data/bld/bb-11.5-monty-asan/storage/maria/ma_blockrec.c:4619
#12 0x0000564355f469cf in _ma_read_block_record2 (info=0x6290003a7218, record=0x619000234868 "\360\003", data=0x6290003a8304 "", end_of_data=0x6290003a8304 "") at /data/bld/bb-11.5-monty-asan/storage/maria/ma_blockrec.c:4875
#13 0x0000564355f49949 in _ma_read_block_record (info=0x6290003a7218, record=0x619000234868 "\360\003", record_pos=284) at /data/bld/bb-11.5-monty-asan/storage/maria/ma_blockrec.c:5226
#14 0x0000564355f13de6 in maria_rrnd (info=0x6290003a7218, buf=0x619000234868 "\360\003", filepos=284) at /data/bld/bb-11.5-monty-asan/storage/maria/ma_rrnd.c:44
#15 0x0000564355e1e32e in ha_maria::rnd_pos (this=0x61d000645ab8, buf=0x619000234868 "\360\003", pos=0x61d00064a8b7 "") at /data/bld/bb-11.5-monty-asan/storage/maria/ha_maria.cc:2686
#16 0x000056435590936a in handler::ha_rnd_pos (this=0x61d000645ab8, buf=0x619000234868 "\360\003", pos=0x61d00064a8b7 "") at /data/bld/bb-11.5-monty-asan/sql/handler.cc:3671
#17 0x00005643556f34b8 in Table_read_cursor::fetch (this=0x62f00002e6b0) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:980
#18 0x00005643556f8247 in Frame_scan_cursor::compute_values_for_current_row (this=0x62f00002e678) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:2277
#19 0x00005643556f7f4b in Frame_scan_cursor::next_row (this=0x62f00002e678) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:2247
#20 0x00005643556f44a3 in Cursor_manager::notify_cursors_next_row (this=0x60300006f610) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:1247
#21 0x00005643556ef415 in compute_window_func (thd=0x62c0001f0218, window_functions=..., cursor_managers=..., tbl=0x621000186138, filesort_result=0x616000f1dd80) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:2917
#22 0x00005643556efc43 in Window_func_runner::exec (this=0x62d00036e080, thd=0x62c0001f0218, tbl=0x621000186138, filesort_result=0x616000f1dd80) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:3045
#23 0x00005643556efe62 in Window_funcs_sort::exec (this=0x62d00036e078, join=0x62d0003368d0, keep_filesort_result=true) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:3073
#24 0x00005643556f0cc7 in Window_funcs_computation::exec (this=0x62d00036e050, join=0x62d0003368d0, keep_last_filesort_result=true) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:3202
#25 0x00005643551985de in AGGR_OP::end_send (this=0x62d00036d980) at /data/bld/bb-11.5-monty-asan/sql/sql_select.cc:32539
#26 0x0000564355155bb6 in sub_select_postjoin_aggr (join=0x62d0003368d0, join_tab=0x62d00036c6b8, end_of_records=true) at /data/bld/bb-11.5-monty-asan/sql/sql_select.cc:23284
#27 0x0000564355156712 in sub_select (join=0x62d0003368d0, join_tab=0x62d00036c248, end_of_records=true) at /data/bld/bb-11.5-monty-asan/sql/sql_select.cc:23539
#28 0x0000564355154bbb in do_select (join=0x62d0003368d0, procedure=0x0) at /data/bld/bb-11.5-monty-asan/sql/sql_select.cc:23119
#29 0x00005643550d364f in JOIN::exec_inner (this=0x62d0003368d0) at /data/bld/bb-11.5-monty-asan/sql/sql_select.cc:4988
#30 0x00005643550d0a6e in JOIN::exec (this=0x62d0003368d0) at /data/bld/bb-11.5-monty-asan/sql/sql_select.cc:4774
#31 0x000056435531b756 in st_select_lex_unit::exec_inner (this=0x62c0001f46e0) at /data/bld/bb-11.5-monty-asan/sql/sql_union.cc:2388
#32 0x000056435531a210 in st_select_lex_unit::exec (this=0x62c0001f46e0) at /data/bld/bb-11.5-monty-asan/sql/sql_union.cc:2292
#33 0x0000564355305e2c in mysql_union (thd=0x62c0001f0218, lex=0x62c0001f4600, result=0x62d0003367a8, unit=0x62c0001f46e0, setup_tables_done_option=0) at /data/bld/bb-11.5-monty-asan/sql/sql_union.cc:45
#34 0x00005643550a3c66 in handle_select (thd=0x62c0001f0218, lex=0x62c0001f4600, result=0x62d0003367a8, setup_tables_done_option=0) at /data/bld/bb-11.5-monty-asan/sql/sql_select.cc:620
#35 0x0000564354fc93d1 in execute_sqlcom_select (thd=0x62c0001f0218, all_tables=0x62900010b460) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:6080
#36 0x0000564354fb96e3 in mysql_execute_command (thd=0x62c0001f0218, is_called_from_prepared_stmt=false) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:3928
#37 0x0000564354fd423b in mysql_parse (thd=0x62c0001f0218, rawbuf=0x629000109238 "(SELECT VAR_POP(write_pct) OVER (), MIN(count_write) OVER (), FIRST_VALUE(count_write) OVER (), BIT_OR(avg_write) OVER (), ROW_NUMBER() OVER (ORDER BY count_read ASC) FROM sys.io_global_by_file_by_byt"..., length=413, parser_state=0x7f811fb239f0) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:7800
#38 0x0000564354fab844 in dispatch_command (command=COM_QUERY, thd=0x62c0001f0218, packet=0x629000285219 "(SELECT VAR_POP(write_pct) OVER (), MIN(count_write) OVER (), FIRST_VALUE(count_write) OVER (), BIT_OR(avg_write) OVER (), ROW_NUMBER() OVER (ORDER BY count_read ASC) FROM sys.io_global_by_file_by_byt"..., packet_length=413, blocking=true) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:1893
#39 0x0000564354fa857c in do_command (thd=0x62c0001f0218, blocking=true) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:1406
#40 0x000056435547a505 in do_handle_one_connection (connect=0x608000003938, put_in_cache=true) at /data/bld/bb-11.5-monty-asan/sql/sql_connect.cc:1419
#41 0x0000564355479ec6 in handle_one_connection (arg=0x6080000038b8) at /data/bld/bb-11.5-monty-asan/sql/sql_connect.cc:1321
#42 0x00005643560a2ace in pfs_spawn_thread (arg=0x617000008598) at /data/bld/bb-11.5-monty-asan/storage/perfschema/pfs.cc:2201
#43 0x00007f812e0a8044 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#44 0x00007f812e12861c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Update: The assertion failure was fixed.

Elena Stepanova added a comment - 2024-01-05 17:51 - edited mdev9101-3.test bb-11.5-monty db02271baeabb196e66421626d85333289caca6e 2024-01-05 19:44:21 4 [ERROR] mariadbd: Got error '200 "Local temporary space limit reached"' for '#sql-temptable-200541-4-51.MAI' mariadbd: /data/bld/bb-11.5-monty-asan/storage/maria/ma_blockrec.h:143: ma_recordpos: Assertion `dir_entry <= 255' failed. 240105 19:44:21 [ERROR] mysqld got signal 6 ; #9 0x00007f812e053e32 in __GI___assert_fail (assertion=0x5643577c6240 "dir_entry <= 255", file=0x5643577c6280 "/data/bld/bb-11.5-monty-asan/storage/maria/ma_blockrec.h", line=143, function=0x5643577cc200 <__PRETTY_FUNCTION__.33> "ma_recordpos") at ./assert/assert.c:101 #10 0x0000564355f25e54 in ma_recordpos (page=8, dir_entry=16383) at /data/bld/bb-11.5-monty-asan/storage/maria/ma_blockrec.h:143 #11 0x0000564355f44aa7 in read_next_extent (info=0x6290003a7218, extent=0x7f811fb20ae0, end_of_data=0x7f811fb20a80) at /data/bld/bb-11.5-monty-asan/storage/maria/ma_blockrec.c:4619 #12 0x0000564355f469cf in _ma_read_block_record2 (info=0x6290003a7218, record=0x619000234868 "\360\003", data=0x6290003a8304 "", end_of_data=0x6290003a8304 "") at /data/bld/bb-11.5-monty-asan/storage/maria/ma_blockrec.c:4875 #13 0x0000564355f49949 in _ma_read_block_record (info=0x6290003a7218, record=0x619000234868 "\360\003", record_pos=284) at /data/bld/bb-11.5-monty-asan/storage/maria/ma_blockrec.c:5226 #14 0x0000564355f13de6 in maria_rrnd (info=0x6290003a7218, buf=0x619000234868 "\360\003", filepos=284) at /data/bld/bb-11.5-monty-asan/storage/maria/ma_rrnd.c:44 #15 0x0000564355e1e32e in ha_maria::rnd_pos (this=0x61d000645ab8, buf=0x619000234868 "\360\003", pos=0x61d00064a8b7 "") at /data/bld/bb-11.5-monty-asan/storage/maria/ha_maria.cc:2686 #16 0x000056435590936a in handler::ha_rnd_pos (this=0x61d000645ab8, buf=0x619000234868 "\360\003", pos=0x61d00064a8b7 "") at /data/bld/bb-11.5-monty-asan/sql/handler.cc:3671 #17 0x00005643556f34b8 in Table_read_cursor::fetch (this=0x62f00002e6b0) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:980 #18 0x00005643556f8247 in Frame_scan_cursor::compute_values_for_current_row (this=0x62f00002e678) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:2277 #19 0x00005643556f7f4b in Frame_scan_cursor::next_row (this=0x62f00002e678) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:2247 #20 0x00005643556f44a3 in Cursor_manager::notify_cursors_next_row (this=0x60300006f610) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:1247 #21 0x00005643556ef415 in compute_window_func (thd=0x62c0001f0218, window_functions=..., cursor_managers=..., tbl=0x621000186138, filesort_result=0x616000f1dd80) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:2917 #22 0x00005643556efc43 in Window_func_runner::exec (this=0x62d00036e080, thd=0x62c0001f0218, tbl=0x621000186138, filesort_result=0x616000f1dd80) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:3045 #23 0x00005643556efe62 in Window_funcs_sort::exec (this=0x62d00036e078, join=0x62d0003368d0, keep_filesort_result=true) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:3073 #24 0x00005643556f0cc7 in Window_funcs_computation::exec (this=0x62d00036e050, join=0x62d0003368d0, keep_last_filesort_result=true) at /data/bld/bb-11.5-monty-asan/sql/sql_window.cc:3202 #25 0x00005643551985de in AGGR_OP::end_send (this=0x62d00036d980) at /data/bld/bb-11.5-monty-asan/sql/sql_select.cc:32539 #26 0x0000564355155bb6 in sub_select_postjoin_aggr (join=0x62d0003368d0, join_tab=0x62d00036c6b8, end_of_records=true) at /data/bld/bb-11.5-monty-asan/sql/sql_select.cc:23284 #27 0x0000564355156712 in sub_select (join=0x62d0003368d0, join_tab=0x62d00036c248, end_of_records=true) at /data/bld/bb-11.5-monty-asan/sql/sql_select.cc:23539 #28 0x0000564355154bbb in do_select (join=0x62d0003368d0, procedure=0x0) at /data/bld/bb-11.5-monty-asan/sql/sql_select.cc:23119 #29 0x00005643550d364f in JOIN::exec_inner (this=0x62d0003368d0) at /data/bld/bb-11.5-monty-asan/sql/sql_select.cc:4988 #30 0x00005643550d0a6e in JOIN::exec (this=0x62d0003368d0) at /data/bld/bb-11.5-monty-asan/sql/sql_select.cc:4774 #31 0x000056435531b756 in st_select_lex_unit::exec_inner (this=0x62c0001f46e0) at /data/bld/bb-11.5-monty-asan/sql/sql_union.cc:2388 #32 0x000056435531a210 in st_select_lex_unit::exec (this=0x62c0001f46e0) at /data/bld/bb-11.5-monty-asan/sql/sql_union.cc:2292 #33 0x0000564355305e2c in mysql_union (thd=0x62c0001f0218, lex=0x62c0001f4600, result=0x62d0003367a8, unit=0x62c0001f46e0, setup_tables_done_option=0) at /data/bld/bb-11.5-monty-asan/sql/sql_union.cc:45 #34 0x00005643550a3c66 in handle_select (thd=0x62c0001f0218, lex=0x62c0001f4600, result=0x62d0003367a8, setup_tables_done_option=0) at /data/bld/bb-11.5-monty-asan/sql/sql_select.cc:620 #35 0x0000564354fc93d1 in execute_sqlcom_select (thd=0x62c0001f0218, all_tables=0x62900010b460) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:6080 #36 0x0000564354fb96e3 in mysql_execute_command (thd=0x62c0001f0218, is_called_from_prepared_stmt=false) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:3928 #37 0x0000564354fd423b in mysql_parse (thd=0x62c0001f0218, rawbuf=0x629000109238 "(SELECT VAR_POP(write_pct) OVER (), MIN(count_write) OVER (), FIRST_VALUE(count_write) OVER (), BIT_OR(avg_write) OVER (), ROW_NUMBER() OVER (ORDER BY count_read ASC) FROM sys.io_global_by_file_by_byt"..., length=413, parser_state=0x7f811fb239f0) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:7800 #38 0x0000564354fab844 in dispatch_command (command=COM_QUERY, thd=0x62c0001f0218, packet=0x629000285219 "(SELECT VAR_POP(write_pct) OVER (), MIN(count_write) OVER (), FIRST_VALUE(count_write) OVER (), BIT_OR(avg_write) OVER (), ROW_NUMBER() OVER (ORDER BY count_read ASC) FROM sys.io_global_by_file_by_byt"..., packet_length=413, blocking=true) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:1893 #39 0x0000564354fa857c in do_command (thd=0x62c0001f0218, blocking=true) at /data/bld/bb-11.5-monty-asan/sql/sql_parse.cc:1406 #40 0x000056435547a505 in do_handle_one_connection (connect=0x608000003938, put_in_cache=true) at /data/bld/bb-11.5-monty-asan/sql/sql_connect.cc:1419 #41 0x0000564355479ec6 in handle_one_connection (arg=0x6080000038b8) at /data/bld/bb-11.5-monty-asan/sql/sql_connect.cc:1321 #42 0x00005643560a2ace in pfs_spawn_thread (arg=0x617000008598) at /data/bld/bb-11.5-monty-asan/storage/perfschema/pfs.cc:2201 #43 0x00007f812e0a8044 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442 #44 0x00007f812e12861c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81 Update: The assertion failure was fixed.

Elena Stepanova added a comment - 2024-01-05 18:42 - edited

mdev9101-4.test

The test case contains one CREATE and one (big) INSERT, executed with binary logging enabled under SET max_tmp_space_usage=64*1024.
INSERT ends with error "Local temporary space limit reached" which is probably expected, but then the following is written into the error log:

bb-11.5-monty db02271baeabb196e66421626d85333289caca6e
[ERROR] Write to binary log failed: Local temporary space limit reached. An incident event is written to binary log and slave will be stopped.

According to previous discussions, this is not expected.
If SET is changed from the local to the global "total" variable, the error correspondingly converts to "Global temporary space limit reached", otherwise the effect is the same.

Update:
This was analyzed and decided to be unavoidable. It is described in the commit message in the section "Noteworthy issue", and should be probably later mentioned in the documentation as well.

Elena Stepanova added a comment - 2024-01-05 18:42 - edited mdev9101-4.test The test case contains one CREATE and one (big) INSERT, executed with binary logging enabled under SET max_tmp_space_usage=64*1024 . INSERT ends with error "Local temporary space limit reached" which is probably expected, but then the following is written into the error log: bb-11.5-monty db02271baeabb196e66421626d85333289caca6e [ERROR] Write to binary log failed: Local temporary space limit reached. An incident event is written to binary log and slave will be stopped. According to previous discussions, this is not expected. If SET is changed from the local to the global "total" variable, the error correspondingly converts to "Global temporary space limit reached", otherwise the effect is the same. Update: This was analyzed and decided to be unavoidable. It is described in the commit message in the section "Noteworthy issue", and should be probably later mentioned in the documentation as well.

Elena Stepanova added a comment - 2024-01-08 19:34 - edited

mdev9101-5.test

The test case sets slave_parallel_threads=4 and max_total_tmp_space_usage=64K on the slave, creates an InnoDB table on the master and runs a fairly big transaction consisting of several INSERT statements, all in RBR mode. The slave fails with

bb-11.5-monty 28be348cb8cce71461da0dff09245a645196a647
mariadbd: /data/bld/bb-11.5-monty-asan/sql/log.cc:2242: int binlog_rollback(handlerton, THD, bool): Assertion `!all' failed.
240108 21:29:48 [ERROR] mysqld got signal 6 ;

#9 0x00007f70ca253e32 in __GI___assert_fail (assertion=0x55a2178bf180 "!all", file=0x55a2178bc360 "/data/bld/bb-11.5-monty-asan/sql/log.cc", line=2242, function=0x55a2178bf040 "int binlog_rollback(handlerton, THD, bool)") at ./assert/assert.c:101
#10 0x000055a215e61436 in binlog_rollback (hton=0x615000001998, thd=0x62c0002b0218, all=true) at /data/bld/bb-11.5-monty-asan/sql/log.cc:2242
#11 0x000055a215b20cc1 in ha_rollback_trans (thd=0x62c0002b0218, all=true) at /data/bld/bb-11.5-monty-asan/sql/handler.cc:2274
#12 0x000055a2156e3fea in trans_rollback (thd=0x62c0002b0218) at /data/bld/bb-11.5-monty-asan/sql/transaction.cc:372
#13 0x000055a215677e0b in rpl_group_info::cleanup_context (this=0x61d00038a480, thd=0x62c0002b0218, error=true) at /data/bld/bb-11.5-monty-asan/sql/rpl_rli.cc:2275
#14 0x000055a21585fa42 in signal_error_to_sql_driver_thread (thd=0x62c0002b0218, rgi=0x61d00038a480, err=1) at /data/bld/bb-11.5-monty-asan/sql/rpl_parallel.cc:332
#15 0x000055a21586747e in handle_rpl_parallel_thread (arg=0x624000163688) at /data/bld/bb-11.5-monty-asan/sql/rpl_parallel.cc:1578
#16 0x000055a2162c6c62 in pfs_spawn_thread (arg=0x617000070b18) at /data/bld/bb-11.5-monty-asan/storage/perfschema/pfs.cc:2201
#17 0x00007f70ca2a8044 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#18 0x00007f70ca32861c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Update: The assertion failure was fixed

Elena Stepanova added a comment - 2024-01-08 19:34 - edited mdev9101-5.test The test case sets slave_parallel_threads=4 and max_total_tmp_space_usage=64K on the slave , creates an InnoDB table on the master and runs a fairly big transaction consisting of several INSERT statements, all in RBR mode. The slave fails with bb-11.5-monty 28be348cb8cce71461da0dff09245a645196a647 mariadbd: /data/bld/bb-11.5-monty-asan/sql/log.cc:2242: int binlog_rollback(handlerton*, THD*, bool): Assertion `!all' failed. 240108 21:29:48 [ERROR] mysqld got signal 6 ; #9 0x00007f70ca253e32 in __GI___assert_fail (assertion=0x55a2178bf180 "!all", file=0x55a2178bc360 "/data/bld/bb-11.5-monty-asan/sql/log.cc", line=2242, function=0x55a2178bf040 "int binlog_rollback(handlerton*, THD*, bool)") at ./assert/assert.c:101 #10 0x000055a215e61436 in binlog_rollback (hton=0x615000001998, thd=0x62c0002b0218, all=true) at /data/bld/bb-11.5-monty-asan/sql/log.cc:2242 #11 0x000055a215b20cc1 in ha_rollback_trans (thd=0x62c0002b0218, all=true) at /data/bld/bb-11.5-monty-asan/sql/handler.cc:2274 #12 0x000055a2156e3fea in trans_rollback (thd=0x62c0002b0218) at /data/bld/bb-11.5-monty-asan/sql/transaction.cc:372 #13 0x000055a215677e0b in rpl_group_info::cleanup_context (this=0x61d00038a480, thd=0x62c0002b0218, error=true) at /data/bld/bb-11.5-monty-asan/sql/rpl_rli.cc:2275 #14 0x000055a21585fa42 in signal_error_to_sql_driver_thread (thd=0x62c0002b0218, rgi=0x61d00038a480, err=1) at /data/bld/bb-11.5-monty-asan/sql/rpl_parallel.cc:332 #15 0x000055a21586747e in handle_rpl_parallel_thread (arg=0x624000163688) at /data/bld/bb-11.5-monty-asan/sql/rpl_parallel.cc:1578 #16 0x000055a2162c6c62 in pfs_spawn_thread (arg=0x617000070b18) at /data/bld/bb-11.5-monty-asan/storage/perfschema/pfs.cc:2201 #17 0x00007f70ca2a8044 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442 #18 0x00007f70ca32861c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81 Update: The assertion failure was fixed

Elena Stepanova added a comment - 2024-01-10 20:18 - edited

--source include/have_log_bin.inc

SET max_tmp_space_usage= 64*1024;

CREATE TABLE t (

  a varchar(1024), b varchar(1024), c varchar(1024), d varchar(1024), e varchar(1024), f varchar(1024), g varchar(1024)

) ENGINE=MyISAM;

INSERT INTO t VALUES

(REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024)),

(REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024)),

(REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024)),

(REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024)),

(REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024)),

(REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024),REPEAT('x',1024)),

('x','x','x','x','x','x','x');

UPDATE t SET a = '' LIMIT 100;

# Cleanup

DROP TABLE t;

bb-11.5-monty 7393f849bfd48ec82e91469c194227a04cdcd58d
mariadbd: /src/sql/log.cc:8753: int MYSQL_BIN_LOG::write_transaction_or_stmt(group_commit_entry*, uint64): Assertion `!(entry->using_stmt_cache && !mngr->stmt_cache.empty() && mngr->get_binlog_cache_log((0))->error)' failed.
240110 22:14:44 [ERROR] mysqld got signal 6 ;

#9 0x00007fac5e853e32 in __GI___assert_fail (assertion=0x5596694ddda0 "!(entry->using_stmt_cache && !mngr->stmt_cache.empty() && mngr->get_binlog_cache_log((0))->error)", file=0x5596694d2420 "/src/sql/log.cc", line=8753, function=0x5596694ddc00 "int MYSQL_BIN_LOG::write_transaction_or_stmt(group_commit_entry*, uint64)") at ./assert/assert.c:101
#10 0x0000559667aa01a0 in MYSQL_BIN_LOG::write_transaction_or_stmt (this=0x55966b3e4600 <mysql_bin_log>, entry=0x7fac53ebd010, commit_id=0) at /src/sql/log.cc:8753
#11 0x0000559667a9da11 in MYSQL_BIN_LOG::trx_group_commit_leader (this=0x55966b3e4600 <mysql_bin_log>, leader=0x7fac53ebd010) at /src/sql/log.cc:8490
#12 0x0000559667a9c515 in MYSQL_BIN_LOG::write_transaction_to_binlog_events (this=0x55966b3e4600 <mysql_bin_log>, entry=0x7fac53ebd010) at /src/sql/log.cc:8282
#13 0x0000559667a9a383 in MYSQL_BIN_LOG::write_transaction_to_binlog (this=0x55966b3e4600 <mysql_bin_log>, thd=0x62c0000d0218, cache_mngr=0x61b000015098, end_ev=0x7fac53ebd2f0, all=false, using_stmt_cache=true, using_trx_cache=false, is_ro_1pc=false) at /src/sql/log.cc:7879
#14 0x0000559667a73083 in binlog_flush_cache (thd=0x62c0000d0218, cache_mngr=0x61b000015098, end_ev=0x7fac53ebd2f0, all=false, using_stmt=true, using_trx=false, is_ro_1pc=false) at /src/sql/log.cc:1706
#15 0x0000559667a73792 in binlog_commit_flush_stmt_cache (thd=0x62c0000d0218, all=false, cache_mngr=0x61b000015098) at /src/sql/log.cc:1759
#16 0x0000559667a7716b in binlog_rollback (hton=0x615000001998, thd=0x62c0000d0218, all=false) at /src/sql/log.cc:2219
#17 0x0000559667736cd5 in ha_rollback_trans (thd=0x62c0000d0218, all=false) at /src/sql/handler.cc:2274
#18 0x00005596672fb72e in trans_rollback_stmt (thd=0x62c0000d0218) at /src/sql/transaction.cc:535
#19 0x0000559666e0150f in mysql_execute_command (thd=0x62c0000d0218, is_called_from_prepared_stmt=false) at /src/sql/sql_parse.cc:5868
#20 0x0000559666e0e277 in mysql_parse (thd=0x62c0000d0218, rawbuf=0x6290000e6238 "UPDATE t SET a = '' LIMIT 100", length=29, parser_state=0x7fac53ebe9f0) at /src/sql/sql_parse.cc:7800
#21 0x0000559666de5880 in dispatch_command (command=COM_QUERY, thd=0x62c0000d0218, packet=0x629000249219 "UPDATE t SET a = '' LIMIT 100", packet_length=29, blocking=true) at /src/sql/sql_parse.cc:1893
#22 0x0000559666de25b8 in do_command (thd=0x62c0000d0218, blocking=true) at /src/sql/sql_parse.cc:1406
#23 0x00005596672b4637 in do_handle_one_connection (connect=0x608000002eb8, put_in_cache=true) at /src/sql/sql_connect.cc:1419
#24 0x00005596672b3ff8 in handle_one_connection (arg=0x608000002e38) at /src/sql/sql_connect.cc:1321
#25 0x0000559667edcc76 in pfs_spawn_thread (arg=0x617000006298) at /src/storage/perfschema/pfs.cc:2201
#26 0x00007fac5e8a8044 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#27 0x00007fac5e92861c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Update: The assertion failure was fixed, the UPDATE query fails with (41): Local temporary space limit reached instead.

Elena Stepanova added a comment - 2024-01-10 20:18 - edited --source include/have_log_bin.inc SET max_tmp_space_usage= 64*1024; CREATE TABLE t ( a varchar (1024), b varchar (1024), c varchar (1024), d varchar (1024), e varchar (1024), f varchar (1024), g varchar (1024) ) ENGINE=MyISAM; INSERT INTO t VALUES (REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024)), (REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024)), (REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024)), (REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024)), (REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024)), (REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024),REPEAT( 'x' ,1024)), ( 'x' , 'x' , 'x' , 'x' , 'x' , 'x' , 'x' ); UPDATE t SET a = '' LIMIT 100; # Cleanup DROP TABLE t; bb-11.5-monty 7393f849bfd48ec82e91469c194227a04cdcd58d mariadbd: /src/sql/log.cc:8753: int MYSQL_BIN_LOG::write_transaction_or_stmt(group_commit_entry*, uint64): Assertion `!(entry->using_stmt_cache && !mngr->stmt_cache.empty() && mngr->get_binlog_cache_log((0))->error)' failed. 240110 22:14:44 [ERROR] mysqld got signal 6 ; #9 0x00007fac5e853e32 in __GI___assert_fail (assertion=0x5596694ddda0 "!(entry->using_stmt_cache && !mngr->stmt_cache.empty() && mngr->get_binlog_cache_log((0))->error)", file=0x5596694d2420 "/src/sql/log.cc", line=8753, function=0x5596694ddc00 "int MYSQL_BIN_LOG::write_transaction_or_stmt(group_commit_entry*, uint64)") at ./assert/assert.c:101 #10 0x0000559667aa01a0 in MYSQL_BIN_LOG::write_transaction_or_stmt (this=0x55966b3e4600 <mysql_bin_log>, entry=0x7fac53ebd010, commit_id=0) at /src/sql/log.cc:8753 #11 0x0000559667a9da11 in MYSQL_BIN_LOG::trx_group_commit_leader (this=0x55966b3e4600 <mysql_bin_log>, leader=0x7fac53ebd010) at /src/sql/log.cc:8490 #12 0x0000559667a9c515 in MYSQL_BIN_LOG::write_transaction_to_binlog_events (this=0x55966b3e4600 <mysql_bin_log>, entry=0x7fac53ebd010) at /src/sql/log.cc:8282 #13 0x0000559667a9a383 in MYSQL_BIN_LOG::write_transaction_to_binlog (this=0x55966b3e4600 <mysql_bin_log>, thd=0x62c0000d0218, cache_mngr=0x61b000015098, end_ev=0x7fac53ebd2f0, all=false, using_stmt_cache=true, using_trx_cache=false, is_ro_1pc=false) at /src/sql/log.cc:7879 #14 0x0000559667a73083 in binlog_flush_cache (thd=0x62c0000d0218, cache_mngr=0x61b000015098, end_ev=0x7fac53ebd2f0, all=false, using_stmt=true, using_trx=false, is_ro_1pc=false) at /src/sql/log.cc:1706 #15 0x0000559667a73792 in binlog_commit_flush_stmt_cache (thd=0x62c0000d0218, all=false, cache_mngr=0x61b000015098) at /src/sql/log.cc:1759 #16 0x0000559667a7716b in binlog_rollback (hton=0x615000001998, thd=0x62c0000d0218, all=false) at /src/sql/log.cc:2219 #17 0x0000559667736cd5 in ha_rollback_trans (thd=0x62c0000d0218, all=false) at /src/sql/handler.cc:2274 #18 0x00005596672fb72e in trans_rollback_stmt (thd=0x62c0000d0218) at /src/sql/transaction.cc:535 #19 0x0000559666e0150f in mysql_execute_command (thd=0x62c0000d0218, is_called_from_prepared_stmt=false) at /src/sql/sql_parse.cc:5868 #20 0x0000559666e0e277 in mysql_parse (thd=0x62c0000d0218, rawbuf=0x6290000e6238 "UPDATE t SET a = '' LIMIT 100", length=29, parser_state=0x7fac53ebe9f0) at /src/sql/sql_parse.cc:7800 #21 0x0000559666de5880 in dispatch_command (command=COM_QUERY, thd=0x62c0000d0218, packet=0x629000249219 "UPDATE t SET a = '' LIMIT 100", packet_length=29, blocking=true) at /src/sql/sql_parse.cc:1893 #22 0x0000559666de25b8 in do_command (thd=0x62c0000d0218, blocking=true) at /src/sql/sql_parse.cc:1406 #23 0x00005596672b4637 in do_handle_one_connection (connect=0x608000002eb8, put_in_cache=true) at /src/sql/sql_connect.cc:1419 #24 0x00005596672b3ff8 in handle_one_connection (arg=0x608000002e38) at /src/sql/sql_connect.cc:1321 #25 0x0000559667edcc76 in pfs_spawn_thread (arg=0x617000006298) at /src/storage/perfschema/pfs.cc:2201 #26 0x00007fac5e8a8044 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442 #27 0x00007fac5e92861c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81 Update: The assertion failure was fixed, the UPDATE query fails with (41): Local temporary space limit reached instead.

Michael Widenius added a comment - 2024-03-15 09:40

Change state to reviewer

Michael Widenius added a comment - 2024-03-15 09:40 Change state to reviewer

Sergei Golubchik added a comment - 2024-03-23 13:05

To test this feature separately, please use bb-11.5-~~MDEV-9101~~-max-tmp-space-used

Sergei Golubchik added a comment - 2024-03-23 13:05 To test this feature separately, please use bb-11.5- MDEV-9101 -max-tmp-space-used

Sergei Golubchik added a comment - 2024-04-19 08:45

review sent per email.

https://lists.mariadb.org/hyperkitty/list/developers@lists.mariadb.org/thread/3BAGDS53ZQQ62L5APQGIE5IXAWUG4LUX/

Sergei Golubchik added a comment - 2024-04-19 08:45 review sent per email. https://lists.mariadb.org/hyperkitty/list/developers@lists.mariadb.org/thread/3BAGDS53ZQQ62L5APQGIE5IXAWUG4LUX/

Elena Stepanova added a comment - 2024-05-27 12:26 - edited

The final variable names are

MariaDB [(none)]> show variables like 'max_tmp%';

+-----------------------------+---------------+

| Variable_name               | Value         |

+-----------------------------+---------------+

| max_tmp_session_space_usage | 1099511627776 |

| max_tmp_total_space_usage   | 1099511627776 |

+-----------------------------+---------------+

It is also documented incorrectly in the KB (MDEV-33715).

Elena Stepanova added a comment - 2024-05-27 12:26 - edited The final variable names are MariaDB [(none)]> show variables like 'max_tmp%' ; + -----------------------------+---------------+ | Variable_name | Value | + -----------------------------+---------------+ | max_tmp_session_space_usage | 1099511627776 | | max_tmp_total_space_usage | 1099511627776 | + -----------------------------+---------------+ It is also documented incorrectly in the KB ( MDEV-33715 ).

People

Assignee:: Michael Widenius

Reporter:: Michael Widenius

Votes:: 1 Vote for this issue

Watchers:: 10 Start watching this issue

Dates

Created:: 2015-11-09 14:05

Updated:: 3 days ago 09:28

Resolved:: 2024-05-27 11:26

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.

MariaDB Server

Details

Description

Attachments

Attachments

Issue Links

Activity

People

Dates

Git Integration