Assertion failure: os0file.cc:3416:!exists while taking backups with lock-ddl=REDUCED

Description

During backup prepare following crash is seen. This crash is found using pstress while testing https://perconadev.atlassian.net/browse/PXB-3034. However, a confirmation is required from the Devs if it is related to it. Table Encryption was disabled during the test.

The bug is easily reproducible using attached script. Also, recorded RR sessions are available for investigation.

Stacktrace is furnished below:

#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=140052603666304) at ./nptl/pthread_kill.c:44 #1 __pthread_kill_internal (signo=6, threadid=140052603666304) at ./nptl/pthread_kill.c:78 #2 __GI___pthread_kill (threadid=140052603666304, signo=signo@entry=6) at ./nptl/pthread_kill.c:89 #3 0x00007f6089d69476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26 #4 0x00007f6089d4f7f3 in __GI_abort () at ./stdlib/abort.c:79 #5 0x00005582acdcc401 in my_abort () at /home/mohit.joshi/pxb-8.2/mysys/my_init.cc:261 #6 0x00005582abbbb58f in ut_dbg_assertion_failed (expr=0x5582ade79ae0 "!exists", file=0x5582ade78440 "/home/mohit.joshi/pxb-8.2/storage/innobase/os/os0file.cc", line=3416) at /home/mohit.joshi/pxb-8.2/storage/innobase/ut/ut0dbg.cc:100 #7 0x00005582ab9d6351 in os_file_rename_func (oldpath=0x5582b14d1410 "./test/#sql-1fc79d_13#p#p3.ibd", newpath=0x5582b14d3670 "./test/tt_28_p#p#p3.ibd") at /home/mohit.joshi/pxb-8.2/storage/innobase/os/os0file.cc:3416 #8 0x00005582ab722e78 in pfs_os_file_rename_func (key=..., oldpath=0x5582b14d1410 "./test/#sql-1fc79d_13#p#p3.ibd", newpath=0x5582b14d3670 "./test/tt_28_p#p#p3.ibd", src_location=...) at /home/mohit.joshi/pxb-8.2/storage/innobase/include/os0file.ic:475 #9 0x00005582ab730df5 in Fil_shard::space_rename (this=0x5582b1398eb0, space_id=788, old_path=0x5582b14d1000 "./test/#sql-1fc79d_13#p#p3.ibd", new_name=0x7ffd3304af10 "test/tt_28_p#p#p3", new_path_in=0x0) at /home/mohit.joshi/pxb-8.2/storage/innobase/fil/fil0fil.cc:5642 #10 0x00005582ab73108c in fil_rename_tablespace (space_id=788, old_path=0x5582b14d1000 "./test/#sql-1fc79d_13#p#p3.ibd", new_name=0x7ffd3304af10 "test/tt_28_p#p#p3", new_path_in=0x0) at /home/mohit.joshi/pxb-8.2/storage/innobase/fil/fil0fil.cc:5687 #11 0x00005582aa9b4c83 in prepare_handle_ren_files (entry=...) at /home/mohit.joshi/pxb-8.2/storage/innobase/xtrabackup/src/xtrabackup.cc:5541 #12 0x00005582aa9d891e in std::__invoke_impl<bool, bool (*&)(datadir_entry_t const&, void*), datadir_entry_t const&, void*> (__f=@0x7ffd3304b440: 0x5582aa9b485a <prepare_handle_ren_files(datadir_entry_t const&, void*)>) at /usr/include/c++/11/bits/invoke.h:61 #13 0x00005582aa9d6043 in std::__invoke_r<bool, bool (*&)(datadir_entry_t const&, void*), datadir_entry_t const&, void*> (__fn=@0x7ffd3304b440: 0x5582aa9b485a <prepare_handle_ren_files(datadir_entry_t const&, void*)>) at /usr/include/c++/11/bits/invoke.h:114 #14 0x00005582aa9d2477 in std::_Function_handler<bool (datadir_entry_t const&, void*), bool (*)(datadir_entry_t const&, void*)>::_M_invoke(std::_Any_data const&, datadir_entry_t const&, void*&&) (__functor=..., __args#0=..., __args#1=@0x7ffd3304b218: 0x0) at /usr/include/c++/11/bits/std_function.h:290 #15 0x00005582aa9cda2f in std::function<bool (datadir_entry_t const&, void*)>::operator()(datadir_entry_t const&, void*) const (this=0x7ffd3304b440, __args#0=..., __args#1=0x0) at /usr/include/c++/11/bits/std_function.h:590 #16 0x00005582aa9b5dd6 in process_datadir_l2cbk(char const*, char const*, char const*, char const*, char const*, std::function<bool (datadir_entry_t const&, void*)>, void*) (datadir=0x5582ad2fc5a8 ".", dbname=0x5582b13cfb53 "test", path=0x7ffd3304b460 "./test/788.ibd.ren", name=0x5582b14d75d3 "788.ibd.ren", suffix=0x5582ad2fea56 ".ren", func=..., data=0x0) at /home/mohit.joshi/pxb-8.2/storage/innobase/xtrabackup/src/xtrabackup.cc:5704 #17 0x00005582aa9b5f54 in operator() (__closure=0x5582b14cddc0, l2path=0x7ffd3304ba00 "./test", l2name=0x5582b14d75d3 "788.ibd.ren") at /home/mohit.joshi/pxb-8.2/storage/innobase/xtrabackup/src/xtrabackup.cc:5737 #18 0x00005582aa9c0bb4 in std::__invoke_impl<void, process_datadir_l1cbk(char const*, char const*, char const*, char const*, handle_datadir_entry_func_t, void*)::<lambda(char const*, char const*)>&, char const*, char const*>(std::__invoke_other, struct {...} &) (__f=...) at /usr/include/c++/11/bits/invoke.h:61 #19 0x00005582aa9c02a6 in std::__invoke_r<void, process_datadir_l1cbk(char const*, char const*, char const*, char const*, handle_datadir_entry_func_t, void*)::<lambda(char const*, char const*)>&, char const*, char const*>(struct {...} &) (__fn=...) at /usr/include/c++/11/bits/invoke.h:111 #20 0x00005582aa9bfdd3 in std::_Function_handler<void(char const*, char const*), process_datadir_l1cbk(char const*, char const*, char const*, char const*, handle_datadir_entry_func_t, void*)::<lambda(char const*, char const*)> >::_M_invoke(const std::_Any_data &, const char *&&, const char *&&) (__functor=..., __args#0=@0x7ffd3304b760: 0x7ffd3304ba00 "./test", __args#1=@0x7ffd3304b758: 0x5582b14d75d3 "788.ibd.ren") at /usr/include/c++/11/bits/std_function.h:290 #21 0x00005582ab9e1a9d in std::function<void (char const*, char const*)>::operator()(char const*, char const*) const (this=0x7ffd3304b8e0, __args#0=0x7ffd3304ba00 "./test", __args#1=0x5582b14d75d3 "788.ibd.ren") at /usr/include/c++/11/bits/std_function.h:590 #22 0x00005582ab9d5524 in os_file_scan_directory(char const*, std::function<void (char const*, char const*)>, bool) (path=0x7ffd3304ba00 "./test", scan_cbk=..., is_drop=false) at /home/mohit.joshi/pxb-8.2/storage/innobase/os/os0file.cc:3119 #23 0x00005582aa9b6115 in process_datadir_l1cbk(char const*, char const*, char const*, char const*, std::function<bool (datadir_entry_t const&, void*)>, void*) (datadir=0x5582ad2fc5a8 ".", path=0x7ffd3304ba00 "./test", name=0x5582b13cfb53 "test", suffix=0x5582ad2fea56 ".ren", func=..., data=0x0) at /home/mohit.joshi/pxb-8.2/storage/innobase/xtrabackup/src/xtrabackup.cc:5728 #24 0x00005582aa9b6425 in operator() (__closure=0x5582b13cb390, l1path=0x5582ad2fc5a8 ".", l1name=0x5582b13cfb53 "test") at /home/mohit.joshi/pxb-8.2/storage/innobase/xtrabackup/src/xtrabackup.cc:5773 #25 0x00005582aa9c0c9a in std::__invoke_impl<void, xb_process_datadir(char const*, char const*, handle_datadir_entry_func_t, void*)::<lambda(char const*, char const*)>&, char const*, char const*>(std::__invoke_other, struct {...} &) (__f=...) at /usr/include/c++/11/bits/invoke.h:61 #26 0x00005582aa9c0446 in std::__invoke_r<void, xb_process_datadir(char const*, char const*, handle_datadir_entry_func_t, void*)::<lambda(char const*, char const*)>&, char const*, char const*>(struct {...} &) (__fn=...) at /usr/include/c++/11/bits/invoke.h:111 #27 0x00005582aa9bfefd in std::_Function_handler<void(char const*, char const*), xb_process_datadir(char const*, char const*, handle_datadir_entry_func_t, void*)::<lambda(char const*, char const*)> >::_M_invoke(const std::_Any_data &, const char *&&, const char *&&) (__functor=..., __args#0=@0x7ffd3304bd00: 0x5582ad2fc5a8 ".", __args#1=@0x7ffd3304bcf8: 0x5582b13cfb53 "test") at /usr/include/c++/11/bits/std_function.h:290 #28 0x00005582ab9e1a9d in std::function<void (char const*, char const*)>::operator()(char const*, char const*) const (this=0x7ffd3304bdd0, __args#0=0x5582ad2fc5a8 ".", __args#1=0x5582b13cfb53 "test") at /usr/include/c++/11/bits/std_function.h:590 #29 0x00005582ab9d5524 in os_file_scan_directory(char const*, std::function<void (char const*, char const*)>, bool) (path=0x5582ad2fc5a8 ".", scan_cbk=..., is_drop=false) at /home/mohit.joshi/pxb-8.2/storage/innobase/os/os0file.cc:3119 #30 0x00005582aa9b64f8 in xb_process_datadir(char const*, char const*, std::function<bool (datadir_entry_t const&, void*)>, void*) (path=0x5582ad2fc5a8 ".", suffix=0x5582ad2fea56 ".ren", func=..., data=0x0) at /home/mohit.joshi/pxb-8.2/storage/innobase/xtrabackup/src/xtrabackup.cc:5765 #31 0x00005582aa9baae4 in xtrabackup_prepare_func (argc=4, argv=0x5582b0fc8370) at /home/mohit.joshi/pxb-8.2/storage/innobase/xtrabackup/src/xtrabackup.cc:6787 #32 0x00005582aa9bf35f in main (argc=6, argv=0x7ffd3304cdb8) at /home/mohit.joshi/pxb-8.2/storage/innobase/xtrabackup/src/xtrabackup.cc:7938

Environment

None

Activity

mohit.joshi May 8, 2024 at 8:47 AM

Closing as Duplicate of https://perconadev.atlassian.net/browse/PXB-3248 as the symptom is decryption failure and the underlying root cause is the same.

Satya Bodapati April 26, 2024 at 2:28 PM

Satya Bodapati April 26, 2024 at 12:07 PM

what if we process the .del files first always?

so 425.drop would delete the p3 (we dont care the current name in backup. A file with space_id 425 will be deleted)

and 788.ren can happily rename from #sq1 to p3.


This logic is because we skipped 425 rename and consolidated to a delete operation. ie we skip all intermediate operations and only create the .del file

So while prepareing , we should handle the .del files first. Then we are applying all the consolidated operations in a way..

rename and .new can happen later..


i wonder though if there is any dependency between rename and .new.. problem for another day.. (the renames are messy 😢 )

Satya Bodapati April 26, 2024 at 12:02 PM

now, would a .ren file for 425 helped? rename 425 from p3 to #sql2???

May be not always. it works depending up on the order of processing of .ren files

if 425.ren is processed first, it would renamed to #sql2

then 788.ren would have renamed #sql1 to p3

and 425.drop would have deleted the #sql2

 

This cannot be the solution because if 788.ren is processed first, we have the same problem…

How to solve this 🤔

Satya Bodapati April 26, 2024 at 12:00 PM

a rr file for backup would have been, this is reverse engineering from log file 😢

Done

Details

Assignee

Reporter

Found by Automation

Yes

Needs QA

Yes

Components

Sprint

Priority

Smart Checklist

Created February 28, 2024 at 2:15 PM
Updated May 8, 2024 at 8:47 AM
Resolved May 8, 2024 at 8:00 AM

Flag notifications