Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Replace btr_pcur_open_on_user_rec() with btr_pcur_open_low()? #7

Open
midenok opened this issue Oct 10, 2016 · 0 comments
Open

Replace btr_pcur_open_on_user_rec() with btr_pcur_open_low()? #7

midenok opened this issue Oct 10, 2016 · 0 comments

Comments

@midenok
Copy link
Owner

midenok commented Oct 10, 2016

No description provided.

midenok pushed a commit that referenced this issue Jun 12, 2019
           specific temporary errors

The optimistic parallel slave's worker thread could face a run-time error due to
the algorithm's specifics which allows for conflicts like the reported
"Can't find record in 'table'".
A typical stack is like

{noformat}
#0  handler::print_error (this=0x61c00008f8a0, error=149, errflag=0) at handler.cc:3650
#1  0x0000555555e95361 in write_record (thd=thd@entry=0x62a0000a2208, table=table@entry=0x61f00008ce88, info=info@entry=0x7fffdee356d0) at sql_insert.cc:1944
#2  0x0000555555ea7767 in mysql_insert (thd=thd@entry=0x62a0000a2208, table_list=0x61b00012ada0, fields=..., values_list=..., update_fields=..., update_values=..., duplic=<optimized out>, ignore=<optimized out>) at sql_insert.cc:1039
#3  0x0000555555efda90 in mysql_execute_command (thd=thd@entry=0x62a0000a2208) at sql_parse.cc:3927
#4  0x0000555555f0cc50 in mysql_parse (thd=0x62a0000a2208, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at sql_parse.cc:7449
#5  0x00005555566d4444 in Query_log_event::do_apply_event (this=0x61200005b9c8, rgi=<optimized out>, query_arg=<optimized out>, q_len_arg=<optimized out>) at log_event.cc:4508
#6  0x00005555566d639e in Query_log_event::do_apply_event (this=<optimized out>, rgi=<optimized out>) at log_event.cc:4185
#7  0x0000555555d738cf in Log_event::apply_event (rgi=0x61d0001ea080, this=0x61200005b9c8) at log_event.h:1343
#8  apply_event_and_update_pos_apply (ev=ev@entry=0x61200005b9c8, thd=thd@entry=0x62a0000a2208, rgi=rgi@entry=0x61d0001ea080, reason=<optimized out>) at slave.cc:3479
#9  0x0000555555d8596b in apply_event_and_update_pos_for_parallel (ev=ev@entry=0x61200005b9c8, thd=thd@entry=0x62a0000a2208, rgi=rgi@entry=0x61d0001ea080) at slave.cc:3623
#10 0x00005555562aca83 in rpt_handle_event (qev=qev@entry=0x6190000fa088, rpt=rpt@entry=0x62200002bd68) at rpl_parallel.cc:50
#11 0x00005555562bd04e in handle_rpl_parallel_thread (arg=arg@entry=0x62200002bd68) at rpl_parallel.cc:1258
{noformat}

Here {{handler::print_error}} computes whether to error log the
current error when --log-warnings > 1. The decision flag is consulted
bu {{my_message_sql()}} which can be eventually called.
In the bug case the decision is to log.
However in the optimistic mode slave applier case any conflict is
attempted to resolve with rollback and retry to success. Hence the
logging is at least extraneous.

The case is fixed with adding a new flag {{ME_LOG_AS_WARN}} which
{{handler::print_error}} may propagate further on through {{my_error}}
when the error comes from an optimistically running slave worker thread.

The new flag effectively requests the warning level for the errlog record,
while the thread's DA records the actual error (which is regarded as temporary one
by the parallel slave error handler).
midenok pushed a commit that referenced this issue Jun 12, 2019
@midenok midenok mentioned this issue Aug 19, 2019
midenok pushed a commit that referenced this issue Oct 13, 2020
Problem:
=======
SHOW BINLOG EVENTS FROM <"random"-pos> caused a variety of failures as
reported in MDEV-18046. They are fixed but that approach is not future-proof
as well as is not optimal to create extra check for being constructed event
parameters.

Analysis:
=========
"show binlog events from <pos>" code considers the user given position as a
valid event start position. The code starts reading data from this event start
position onwards and tries to map it to a set of known events. Each event has
a specific event structure and asserts have been added to ensure that, read
event data, satisfies the event specific requirements. When a random position
is supplied to "show binlog events command" the event structure specific
checks will fail and they result in assert.

For example: https://jira.mariadb.org/browse/MDEV-18046
In the bug description user executes CREATE TABLE/INSERT and ALTER SQL
commands.

When a crazy offset like "SHOW BINLOG EVENTS FROM 365" is provided code
assumes offset 365 as valid event begin and proceeds to EVENT_LEN_OFFSET reads
some random length and comes up with a crazy event which didn't exits in the
binary log. In this quoted example scenario, event read at offset 365 is
considered as "Update_rows_log_event", which is not present in binary log.
Since this is a random event its validation fails and code results in
assert/segmentation fault, as shown below.

mysqld: /data/src/10.4/sql/log_event.cc:10863: Rows_log_event::Rows_log_event(
    const char*, uint, const Format_description_log_event*):
    Assertion `var_header_len >= 2' failed.
    181220 15:27:02 [ERROR] mysqld got signal 6 ;
#7  0x00007fa0d96abee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
#8  0x000055e744ef82de in Rows_log_event::Rows_log_event (this=0x7fa05800d390,
    buf=0x7fa05800d080 "", event_len=254, description_event=0x7fa058006d60) at
/data/src/10.4/sql/log_event.cc:10863
#9  0x000055e744f00cf8 in Update_rows_log_event::Update_rows_log_event

Since we are reading random data repeating the same command SHOW BINLOG EVENTS
FROM 365 produces different types of crashes with different events. MDEV-18046
reported 10 such crashes.

In order to avoid such scenarios user provided starting offset needs to be
validated for its correctness. Best way of doing this is to make use of
checksums if they are available. MDEV-18046 fix introduced the checksum based
validation.

The issue still remains in cases where binlog checksums are disabled. Please
find the following bug reports.

MDEV-22473: binlog.binlog_show_binlog_event_random_pos failed in buildbot,
            server crashed in read_log_event
MDEV-22455: Server crashes in Table_map_log_event,
            binlog.binlog_invalid_read_in_rotate failed in buildbot

Fix:
====
When binlog checksum is disabled, perform scan(via reading event by event), to
validate the requested FROM <pos> offset. Starting from offset 4 read the
event_length of next_event in the binary log. Using the next_event length
advance current offset to point to next event. Repeat this process till the
current offset is less than or equal to crazy offset. If current offset is
higher than crazy offset provide appropriate invalid input offset error.
midenok pushed a commit that referenced this issue Nov 19, 2021
  Read of size 8 at 0x7fecf2e75fc8 by thread T2 (mutexes: write M1318):
    #0 tpool::thread_pool_generic::submit_task(tpool::task*) /tpool/tpool_generic.cc:823:9 (mariadbd+0x25fd2d2)
    #1 (anonymous namespace)::aio_uring::thread_routine((anonymous namespace)::aio_uring*) /tpool/aio_liburing.cc:173:20 (mariadbd+0x260b21b)
    #2 void std::__invoke_impl<void, void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>(std::__invoke_other, void (*&&)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:61:14 (mariadbd+0x260c62a)
    #3 std::__invoke_result<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>::type std::__invoke<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>(void (*&&)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x260c4ba)
    #4 void std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> >::_M_invoke<0ul, 1ul>(std::_Index_tuple<0ul, 1ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x260c442)
    #5 std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x260c3c5)
    #6 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x260c189)
    #7 <null> <null> (libstdc++.so.6+0xd230f)

  Previous write of size 8 at 0x7fecf2e75fc8 by main thread:
    #0 tpool::task::task(void (*)(void*), void*, tpool::task_group*) /tpool/task.cc:40:46 (mariadbd+0x260a138)
    #1 tpool::aiocb::aiocb() /tpool/tpool.h:147:13 (mariadbd+0x2355943)
    #2 void std::_Construct<tpool::aiocb>(tpool::aiocb*) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_construct.h:109:38 (mariadbd+0x2355845)
    #3 tpool::aiocb* std::__uninitialized_default_n_1<false>::__uninit_default_n<tpool::aiocb*, unsigned long>(tpool::aiocb*, unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:579:3 (mariadbd+0x235576c)
    #4 tpool::aiocb* std::__uninitialized_default_n<tpool::aiocb*, unsigned long>(tpool::aiocb*, unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:638:14 (mariadbd+0x23556e9)
    #5 tpool::aiocb* std::__uninitialized_default_n_a<tpool::aiocb*, unsigned long, tpool::aiocb>(tpool::aiocb*, unsigned long, std::allocator<tpool::aiocb>&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:704:14 (mariadbd+0x2355641)
    #6 std::vector<tpool::aiocb, std::allocator<tpool::aiocb> >::_M_default_initialize(unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_vector.h:1606:4 (mariadbd+0x2354f3d)
    #7 std::vector<tpool::aiocb, std::allocator<tpool::aiocb> >::vector(unsigned long, std::allocator<tpool::aiocb> const&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_vector.h:512:9 (mariadbd+0x2354a19)
    #8 tpool::cache<tpool::aiocb>::cache(unsigned long, tpool::cache_notification_mode) /tpool/tpool_structs.h:73:20 (mariadbd+0x2354784)
    #9 io_slots::io_slots(int, int) /storage/innobase/os/os0file.cc:93:3 (mariadbd+0x235343b)
    #10 os_aio_init() /storage/innobase/os/os0file.cc:3780:22 (mariadbd+0x234ebce)
    #11 srv_start(bool) /storage/innobase/srv/srv0start.cc:1190:6 (mariadbd+0x256720c)
    #12 innodb_init(void*) /storage/innobase/handler/ha_innodb.cc:4188:8 (mariadbd+0x1ed3bda)
    #13 ha_initialize_handlerton(st_plugin_int*) /sql/handler.cc:659:31 (mariadbd+0xf7be06)
    #14 plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) /sql/sql_plugin.cc:1463:9 (mariadbd+0x160fa1b)
    #15 plugin_init(int*, char**, int) /sql/sql_plugin.cc:1756:15 (mariadbd+0x160f07f)
    #16 init_server_components() /sql/mysqld.cc:5043:7 (mariadbd+0xd70fb2)
    #17 mysqld_main(int, char**) /sql/mysqld.cc:5655:7 (mariadbd+0xd6a9d7)
    #18 main /sql/main.cc:34:10 (mariadbd+0xd65d18)

I think the report is incorrect: it's not possible to have such a race
condition. I've checked it by reading the code and putting assertions.
Namely, no aio I/O is possible before the end of os_aio_init().
Most probably it's some bug in TSAN. But the patch fixes around 5 related
reports and this is a step toward TSAN usefullness. Currently it reports too
much noise.

std::unique_ptr is a step toward https://isocpp.github.io/CppCoreGuidelines/CppCoreGuidelines#r11-avoid-calling-new-and-delete-explicitly
There is no std::make_unique() in C++11, however.
midenok pushed a commit that referenced this issue Nov 19, 2021
WARNING: ThreadSanitizer: data race (pid=1503350)
  Write of size 8 at 0x0000067b1f20 by thread T3:
    #0 os_file_sync_posix(int) /storage/innobase/os/os0file.cc:895:5 (mariadbd+0x23493f6)
    #1 os_file_flush_func(int) /storage/innobase/os/os0file.cc:983:8 (mariadbd+0x2349204)
    #2 file_os_io::flush() /storage/innobase/log/log0log.cc:326:10 (mariadbd+0x22eaaa9)
    #3 log_file_t::flush() /storage/innobase/log/log0log.cc:440:18 (mariadbd+0x22eb2d0)
    #4 log_t::file::flush() /storage/innobase/log/log0log.cc:507:29 (mariadbd+0x22ebe69)
    #5 log_write_flush_to_disk_low(unsigned long) /storage/innobase/log/log0log.cc:629:17 (mariadbd+0x22ed3f3)
    #6 log_write_up_to(unsigned long, bool, bool, completion_callback const*) /storage/innobase/log/log0log.cc:829:3 (mariadbd+0x22ecb04)
    #7 log_checkpoint_low(unsigned long, unsigned long) /storage/innobase/buf/buf0flu.cc:1734:5 (mariadbd+0x20d37f1)
    #8 buf_flush_sync_for_checkpoint(unsigned long) /storage/innobase/buf/buf0flu.cc:1947:7 (mariadbd+0x20d4193)
    #9 buf_flush_page_cleaner() /storage/innobase/buf/buf0flu.cc:2186:9 (mariadbd+0x20cdad7)
    #10 void std::__invoke_impl<void, void (*)()>(std::__invoke_other, void (*&&)()) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:61:14 (mariadbd+0x20c3aaa)
    #11 std::__invoke_result<void (*)()>::type std::__invoke<void (*)()>(void (*&&)()) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x20c39bd)
    #12 void std::thread::_Invoker<std::tuple<void (*)()> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x20c3965)
    #13 std::thread::_Invoker<std::tuple<void (*)()> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x20c3905)
    #14 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)()> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x20c37f9)
    #15 <null> <null> (libstdc++.so.6+0xd230f)

  Previous write of size 8 at 0x0000067b1f20 by main thread:
    #0 os_file_sync_posix(int) /storage/innobase/os/os0file.cc:895:5 (mariadbd+0x23493f6)
    #1 os_file_flush_func(int) /storage/innobase/os/os0file.cc:983:8 (mariadbd+0x2349204)
    #2 fil_space_t::flush_low() /storage/innobase/fil/fil0fil.cc:504:5 (mariadbd+0x205cad5)
    #3 fil_flush_file_spaces() /storage/innobase/fil/fil0fil.cc:2947:13 (mariadbd+0x206523f)
    #4 log_checkpoint() /storage/innobase/buf/buf0flu.cc:1777:5 (mariadbd+0x20cd069)
    #5 buf_flush_wait_flushed(unsigned long) /storage/innobase/buf/buf0flu.cc:1867:5 (mariadbd+0x20ccf95)
    #6 log_make_checkpoint() /storage/innobase/buf/buf0flu.cc:1793:3 (mariadbd+0x20cc4c9)
    #7 buf_dblwr_t::create() /storage/innobase/buf/buf0dblwr.cc:216:3 (mariadbd+0x209076a)
    #8 srv_start(bool) /storage/innobase/srv/srv0start.cc:1685:20 (mariadbd+0x256b514)
    #9 innodb_init(void*) /storage/innobase/handler/ha_innodb.cc:4188:8 (mariadbd+0x1ed406a)
    #10 ha_initialize_handlerton(st_plugin_int*) /sql/handler.cc:659:31 (mariadbd+0xf7c246)
    #11 plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) /sql/sql_plugin.cc:1463:9 (mariadbd+0x160fe6b)
    #12 plugin_init(int*, char**, int) /sql/sql_plugin.cc:1756:15 (mariadbd+0x160f4cf)
    #13 init_server_components() /sql/mysqld.cc:5043:7 (mariadbd+0xd713f2)
    #14 mysqld_main(int, char**) /sql/mysqld.cc:5655:7 (mariadbd+0xd6ae17)
    #15 main /sql/main.cc:34:10 (mariadbd+0xd66158)

This is a correct report by TSAN for an obvious case: unprotected global
counter. Fix it by making counter std::atomic.
midenok pushed a commit that referenced this issue Nov 19, 2021
WARNING: ThreadSanitizer: data race (pid=1506937)
  Write of size 8 at 0x0000067ab740 by thread T6:
    #0 buf_page_get_low(page_id_t, unsigned long, unsigned long, buf_block_t*, unsigned long, mtr_t*, dberr_t*, bool) /storage/innobase/buf/buf0buf.cc:2946:8 (mariadbd+0x2014c7f)
    #1 buf_page_get_gen(page_id_t, unsigned long, unsigned long, buf_block_t*, unsigned long, mtr_t*, dberr_t*, bool) /storage/innobase/buf/buf0buf.cc:3047:10 (mariadbd+0x2016216)
    #2 btr_cur_search_to_nth_level_func(dict_index_t*, unsigned long, dtuple_t const*, page_cur_mode_t, unsigned long, btr_cur_t*, ssux_lock_impl<true>*, mtr_t*, unsigned long) /storage/innobase/btr/btr0cur.cc:1613:10 (mariadbd+0x1fb5bff)
    #3 btr_pcur_open_low(dict_index_t*, unsigned long, dtuple_t const*, page_cur_mode_t, unsigned long, btr_pcur_t*, unsigned long, mtr_t*) /storage/innobase/include/btr0pcur.ic:439:8 (mariadbd+0x24ddead)
    #4 row_search_on_row_ref(btr_pcur_t*, unsigned long, dict_table_t const*, dtuple_t const*, mtr_t*) /storage/innobase/row/row0row.cc:1215:7 (mariadbd+0x24dd537)
    #5 row_purge_reposition_pcur(unsigned long, purge_node_t*, mtr_t*) /storage/innobase/row/row0purge.cc:81:23 (mariadbd+0x24c5369)
    #6 row_purge_reset_trx_id(purge_node_t*, mtr_t*) /storage/innobase/row/row0purge.cc:748:6 (mariadbd+0x24c90c7)
    #7 row_purge_record_func(purge_node_t*, unsigned char*, que_thr_t const*, bool) /storage/innobase/row/row0purge.cc:1174:4 (mariadbd+0x24c8262)
    #8 row_purge(purge_node_t*, unsigned char*, que_thr_t*) /storage/innobase/row/row0purge.cc:1218:18 (mariadbd+0x24c5af3)
    #9 row_purge_step(que_thr_t*) /storage/innobase/row/row0purge.cc:1267:3 (mariadbd+0x24c5996)
    #10 que_thr_step(que_thr_t*) /storage/innobase/que/que0que.cc:653:9 (mariadbd+0x23d5298)
    #11 que_run_threads_low(que_thr_t*) /storage/innobase/que/que0que.cc:709:25 (mariadbd+0x23d3f29)
    #12 que_run_threads(que_thr_t*) /storage/innobase/que/que0que.cc:729:2 (mariadbd+0x23d3bdf)
    #13 srv_task_execute() /storage/innobase/srv/srv0srv.cc:1692:3 (mariadbd+0x2562841)
    #14 purge_worker_callback(void*) /storage/innobase/srv/srv0srv.cc:1864:10 (mariadbd+0x255f361)
    #15 tpool::task_group::execute(tpool::task*) /tpool/task_group.cc:55:9 (mariadbd+0x260a5ca)
    #16 tpool::task::execute() /tpool/task.cc:47:16 (mariadbd+0x260adf6)
    #17 tpool::thread_pool_generic::worker_main(tpool::worker_data*) /tpool/tpool_generic.cc:550:11 (mariadbd+0x25fc590)
    #18 void std::__invoke_impl<void, void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*>(std::__invoke_memfun_deref, void (tpool::thread_pool_generic::*&&)(tpool::worker_data*), tpool::thread_pool_generic*&&, tpool::worker_data*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:74:14 (mariadbd+0x26061b5)
    #19 std::__invoke_result<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*>::type std::__invoke<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*>(void (tpool::thread_pool_generic::*&&)(tpool::worker_data*), tpool::thread_pool_generic*&&, tpool::worker_data*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x2605f57)
    #20 void std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::_M_invoke<0ul, 1ul, 2ul>(std::_Index_tuple<0ul, 1ul, 2ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x2605ecb)
    #21 std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x2605e35)
    #22 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x2605ac9)
    #23 <null> <null> (libstdc++.so.6+0xd230f)

  Previous write of size 8 at 0x0000067ab740 by thread T8:
    #0 buf_page_get_low(page_id_t, unsigned long, unsigned long, buf_block_t*, unsigned long, mtr_t*, dberr_t*, bool) /storage/innobase/buf/buf0buf.cc:2946:8 (mariadbd+0x2014c7f)
    #1 buf_page_get_gen(page_id_t, unsigned long, unsigned long, buf_block_t*, unsigned long, mtr_t*, dberr_t*, bool) /storage/innobase/buf/buf0buf.cc:3047:10 (mariadbd+0x2016216)
    #2 btr_cur_search_to_nth_level_func(dict_index_t*, unsigned long, dtuple_t const*, page_cur_mode_t, unsigned long, btr_cur_t*, ssux_lock_impl<true>*, mtr_t*, unsigned long) /storage/innobase/btr/btr0cur.cc:1613:10 (mariadbd+0x1fb5bff)
    #3 btr_pcur_open_low(dict_index_t*, unsigned long, dtuple_t const*, page_cur_mode_t, unsigned long, btr_pcur_t*, unsigned long, mtr_t*) /storage/innobase/include/btr0pcur.ic:439:8 (mariadbd+0x24ddead)
    #4 row_search_on_row_ref(btr_pcur_t*, unsigned long, dict_table_t const*, dtuple_t const*, mtr_t*) /storage/innobase/row/row0row.cc:1215:7 (mariadbd+0x24dd537)
    #5 row_purge_reposition_pcur(unsigned long, purge_node_t*, mtr_t*) /storage/innobase/row/row0purge.cc:81:23 (mariadbd+0x24c5369)
    #6 row_purge_reset_trx_id(purge_node_t*, mtr_t*) /storage/innobase/row/row0purge.cc:748:6 (mariadbd+0x24c90c7)
    #7 row_purge_record_func(purge_node_t*, unsigned char*, que_thr_t const*, bool) /storage/innobase/row/row0purge.cc:1174:4 (mariadbd+0x24c8262)
    #8 row_purge(purge_node_t*, unsigned char*, que_thr_t*) /storage/innobase/row/row0purge.cc:1218:18 (mariadbd+0x24c5af3)
    #9 row_purge_step(que_thr_t*) /storage/innobase/row/row0purge.cc:1267:3 (mariadbd+0x24c5996)
    #10 que_thr_step(que_thr_t*) /storage/innobase/que/que0que.cc:653:9 (mariadbd+0x23d5298)
    #11 que_run_threads_low(que_thr_t*) /storage/innobase/que/que0que.cc:709:25 (mariadbd+0x23d3f29)
    #12 que_run_threads(que_thr_t*) /storage/innobase/que/que0que.cc:729:2 (mariadbd+0x23d3bdf)
    #13 trx_purge(unsigned long, bool) /storage/innobase/trx/trx0purge.cc:1271:2 (mariadbd+0x25841b4)
    #14 srv_do_purge(unsigned long*) /storage/innobase/srv/srv0srv.cc:1784:20 (mariadbd+0x2563224)
    #15 purge_coordinator_callback_low() /storage/innobase/srv/srv0srv.cc:1881:35 (mariadbd+0x2562b3b)
    #16 purge_coordinator_callback(void*) /storage/innobase/srv/srv0srv.cc:1910:3 (mariadbd+0x255f4ab)
    #17 tpool::task_group::execute(tpool::task*) /tpool/task_group.cc:55:9 (mariadbd+0x260a5ca)
    #18 tpool::task::execute() /tpool/task.cc:47:16 (mariadbd+0x260adf6)
    #19 tpool::thread_pool_generic::worker_main(tpool::worker_data*) /tpool/tpool_generic.cc:550:11 (mariadbd+0x25fc590)
    #20 void std::__invoke_impl<void, void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*>(std::__invoke_memfun_deref, void (tpool::thread_pool_generic::*&&)(tpool::worker_data*), tpool::thread_pool_generic*&&, tpool::worker_data*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:74:14 (mariadbd+0x26061b5)
    #21 std::__invoke_result<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*>::type std::__invoke<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*>(void (tpool::thread_pool_generic::*&&)(tpool::worker_data*), tpool::thread_pool_generic*&&, tpool::worker_data*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x2605f57)
    #22 void std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::_M_invoke<0ul, 1ul, 2ul>(std::_Index_tuple<0ul, 1ul, 2ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x2605ecb)
    #23 std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x2605e35)
    #24 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x2605ac9)
    #25 <null> <null> (libstdc++.so.6+0xd230f)

  Location is global 'buf_dbg_counter' of size 8 at 0x0000067ab740 (mariadbd+0x67ab740)

  The obvious fix is to make counter atomic.
midenok pushed a commit that referenced this issue Nov 19, 2021
  Write of size 1 at 0x0000067abe08 by thread T3 (mutexes: write M1372):
    #0 buf_flush_page_cleaner() /storage/innobase/buf/buf0flu.cc:2366:29 (mariadbd+0x20cea7c)
    #1 void std::__invoke_impl<void, void (*)()>(std::__invoke_other, void (*&&)()) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:61:14 (mariadbd+0x20c3a8a)
    #2 std::__invoke_result<void (*)()>::type std::__invoke<void (*)()>(void (*&&)()) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x20c399d)
    #3 void std::thread::_Invoker<std::tuple<void (*)()> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x20c3945)
    #4 std::thread::_Invoker<std::tuple<void (*)()> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x20c38e5)
    #5 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)()> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x20c37d9)
    #6 <null> <null> (libstdc++.so.6+0xd230f)

  Previous read of size 1 at 0x0000067abe08 by main thread:
    #0 logs_empty_and_mark_files_at_shutdown() /storage/innobase/log/log0log.cc:1094:6 (mariadbd+0x22eeff3)
    #1 innodb_shutdown() /storage/innobase/srv/srv0start.cc:1970:3 (mariadbd+0x256ffd6)
    #2 innobase_end(handlerton*, ha_panic_function) /storage/innobase/handler/ha_innodb.cc:4265:3 (mariadbd+0x1ee3fc4)
    #3 ha_finalize_handlerton(st_plugin_int*) /sql/handler.cc:595:5 (mariadbd+0xf7bac9)
    #4 plugin_deinitialize(st_plugin_int*, bool) /sql/sql_plugin.cc:1266:9 (mariadbd+0x1611789)
    #5 reap_plugins() /sql/sql_plugin.cc:1342:7 (mariadbd+0x160e17d)
    #6 plugin_shutdown() /sql/sql_plugin.cc:2050:7 (mariadbd+0x1611f42)
    #7 clean_up(bool) /sql/mysqld.cc:1923:3 (mariadbd+0xd67a4c)
    #8 unireg_abort /sql/mysqld.cc:1835:3 (mariadbd+0xd67605)
    #9 mysqld_main(int, char**) /sql/mysqld.cc:5741:7 (mariadbd+0xd6b36a)
    #10 main /sql/main.cc:34:10 (mariadbd+0xd661a8)

  Location is global 'buf_page_cleaner_is_active' of size 1 at 0x0000067abe08 (mariadbd+0x67abe08)
midenok pushed a commit that referenced this issue Nov 19, 2021
WARNING: ThreadSanitizer: data race (pid=1510842)
  Write of size 8 at 0x0000067b1e98 by main thread:
    #0 os_file_pwrite(IORequest const&, int, unsigned char const*, unsigned long, unsigned long, dberr_t*) /storage/innobase/os/os0file.cc:2928:2 (mariadbd+0x234c5ac)
    #1 os_file_write_func(IORequest const&, char const*, int, void const*, unsigned long, unsigned long) /storage/innobase/os/os0file.cc:2963:20 (mariadbd+0x234c019)
    #2 file_os_io::write(char const*, unsigned long, st_::span<unsigned char const>) /storage/innobase/log/log0log.cc:320:10 (mariadbd+0x22eaa50)
    #3 log_file_t::write(unsigned long, st_::span<unsigned char const>) /storage/innobase/log/log0log.cc:434:18 (mariadbd+0x22eb1d8)
    #4 log_t::file::write(unsigned long, st_::span<unsigned char>) /storage/innobase/log/log0log.cc:496:29 (mariadbd+0x22ebb55)
    #5 log_write_buf(unsigned char*, unsigned long, unsigned long, unsigned long, unsigned long) /storage/innobase/log/log0log.cc:614:14 (mariadbd+0x22f1b51)
    #6 log_write(bool) /storage/innobase/log/log0log.cc:755:2 (mariadbd+0x22ed2ec)
    #7 log_write_up_to(unsigned long, bool, bool, completion_callback const*) /storage/innobase/log/log0log.cc:817:5 (mariadbd+0x22eca44)
    #8 log_checkpoint_low(unsigned long, unsigned long) /storage/innobase/buf/buf0flu.cc:1734:5 (mariadbd+0x20d37c1)
    #9 log_checkpoint() /storage/innobase/buf/buf0flu.cc:1787:10 (mariadbd+0x20cd155)
    #10 buf_flush_wait_flushed(unsigned long) /storage/innobase/buf/buf0flu.cc:1867:5 (mariadbd+0x20ccf8f)
    #11 log_make_checkpoint() /storage/innobase/buf/buf0flu.cc:1793:3 (mariadbd+0x20cc4c9)
    #12 buf_dblwr_t::create() /storage/innobase/buf/buf0dblwr.cc:216:3 (mariadbd+0x209076a)
    #13 srv_start(bool) /storage/innobase/srv/srv0start.cc:1685:20 (mariadbd+0x256b4aa)
    #14 innodb_init(void*) /storage/innobase/handler/ha_innodb.cc:4188:8 (mariadbd+0x1ed40da)
    #15 ha_initialize_handlerton(st_plugin_int*) /sql/handler.cc:659:31 (mariadbd+0xf7c2b6)
    #16 plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) /sql/sql_plugin.cc:1463:9 (mariadbd+0x160fedb)
    #17 plugin_init(int*, char**, int) /sql/sql_plugin.cc:1756:15 (mariadbd+0x160f53f)
    #18 init_server_components() /sql/mysqld.cc:5043:7 (mariadbd+0xd71462)
    #19 mysqld_main(int, char**) /sql/mysqld.cc:5655:7 (mariadbd+0xd6ae87)
    #20 main /sql/main.cc:34:10 (mariadbd+0xd661c8)

  Previous write of size 8 at 0x0000067b1e98 by thread T3:
    #0 os_file_pwrite(IORequest const&, int, unsigned char const*, unsigned long, unsigned long, dberr_t*) /storage/innobase/os/os0file.cc:2928:2 (mariadbd+0x234c5ac)
    #1 os_file_write_func(IORequest const&, char const*, int, void const*, unsigned long, unsigned long) /storage/innobase/os/os0file.cc:2963:20 (mariadbd+0x234c019)
    #2 file_os_io::write(char const*, unsigned long, st_::span<unsigned char const>) /storage/innobase/log/log0log.cc:320:10 (mariadbd+0x22eaa50)
    #3 log_file_t::write(unsigned long, st_::span<unsigned char const>) /storage/innobase/log/log0log.cc:434:18 (mariadbd+0x22eb1d8)
    #4 log_t::file::write(unsigned long, st_::span<unsigned char>) /storage/innobase/log/log0log.cc:496:29 (mariadbd+0x22ebb55)
    #5 log_write_checkpoint_info(unsigned long) /storage/innobase/log/log0log.cc:911:14 (mariadbd+0x22edd4e)
    #6 log_checkpoint_low(unsigned long, unsigned long) /storage/innobase/buf/buf0flu.cc:1755:3 (mariadbd+0x20d3a3d)
    #7 buf_flush_sync_for_checkpoint(unsigned long) /storage/innobase/buf/buf0flu.cc:1947:7 (mariadbd+0x20d4163)
    #8 buf_flush_page_cleaner() /storage/innobase/buf/buf0flu.cc:2186:9 (mariadbd+0x20cdab1)
    #9 void std::__invoke_impl<void, void (*)()>(std::__invoke_other, void (*&&)()) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:61:14 (mariadbd+0x20c3aaa)
    #10 std::__invoke_result<void (*)()>::type std::__invoke<void (*)()>(void (*&&)()) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x20c39bd)
    #11 void std::thread::_Invoker<std::tuple<void (*)()> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x20c3965)
    #12 std::thread::_Invoker<std::tuple<void (*)()> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x20c3905)
    #13 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)()> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x20c37f9)
    #14 <null> <null> (libstdc++.so.6+0xd230f)

  Location is global 'os_n_file_writes' of size 8 at 0x0000067b1e98 (mariadbd+0x67b1e98)

  Make variable atomic.
midenok pushed a commit that referenced this issue Mar 22, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant