fix: multiple asan errors

[neverchanje]

std::function<std::string()> log_prefixed_message_func = []() {
    static thread_local std::string prefixed_message;

    static thread_local std::once_flag flag;
    std::call_once(flag, [&]() {
        prefixed_message.resize(23);
        int tid = dsn::utils::get_current_tid();
        sprintf(const_cast<char *>(prefixed_message.c_str()), "unknown.io-thrd.%05d: ", tid);
    });

    return prefixed_message;

This function prepends "unknown.io-thrd.: " to every line of our log when the rdsn runtime is not set up.
But this prefix has no useful meaning, as tid is also logged via static void print_header(FILE *fp, dsn_log_level_t log_level) . So I here simplify this function to output ": " instead.

This function has a mem-leak that the thread-local "prefixed_message" will be freed even when log_prefixed_message_func is in use. Simplifying this function also resolves this problem.

[levy5307]

What kind of memory leak? Can you describe it in detail?

[neverchanje]

==3425012==ERROR: AddressSanitizer: heap-use-after-free on address 0x6030000093d0 at pc 0x7fd06fed3480 bp 0x7ffe607c0e40 sp 0x7ffe607c05e8
READ of size 23 at 0x6030000093d0 thread T0
    #0 0x7fd06fed347f  (/usr/lib/x86_64-linux-gnu/libasan.so.5+0x9b47f)
    #1 0x559307aa3d56 in std::char_traits<char>::copy(char*, char const*, unsigned long) /usr/include/c++/9/bits/char_traits.h:365
    #2 0x559307aa3d56 in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::_S_copy(char*, char const*, unsigned long) /usr/include/c++/9/bits/basic_string.h:351
    #3 0x559307aa3d56 in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::_S_copy(char*, char const*, unsigned long) /usr/include/c++/9/bits/basic_string.h:346
    #4 0x559307aa3d56 in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::_S_copy_chars(char*, char*, char*) /usr/include/c++/9/bits/basic_string.h:393
    #5 0x559307aa3d56 in void std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::_M_construct<char*>(char*, char*, std::forward_iterator_tag) /usr/include/c++/9/bits/basic_string.tcc:225
    #6 0x7fd06faa586d in void std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::_M_construct_aux<char*>(char*, char*, std::__false_type) /usr/include/c++/9/bits/basic_string.h:247
    #7 0x7fd06faa586d in void std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::_M_construct<char*>(char*, char*) /usr/include/c++/9/bits/basic_string.h:266
    #8 0x7fd06faa586d in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::basic_string(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) /usr/include/c++/9/bits/basic_string.h:451
    #9 0x7fd06faa586d in operator() /home/wutao1/git/pegasus/rdsn/src/utils/logging.cpp:57
    #10 0x7fd06faa586d in _M_invoke /usr/include/c++/9/bits/std_function.h:286
    #11 0x7fd06face772 in std::function<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > ()>::operator()() const /usr/include/c++/9/bits/std_function.h:688
    #12 0x7fd06face772 in print_header /home/wutao1/git/pegasus/rdsn/src/utils/simple_logger.cpp:72
    #13 0x7fd06facfd25 in dsn::tools::screen_logger::dsn_logv(char const*, char const*, int, dsn_log_level_t, char const*, __va_list_tag*) /home/wutao1/git/pegasus/rdsn/src/utils/simple_logger.cpp:100
    #14 0x7fd06faa2a8e in dsn_logv(char const*, char const*, int, dsn_log_level_t, char const*, __va_list_tag*) /home/wutao1/git/pegasus/rdsn/src/utils/logging.cpp:139
    #15 0x7fd06faa2b9b in dsn_logf(char const*, char const*, int, dsn_log_level_t, char const*, ...) /home/wutao1/git/pegasus/rdsn/src/utils/logging.cpp:151
    #16 0x559307cda30f in dsn::perf_counters::remove_counter(char const*) /home/wutao1/git/pegasus/rdsn/src/perf_counter/perf_counters.cpp:159
    #17 0x559307eac56c in dsn::perf_counter_wrapper::clear() /home/wutao1/git/pegasus/rdsn/include/dsn/perf_counter/perf_counter_wrapper.h:73
    #18 0x559307eac56c in dsn::perf_counter_wrapper::clear() /home/wutao1/git/pegasus/rdsn/include/dsn/perf_counter/perf_counter_wrapper.h:70
    #19 0x559307eac56c in dsn::perf_counter_wrapper::~perf_counter_wrapper() /home/wutao1/git/pegasus/rdsn/include/dsn/perf_counter/perf_counter_wrapper.h:66
    #20 0x559307eac56c in dsn::builtin_counters::~builtin_counters() /home/wutao1/git/pegasus/rdsn/src/perf_counter/builtin_counters.cpp:25
    #21 0x7fd06f482a26  (/lib/x86_64-linux-gnu/libc.so.6+0x49a26)
    #22 0x7fd06f482bdf in exit (/lib/x86_64-linux-gnu/libc.so.6+0x49bdf)
    #23 0x7fd06f4600b9 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b9)
    #24 0x559307a6a92d in _start (/home/wutao1/git/pegasus/rdsn/builder/src/perf_counter/test/dsn_perf_counter_test+0x23092d)

0x6030000093d0 is located 0 bytes inside of 31-byte region [0x6030000093d0,0x6030000093ef)
freed by thread T0 here:
    #0 0x7fd06ff488df in operator delete(void*) (/usr/lib/x86_64-linux-gnu/libasan.so.5+0x1108df)
    #1 0x7fd06f48343e in __call_tls_dtors (/lib/x86_64-linux-gnu/libc.so.6+0x4a43e)

previously allocated by thread T0 here:
    #0 0x7fd06ff47947 in operator new(unsigned long) (/usr/lib/x86_64-linux-gnu/libasan.so.5+0x10f947)
    #1 0x7fd06f788e7d in std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >::_M_mutate(unsigned long, unsigned long, char const*, unsigned long) (/usr/lib/x86_64-linux-gnu/libstdc++.so.6+0x142e7d)

[neverchanje]

"__call_tls_dtors" means the threadlocal vars are freed. But print_header is still reading those vars. It causes an asan error. I have no idea why this happens.

[neverchanje]

==3428602==ERROR: AddressSanitizer: stack-buffer-overflow on address 0x7fffec075928 at pc 0x7f1002a58a6d bp 0x7fffec0740e0 sp 0x7fffec073888
READ of size 47 at 0x7fffec075928 thread T0
    #0 0x7f1002a58a6c  (/usr/lib/x86_64-linux-gnu/libasan.so.5+0x67a6c)
    #1 0x559a236c7123 in std::char_traits<char>::length(char const*) /usr/include/c++/9/bits/char_traits.h:335
    #2 0x559a236c7123 in fmt::v5::internal::arg_formatter_base<fmt::v5::back_insert_range<fmt::v5::internal::basic_buffer<char> > >::write(char const*) /home/wutao1/git/pegasus/rdsn/thirdparty/output/include/fmt/format.h:1353
    #3 0x559a2371c3ff in fmt::v5::internal::arg_formatter_base<fmt::v5::back_insert_range<fmt::v5::internal::basic_buffer<char> > >::operator()(char const*) /home/wutao1/git/pegasus/rdsn/thirdparty/output/include/fmt/format.h:1421
    #4 0x559a2371c3ff in fmt::v5::internal::result_of<fmt::v5::arg_formatter<fmt::v5::back_insert_range<fmt::v5::internal::basic_buffer<char> > > (int)>::type fmt::v5::visit_format_arg<fmt::v5::arg_formatter<fmt::v5::back_insert_range<fmt::v5::internal::basic_buffer<char> > >, fmt::v5::basic_format_context<std::back_insert_iterator<fmt::v5::internal::basic_buffer<char> >, char> >(fmt::v5::arg_formatter<fmt::v5::back_insert_range<fmt::v5::internal::basic_buffer<char> > >&&, fmt::v5::basic_format_arg<fmt::v5::basic_format_context<std::back_insert_iterator<fmt::v5::internal::basic_buffer<char> >, char> > const&) /home/wutao1/git/pegasus/rdsn/thirdparty/output/include/fmt/core.h:856
    #5 0x559a237200f9 in fmt::v5::format_handler<fmt::v5::arg_formatter<fmt::v5::back_insert_range<fmt::v5::internal::basic_buffer<char> > >, char, fmt::v5::basic_format_context<std::back_insert_iterator<fmt::v5::internal::basic_buffer<char> >, char> >::on_replacement_field(char const*) /home/wutao1/git/pegasus/rdsn/thirdparty/output/include/fmt/format.h:3097
    #6 0x559a237200f9 in void fmt::v5::internal::parse_format_string<false, char, fmt::v5::format_handler<fmt::v5::arg_formatter<fmt::v5::back_insert_range<fmt::v5::internal::basic_buffer<char> > >, char, fmt::v5::basic_format_context<std::back_insert_iterator<fmt::v5::internal::basic_buffer<char> >, char> >&>(fmt::v5::basic_string_view<char>, fmt::v5::format_handler<fmt::v5::arg_formatter<fmt::v5::back_insert_range<fmt::v5::internal::basic_buffer<char> > >, char, fmt::v5::basic_format_context<std::back_insert_iterator<fmt::v5::internal::basic_buffer<char> >, char> >&) /home/wutao1/git/pegasus/rdsn/thirdparty/output/include/fmt/format.h:2031
    #7 0x7f10029363bc in fmt::v5::buffer_context<char>::type::iterator fmt::v5::internal::vformat_to<char>(fmt::v5::internal::basic_buffer<char>&, fmt::v5::basic_string_view<char>, fmt::v5::basic_format_args<fmt::v5::buffer_context<char>::type>) (/home/wutao1/git/pegasus/rdsn/builder/src/utils/libdsn_utils.so+0x21b3bc)
    #8 0x7f100291400b in fmt::v5::vprint(_IO_FILE*, fmt::v5::basic_string_view<char>, fmt::v5::format_args) (/home/wutao1/git/pegasus/rdsn/builder/src/utils/libdsn_utils.so+0x1f900b)
    #9 0x7f10028c4a7b in std::enable_if<fmt::v5::internal::is_string<char [16]>::value, void>::type fmt::v5::print<char [16], char, char [24], unsigned long, int, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >(_IO_FILE*, char const (&) [16], char const&, char const (&) [24], unsigned long const&, int const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) /home/wutao1/git/pegasus/rdsn/thirdparty/output/include/fmt/core.h:1478
    #10 0x7f10028c4a7b in print_header /home/wutao1/git/pegasus/rdsn/src/utils/simple_logger.cpp:66
    #11 0x7f10028c9b06 in dsn::tools::simple_logger::dsn_log(char const*, char const*, int, dsn_log_level_t, char const*) /home/wutao1/git/pegasus/rdsn/src/utils/simple_logger.cpp:234
    #12 0x559a237dbdb4 in core_dlog_f_Test::TestBody() /home/wutao1/git/pegasus/rdsn/src/utils/test/logging.cpp:78
    #13 0x559a23cafdad in void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) (/home/wutao1/git/pegasus/rdsn/builder/src/utils/test/dsn_utils_tests+0xa2bdad)
    #14 0x559a23ca93cc in void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) (/home/wutao1/git/pegasus/rdsn/builder/src/utils/test/dsn_utils_tests+0xa253cc)
    #15 0x559a23c8b337 in testing::Test::Run() (/home/wutao1/git/pegasus/rdsn/builder/src/utils/test/dsn_utils_tests+0xa07337)
    #16 0x559a23c8bcbb in testing::TestInfo::Run() (/home/wutao1/git/pegasus/rdsn/builder/src/utils/test/dsn_utils_tests+0xa07cbb)
    #17 0x559a23c8c375 in testing::TestCase::Run() (/home/wutao1/git/pegasus/rdsn/builder/src/utils/test/dsn_utils_tests+0xa08375)
    #18 0x559a23c93624 in testing::internal::UnitTestImpl::RunAllTests() (/home/wutao1/git/pegasus/rdsn/builder/src/utils/test/dsn_utils_tests+0xa0f624)
    #19 0x559a23cb11a9 in bool testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) (/home/wutao1/git/pegasus/rdsn/builder/src/utils/test/dsn_utils_tests+0xa2d1a9)
    #20 0x559a23caa44e in bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) (/home/wutao1/git/pegasus/rdsn/builder/src/utils/test/dsn_utils_tests+0xa2644e)
    #21 0x559a23c92175 in testing::UnitTest::Run() (/home/wutao1/git/pegasus/rdsn/builder/src/utils/test/dsn_utils_tests+0xa0e175)
    #22 0x559a23546b60 in RUN_ALL_TESTS() /home/wutao1/git/pegasus/rdsn/thirdparty/output/include/gtest/gtest.h:2233
    #23 0x559a23546b60 in main /home/wutao1/git/pegasus/rdsn/src/utils/test/main.cpp:18
    #24 0x7f10020190b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)
    #25 0x559a23592c7d in _start (/home/wutao1/git/pegasus/rdsn/builder/src/utils/test/dsn_utils_tests+0x30ec7d)

Address 0x7fffec075928 is located in stack of thread T0 at offset 760 in frame
    #0 0x7f10028c40bf in print_header /home/wutao1/git/pegasus/rdsn/src/utils/simple_logger.cpp:58