Opened 5 years ago

Closed 5 years ago

#13371 closed Bugs (fixed)

Use-after-free with --log_sink=file

Reported by: avi@… Owned by: Raffi Enficiaud
Milestone: Boost 1.67.0 Component: test
Version: Boost 1.64.0 Severity: Problem
Keywords: Cc:

Description

When static destructors are called, as the program exits, we destroy boost::unit_test::(anonymous namespace)::s_log_impl()::the_inst. This has a member vector, m_log_formatter_data. When destroying the second member, we run an ios_base_all_saver destructor, which attempts to restore a stream's format, however that stream has already been deallocated.

Maybe that stream is in another static destructor, which was not ordered wrt. this one? Or maybe it was destroyed even earlier, when unit_test_main() exited.

From ASan (gcc 7.2) log, it looks like the former. One static destructor is run from /usr/include/boost/test/impl/framework.ipp:459, while the other is run from unit_test_log.ipp:122, so there is no ordering among them.

*** No errors detected
=================================================================
==1745==ERROR: AddressSanitizer: heap-use-after-free on address 0x6160000016a8 at pc 0x0000015f8892 bp 0x7ffecdb0b720 sp 0x7ffecdb0b710
READ of size 8 at 0x6160000016a8 thread T0
    #0 0x15f8891 in std::ios_base::width(long) /usr/include/c++/7/bits/ios_base.h:723
    #1 0x161dea0 in boost::io::ios_base_all_saver::restore() /usr/include/boost/io/ios_state.hpp:340
    #2 0x161dda6 in boost::io::ios_base_all_saver::~ios_base_all_saver() /usr/include/boost/io/ios_state.hpp:336
    #3 0x168a22e in void boost::checked_delete<boost::io::ios_base_all_saver>(boost::io::ios_base_all_saver*) /usr/include/boost/core/checked_delete.hpp:34
    #4 0x171b7c5 in boost::detail::sp_counted_impl_p<boost::io::ios_base_all_saver>::dispose() /usr/include/boost/smart_ptr/detail/sp_counted_impl.hpp:78
    #5 0x58b2c4 in boost::detail::sp_counted_base::release() /usr/include/boost/smart_ptr/detail/sp_counted_base_std_atomic.hpp:109
    #6 0x58b51e in boost::detail::shared_count::~shared_count() /usr/include/boost/smart_ptr/detail/shared_count.hpp:419
    #7 0x161eadc in boost::shared_ptr<boost::io::ios_base_all_saver>::~shared_ptr() /usr/include/boost/smart_ptr/shared_ptr.hpp:337
    #8 0x1589a8a in ~unit_test_log_data_helper_impl /usr/include/boost/test/impl/unit_test_log.ipp:87
    #9 0x15f0891 in _Destroy<boost::unit_test::(anonymous namespace)::unit_test_log_data_helper_impl> /usr/include/c++/7/bits/stl_construct.h:98
    #10 0x15eb8ad in __destroy<boost::unit_test::(anonymous namespace)::unit_test_log_data_helper_impl*> /usr/include/c++/7/bits/stl_construct.h:108
    #11 0x15e32c7 in _Destroy<boost::unit_test::(anonymous namespace)::unit_test_log_data_helper_impl*> /usr/include/c++/7/bits/stl_construct.h:137
    #12 0x15cd317 in _Destroy<boost::unit_test::(anonymous namespace)::unit_test_log_data_helper_impl*, boost::unit_test::(anonymous namespace)::unit_test_log_data_helper_impl> /usr/include/c++/7/bits/stl_construct.h:206
    #13 0x15c0de2 in ~vector /usr/include/c++/7/bits/stl_vector.h:434
    #14 0x158aa72 in ~unit_test_log_impl /usr/include/boost/test/impl/unit_test_log.ipp:122
    #15 0x7f6c2db90b57 in __run_exit_handlers (/lib64/libc.so.6+0x3bb57)
    #16 0x7f6c2db90ba9 in exit (/lib64/libc.so.6+0x3bba9)
    #17 0x7f6c2db76010 in __libc_start_main (/lib64/libc.so.6+0x21010)
    #18 0x4172e9 in _start (/home/avi/seastar/build/debug/tests/memcached/test_ascii_parser_g+0x4172e9)

0x6160000016a8 is located 296 bytes inside of 544-byte region [0x616000001580,0x6160000017a0)
freed by thread T0 here:
    #0 0x7f6c32c9d6d8 in operator delete(void*, unsigned long) (/lib64/libasan.so.4+0xe16d8)
    #1 0x1717f1e in boost::detail::sp_counted_impl_pd<std::basic_ofstream<char, std::char_traits<char> >*, boost::detail::sp_ms_deleter<std::basic_ofstream<char, std::char_traits<char> > > >::~sp_counted_impl_pd() /usr/include/boost/smart_ptr/detail/sp_counted_impl.hpp:127
    #2 0xc1563b in boost::detail::sp_counted_base::destroy() /usr/include/boost/smart_ptr/detail/sp_counted_base_std_atomic.hpp:89
    #3 0x58b3e4 in boost::detail::sp_counted_base::weak_release() /usr/include/boost/smart_ptr/detail/sp_counted_base_std_atomic.hpp:123
    #4 0x58b2f3 in boost::detail::sp_counted_base::release() /usr/include/boost/smart_ptr/detail/sp_counted_base_std_atomic.hpp:110
    #5 0x58b51e in boost::detail::shared_count::~shared_count() /usr/include/boost/smart_ptr/detail/shared_count.hpp:419
    #6 0x15fe350 in boost::shared_ptr<std::basic_ofstream<char, std::char_traits<char> > >::~shared_ptr() /usr/include/boost/smart_ptr/shared_ptr.hpp:337
    #7 0x160f9ec in boost::unit_test::runtime_config::stream_holder::~stream_holder() /usr/include/boost/test/unit_test_parameters.hpp:96
    #8 0x16fb8fc in std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder>::~pair() /usr/include/c++/7/bits/stl_pair.h:198
    #9 0x16fb964 in void __gnu_cxx::new_allocator<std::_Rb_tree_node<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> > >::destroy<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> >(std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder>*) /usr/include/c++/7/ext/new_allocator.h:140
    #10 0x16ef009 in void std::allocator_traits<std::allocator<std::_Rb_tree_node<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> > > >::destroy<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> >(std::allocator<std::_Rb_tree_node<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> > >&, std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder>*) /usr/include/c++/7/bits/alloc_traits.h:487
    #11 0x16d81bc in std::_Rb_tree<boost::unit_test::output_format, std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder>, std::_Select1st<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> >, std::less<boost::unit_test::output_format>, std::allocator<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> > >::_M_destroy_node(std::_Rb_tree_node<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> >*) /usr/include/c++/7/bits/stl_tree.h:650
    #12 0x16adac7 in std::_Rb_tree<boost::unit_test::output_format, std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder>, std::_Select1st<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> >, std::less<boost::unit_test::output_format>, std::allocator<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> > >::_M_drop_node(std::_Rb_tree_node<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> >*) /usr/include/c++/7/bits/stl_tree.h:658
    #13 0x167e5af in std::_Rb_tree<boost::unit_test::output_format, std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder>, std::_Select1st<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> >, std::less<boost::unit_test::output_format>, std::allocator<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> > >::_M_erase(std::_Rb_tree_node<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> >*) /usr/include/c++/7/bits/stl_tree.h:1858
    #14 0x1649760 in std::_Rb_tree<boost::unit_test::output_format, std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder>, std::_Select1st<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> >, std::less<boost::unit_test::output_format>, std::allocator<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> > >::~_Rb_tree() /usr/include/c++/7/bits/stl_tree.h:949
    #15 0x160f988 in std::map<boost::unit_test::output_format, boost::unit_test::runtime_config::stream_holder, std::less<boost::unit_test::output_format>, std::allocator<std::pair<boost::unit_test::output_format const, boost::unit_test::runtime_config::stream_holder> > >::~map() /usr/include/c++/7/bits/stl_map.h:294
    #16 0x161009b in boost::unit_test::framework::state::~state() /usr/include/boost/test/impl/framework.ipp:459
    #17 0x7f6c2db90b57 in __run_exit_handlers (/lib64/libc.so.6+0x3bb57)

previously allocated by thread T0 here:
    #0 0x7f6c32c9c158 in operator new(unsigned long) (/lib64/libasan.so.4+0xe0158)
    #1 0x169dfd6 in boost::detail::shared_count::shared_count<std::basic_ofstream<char, std::char_traits<char> >*, boost::detail::sp_ms_deleter<std::basic_ofstream<char, std::char_traits<char> > > >(std::basic_ofstream<char, std::char_traits<char> >*, boost::detail::sp_inplace_tag<boost::detail::sp_ms_deleter<std::basic_ofstream<char, std::char_traits<char> > > >) /usr/include/boost/smart_ptr/detail/shared_count.hpp:206
    #2 0x16728db in boost::shared_ptr<std::basic_ofstream<char, std::char_traits<char> > >::shared_ptr<std::basic_ofstream<char, std::char_traits<char> >, boost::detail::sp_inplace_tag<boost::detail::sp_ms_deleter<std::basic_ofstream<char, std::char_traits<char> > > > >(std::basic_ofstream<char, std::char_traits<char> >*, boost::detail::sp_inplace_tag<boost::detail::sp_ms_deleter<std::basic_ofstream<char, std::char_traits<char> > > >) /usr/include/boost/smart_ptr/shared_ptr.hpp:372
    #3 0x163c6e6 in boost::detail::sp_if_not_array<std::basic_ofstream<char, std::char_traits<char> > >::type boost::make_shared<std::basic_ofstream<char, std::char_traits<char> >>() /usr/include/boost/smart_ptr/make_shared_object.hpp:250
    #4 0x15fe6ad in boost::unit_test::runtime_config::stream_holder::setup(boost::unit_test::basic_cstring<char const> const&) /usr/include/boost/test/unit_test_parameters.hpp:114
    #5 0x155cd45 in boost::unit_test::framework::impl::setup_loggers() /usr/include/boost/test/impl/framework.ipp:861
    #6 0x1561113 in boost::unit_test::framework::init(bool (*)(), int, char**) /usr/include/boost/test/impl/framework.ipp:1033
    #7 0x1599d40 in boost::unit_test::unit_test_main(bool (*)(), int, char**) /usr/include/boost/test/impl/unit_test_main.ipp:189
    #8 0x15c067f in main tests/test-utils.cc:84
    #9 0x7f6c2db76009 in __libc_start_main (/lib64/libc.so.6+0x21009)

SUMMARY: AddressSanitizer: heap-use-after-free /usr/include/c++/7/bits/ios_base.h:723 in std::ios_base::width(long)
Shadow bytes around the buggy address:
  0x0c2c7fff8280: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c2c7fff8290: 00 00 00 00 06 fa fa fa fa fa fa fa fa fa fa fa
  0x0c2c7fff82a0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c2c7fff82b0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c2c7fff82c0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
=>0x0c2c7fff82d0: fd fd fd fd fd[fd]fd fd fd fd fd fd fd fd fd fd
  0x0c2c7fff82e0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c2c7fff82f0: fd fd fd fd fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c2c7fff8300: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c2c7fff8310: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c2c7fff8320: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
==1745==ABORTING

Change History (6)

comment:1 by Raffi Enficiaud, 5 years ago

Owner: changed from Gennadiy Rozental to Raffi Enficiaud
Status: newassigned

comment:2 by Raffi Enficiaud, 5 years ago

Blind fix on branch topic/13371-logstream-use-after-destroy

comment:3 by Raffi Enficiaud, 5 years ago

Milestone: To Be DeterminedBoost 1.67.0

comment:4 by Raffi Enficiaud, 5 years ago

I finally was able to make a regression test for this one. Should land soonish in develop and master.

comment:5 by Raffi Enficiaud, 5 years ago

In develop

comment:6 by Raffi Enficiaud, 5 years ago

Resolution: fixed
Status: assignedclosed

In master

Note: See TracTickets for help on using tickets.