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

spdlog: do not drop logger in destructor #3116

Merged
merged 1 commit into from
Apr 11, 2024
Merged

spdlog: do not drop logger in destructor #3116

merged 1 commit into from
Apr 11, 2024

Conversation

pcolberg
Copy link
Contributor

@pcolberg pcolberg commented Apr 8, 2024

For static objects, the order of destruction is in reverse of the order of construction, but the latter is hard to control except among static objects defined within the same translation unit. This means that spdlog may be destructed before spdlog::drop() is invoked in the destructor, which leads to a segmentation fault due to memory use-after-free.

Move call of spdlog::drop() from destructor to main() function, to ensure the logger may be re-registered with the same name in tests. Use Scope Guard pattern to implement RAII for logger registration.

Link: ros2/rclcpp#933
Link: gabime/spdlog#1738
Link: gabime/spdlog#2113
Link: https://en.wikibooks.org/wiki/More_C++_Idioms/Scope_Guard
Closes: https://hsdes.intel.com/appstore/article/#/22019839238

Cc: @badanur

@pcolberg pcolberg self-assigned this Apr 8, 2024
@pcolberg pcolberg requested review from a team as code owners April 8, 2024 19:15
@pcolberg
Copy link
Contributor Author

pcolberg commented Apr 8, 2024

Stack trace of hssi with opae-sdk 2.12.0-5 on RHEL 8.6:

(gdb) r --pci-address 0000:b1:00.6 hssi_100g --num-packets 100 --port 0
Starting program: /usr/bin/hssi --pci-address 0000:b1:00.6 hssi_100g --num-packets 100 --port 0
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
[New Thread 0x7ffff33ff700 (LWP 804376)]
100G loopback test
  port: 0
  eth_loopback: on
  num_packets: 100
  gap: none
  src_address: 11:22:33:44:55:66
    (bits): 0x665544332211
  dest_address: 77:88:99:aa:bb:cc
    (bits): 0xccbbaa998877
  pattern: random
  start size: 40
  end size: 2580
  end select: pkt_num
  eth: 
  continuous mode: off
  monitor duration: 0 sec

No eth interface, so not honoring --eth-loopback.
0x40000           ETH_AFU_DFH: 0x1000010000001000
0x40008          ETH_AFU_ID_L: 0xb03abd8d4a533812
0x40010          ETH_AFU_ID_H: 0x43425ee692b24742
0x40030      TRAFFIC_CTRL_CMD: 0x0000000000000000
0x40038     TRAFFIC_CTRL_DATA: 0x0000004000000064
0x40040 TRAFFIC_CTRL_PORT_SEL: 0x0000000000000000
0x40048        AFU_SCRATCHPAD: 0x0000000045324511

0x1000                scratch: 0x00000000
0x1001               block_ID: 0x434c4e54
0x1008               pkt_size: 0x25800040
0x1009                  ctrl0: 0x80000064
0x1010                  ctrl1: 0x00000040
0x1011            dst_addr_lo: 0xaa998877
0x1012            dst_addr_hi: 0x0000ccbb
0x1013            src_addr_lo: 0x44332211
0x1014            src_addr_hi: 0x00006655
0x1015               rx_count: 0x00000000
0x1016                mlb_rst: 0x00000000
0x1017               tx_count: 0x00000064

No eth interface, so not showing stats.
[Thread 0x7ffff33ff700 (LWP 804376) exited]

Thread 1 "hssi" received signal SIGSEGV, Segmentation fault.
std::_Hashtable<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> >, std::allocator<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> > >, std::__detail::_Select1st, std::equal_to<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::hash<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<true, false, true> >::_M_find_before_node (
    this=this@entry=0x7ffff5e7f118 <spdlog::details::registry::instance()::s_instance+120>, __n=__n@entry=0, 
    __k="hssi_100g", __code=1051062443682879639) at /usr/include/c++/8/bits/hashtable.h:1565
warning: Source file is more recent than executable.
1565		 if (!__p->_M_nxt || _M_bucket_index(__p->_M_next()) != __n)
Missing separate debuginfos, use: yum debuginfo-install libgcc-8.5.0-20.el8.x86_64 libstdc++-8.5.0-20.el8.x86_64 libuuid-2.32.1-43.el8.x86_64
(gdb) bt
#0  std::_Hashtable<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> >, std::allocator<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> > >, std::__detail::_Select1st, std::equal_to<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::hash<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<true, false, true> >::_M_find_before_node (
    this=this@entry=0x7ffff5e7f118 <spdlog::details::registry::instance()::s_instance+120>, __n=__n@entry=0, 
    __k="hssi_100g", __code=1051062443682879639) at /usr/include/c++/8/bits/hashtable.h:1565
#1  0x00007ffff5c383af in std::_Hashtable<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> >, std::allocator<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> > >, std::__detail::_Select1st, std::equal_to<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::hash<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<true, false, true> >::_M_erase (
    this=this@entry=0x7ffff5e7f118 <spdlog::details::registry::instance()::s_instance+120>, __k="hssi_100g")
    at /usr/include/c++/8/bits/hashtable_policy.h:1398
#2  0x00007ffff5c384a3 in std::_Hashtable<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> >, std::allocator<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> > >, std::__detail::_Select1st, std::equal_to<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::hash<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<true, false, true> >::erase (__k="hssi_100g", 
    this=0x7ffff5e7f118 <spdlog::details::registry::instance()::s_instance+120>)
    at /usr/include/c++/8/bits/hashtable.h:765
#3  std::unordered_map<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::shared_ptr<spdlog::logger>, std::hash<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::equal_to<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> > > >::erase (__x="hssi_100g", this=0x7ffff5e7f118 <spdlog::details::registry::instance()::s_instance+120>)
    at /usr/include/c++/8/bits/unordered_map.h:815
#4  spdlog::details::registry::drop (this=0x7ffff5e7f0a0 <spdlog::details::registry::instance()::s_instance>, 
    logger_name="hssi_100g") at ../include/spdlog/details/registry-inl.h:222
#5  0x0000555555427163 in opae::afu_test::afu::~afu (this=0x5555556820a0 <app>, __in_chrg=<optimized out>)
    at /usr/include/c++/8/bits/shared_ptr_base.h:1010
#6  0x00007ffff4c511ec in __run_exit_handlers (status=0, listp=0x7ffff4fbf758 <__exit_funcs>, 
    run_list_atexit=run_list_atexit@entry=true, run_dtors=run_dtors@entry=true) at exit.c:108
#7  0x00007ffff4c51320 in __GI_exit (status=<optimized out>) at exit.c:139
#8  0x00007ffff4c3acaa in __libc_start_main (main=0x555555411d00 <main(int, char**)>, argc=8, argv=0x7fffffffe478, 
    init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fffffffe468)
    at ../csu/libc-start.c:348
#9  0x0000555555411f8e in _start () at /usr/src/debug/opae-2.12.0-5.el8.x86_64/samples/hssi/hssi_afu.h:56

@pcolberg
Copy link
Contributor Author

pcolberg commented Apr 8, 2024

test_dummy_afu fails due to duplicate logger:

[ RUN      ] dummy_afu/dummy_afu_p.main_invalid_guid/0
unknown file: Failure
C++ exception with description "logger with name 'mmio' already exists" thrown in the test body.
[  FAILED  ] dummy_afu/dummy_afu_p.main_invalid_guid/0, where GetParam() = "dfl-d5005" (132 ms)

@pcolberg pcolberg marked this pull request as draft April 8, 2024 19:30
@pcolberg pcolberg force-pushed the pcolberg/spdlog branch 2 times, most recently from cc25c6b to 8011090 Compare April 8, 2024 20:25
@coveralls
Copy link

coveralls commented Apr 8, 2024

Pull Request Test Coverage Report for Build 8606807048

Details

  • 6 of 18 (33.33%) changed or added relevant lines in 3 files are covered.
  • No unchanged relevant lines lost coverage.
  • Overall coverage decreased (-0.02%) to 64.673%

Changes Missing Coverage Covered Lines Changed/Added Lines %
samples/cxl_hello_fpga/he_cache_test.h 0 6 0.0%
samples/cxl_host_exerciser/he_cache_test.h 0 6 0.0%
Totals Coverage Status
Change from base Build 8147633845: -0.02%
Covered Lines: 15823
Relevant Lines: 24466

💛 - Coveralls

anandaravuri
anandaravuri previously approved these changes Apr 8, 2024
@pcolberg
Copy link
Contributor Author

pcolberg commented Apr 8, 2024

Thankfully the compiler stopped me from resorting to a non-RAII solution using goto:

[2/20] Building CXX object samples/cxl_host_exerciser/CMakeFiles/cxl_host_exerciser.dir/cxl_host_exerciser.cpp.o
FAILED: samples/cxl_host_exerciser/CMakeFiles/cxl_host_exerciser.dir/cxl_host_exerciser.cpp.o 
/usr/bin/c++ -DFMT_SHARED -DHAVE_CONFIG_H=1 -DLIBOPAE_DEBUG=1 -DSPDLOG_SHARED_LIB -DSPDLOG_COMPILED_LIB -DSPDLOG_FMT_EXTERNAL -I/home/pcolberg/git/github.com/OFS/opae-sdk/libraries -I/home/pcolberg/git/github.com/OFS/opae-sdk/samples/base/sw -I/home/pcolberg/git/github.com/OFS/opae-sdk/include -I/home/pcolberg/git/github.com/OFS/opae-sdk/build/include -I/home/pcolberg/git/github.com/OFS/opae-sdk/samples/cxl_host_exerciser -I/home/pcolberg/git/github.com/OFS/opae-sdk/tests/framework -I/home/pcolberg/git/github.com/OFS/opae-sdk/libraries/plugins/xfpga -std=c++14 -g -O0 -Wall -Wextra -Werror -pthread -std=gnu++14 -Wno-unused-result -MD -MT samples/cxl_host_exerciser/CMakeFiles/cxl_host_exerciser.dir/cxl_host_exerciser.cpp.o -MF samples/cxl_host_exerciser/CMakeFiles/cxl_host_exerciser.dir/cxl_host_exerciser.cpp.o.d -o samples/cxl_host_exerciser/CMakeFiles/cxl_host_exerciser.dir/cxl_host_exerciser.cpp.o -c /home/pcolberg/git/github.com/OFS/opae-sdk/samples/cxl_host_exerciser/cxl_host_exerciser.cpp
In file included from /home/pcolberg/git/github.com/OFS/opae-sdk/samples/cxl_host_exerciser/cxl_host_exerciser.h:28,
                 from /home/pcolberg/git/github.com/OFS/opae-sdk/samples/cxl_host_exerciser/cxl_he_cmd.h:32,
                 from /home/pcolberg/git/github.com/OFS/opae-sdk/samples/cxl_host_exerciser/cxl_he_cache_cmd.h:29,
                 from /home/pcolberg/git/github.com/OFS/opae-sdk/samples/cxl_host_exerciser/cxl_host_exerciser.cpp:30:
/home/pcolberg/git/github.com/OFS/opae-sdk/samples/cxl_host_exerciser/he_cache_test.h: In member function ‘int opae::afu_test::afu::main(int, char**)’:
/home/pcolberg/git/github.com/OFS/opae-sdk/samples/cxl_host_exerciser/he_cache_test.h:486:1: error: jump to label ‘drop_logger’
  486 | drop_logger:
      | ^~~~~~~~~~~
/home/pcolberg/git/github.com/OFS/opae-sdk/samples/cxl_host_exerciser/he_cache_test.h:469:12: note:   from here
  469 |       goto drop_logger;
      |            ^~~~~~~~~~~
/home/pcolberg/git/github.com/OFS/opae-sdk/samples/cxl_host_exerciser/he_cache_test.h:473:18: note:   crosses initialization of ‘CLI::Option* opt’
  473 |     CLI::Option* opt = app->get_option_no_throw("--device");
      |                  ^~~
/home/pcolberg/git/github.com/OFS/opae-sdk/samples/cxl_host_exerciser/he_cache_test.h:472:9: note:   crosses initialization of ‘int dev_index’
  472 |     int dev_index = 0;
      |         ^~~~~~~~~

@pcolberg
Copy link
Contributor Author

pcolberg commented Apr 8, 2024

This duplicates the code for class scoped_register_logger in the same manner as class afu is duplicated among the three samples. If that is an issue, I feel the latter duplication should be adressed first; rather than promoting class scoped_register_logger to a common, reusable header.

For static objects, the order of destruction is in reverse of the order
of construction, but the latter is hard to control except among static
objects defined within the same translation unit. This means that spdlog
may be destructed before spdlog::drop() is invoked in the destructor,
which leads to a segmentation fault due to memory use-after-free.

Move call of spdlog::drop() from destructor to main() function, to
ensure the logger may be re-registered with the same name in tests.
Use Scope Guard pattern to implement RAII for logger registration.

Link: ros2/rclcpp#933
Link: gabime/spdlog#1738
Link: gabime/spdlog#2113
Link: https://en.wikibooks.org/wiki/More_C++_Idioms/Scope_Guard
Closes: https://hsdes.intel.com/appstore/article/#/22019839238
Signed-off-by: Peter Colberg <[email protected]>
@pcolberg pcolberg marked this pull request as ready for review April 8, 2024 21:45
@pcolberg pcolberg merged commit 3ec53b0 into master Apr 11, 2024
30 checks passed
@pcolberg pcolberg deleted the pcolberg/spdlog branch April 11, 2024 20:48
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants