Boost deadline_timer causes stack-buffer-overflow

Question

I have been stuck on a really wierd bug with Boost Deadline_timer for the last days. Desktop: Ubuntu 18.04 Boost: v1.65.01

When I create a new deadline_timer within the constructor of my class AddressSanitizer catches a stack-buffer-overflow coming from inside the Boost libraries.

I have a few observations:

• I also notice that something is wrong without AddressSanitizer by that either the timer timeouts all the time becauce expiry_time is negative, or never expires. So it seems as if someplace someone is changing that memory region.
• The class I am working with is quite big and is using the same Boost io_service to send data over UDP.
• I am not able to reproduce the bug in just a standalone source file.
• When I remove code to isolate the issue the issue remains no matter how much code I remove. I have gone down to a just a main filecreate a io_service and a deadline_timer and it stills throws that error. If I duplicate that in another file and duplicate the CMakeLists entry I am still not able to reproduce it.

The structure of the class is not very complicated and here is an example class which essentially does the same udp_timer.hpp

#include "boost/asio.hpp"


class UdpTimer {
    public:
        UdpTimer();
        ~UdpTimer();
        void run();

        void timer_callback(const boost::system::error_code &e);
        void udp_callback(const boost::system::error_code &e, size_t bytes_recvd);
        boost::asio::io_service io;
    
    private:
        boost::asio::ip::udp::socket *socket;
        boost::asio::ip::udp::endpoint *ep;
        boost::asio::deadline_timer *timer;
        char recv_buf[2048];
        unsigned int tot_bytes_recved;
};

udp_timer.cpp

#include "udp_timer.hpp"
#include "boost/bind.hpp"
#include <iostream>

UdpTimer::UdpTimer() {
    // Set up UDP part
  ep = new boost::asio::ip::udp::endpoint(boost::asio::ip::udp::v4(), 30042);
  socket = new boost::asio::ip::udp::socket(io, *ep);
  socket->async_receive_from(
    boost::asio::buffer(recv_buf, 2048), *ep,
      boost::bind(&UdpTimer::udp_callback, this,
      boost::asio::placeholders::error,
      boost::asio::placeholders::bytes_transferred)
  );

  tot_bytes_recved = 0;

  timer = new boost::asio::deadline_timer(io, boost::posix_time::seconds(1));
  timer->async_wait(boost::bind(&UdpTimer::timer_callback, this, boost::asio::placeholders::error));
}

UdpTimer::~UdpTimer() {
    delete ep;
    delete socket;
    delete timer;
}

void UdpTimer::run() {
    io.run(); // Never returns
}


// Timer callback. Print info and reset timer
void UdpTimer::timer_callback(const boost::system::error_code &e) {       
    if (e) return;
    static int count = 0;
    std::cout <<"Timer Callback #" <<count++ <<"Bytes received = " <<tot_bytes_recved <<std::endl;
    std::cout <<recv_buf <<std::endl;

    timer->expires_from_now(boost::posix_time::seconds(1));
    timer->async_wait(boost::bind(&UdpTimer::timer_callback, this, boost::asio::placeholders::error));
}

// Udp callback. Update bytes received count
void UdpTimer::udp_callback(const boost::system::error_code &e, size_t bytes_recvd) {
    if (e) return;

    tot_bytes_recved += bytes_recvd;

    socket->async_receive_from(
    boost::asio::buffer(recv_buf, 2048), *ep,
      boost::bind(&UdpTimer::udp_callback, this,
      boost::asio::placeholders::error,
      boost::asio::placeholders::bytes_transferred)
  );
}


int main(void)  {
    UdpTimer udp_timer;
    udp_timer.run();
}

This placed inside the program is enough to generate that error.

=================================================================
==20441==ERROR: AddressSanitizer: stack-buffer-overflow on address 0x7ffe4a7621d0 at pc 0x55d73239950c bp 0x7ffe4a761f50 sp 0x7ffe4a761f40
WRITE of size 16 at 0x7ffe4a7621d0 thread T0
    #0 0x55d73239950b in boost::date_time::base_time<boost::posix_time::ptime, boost::date_time::split_timedate_system<boost::posix_time::posix_time_system_config> >::base_time(boost::gregorian::date const&, boost::posix_time::time_duration const&, boost::date_time::dst_flags) (/home/erl/dev/test/build/prog_ins+0x61950b)
    #1 0x55d732396495 in boost::posix_time::ptime::ptime(boost::gregorian::date, boost::posix_time::time_duration) /usr/include/boost/date_time/posix_time/ptime.hpp:40
    #2 0x55d7323d4855 in boost::date_time::microsec_clock<boost::posix_time::ptime>::create_time(tm* (*)(long const*, tm*)) /usr/include/boost/date_time/microsec_time_clock.hpp:116
    #3 0x55d7323d12f6 in boost::date_time::microsec_clock<boost::posix_time::ptime>::universal_time() /usr/include/boost/date_time/microsec_time_clock.hpp:76
    #4 0x55d7323cb501 in boost::asio::time_traits<boost::posix_time::ptime>::now() /usr/include/boost/asio/time_traits.hpp:48
    #5 0x55d7323db197 in boost::asio::detail::deadline_timer_service<boost::asio::time_traits<boost::posix_time::ptime> >::expires_from_now(boost::asio::detail::deadline_timer_service<boost::asio::time_traits<boost::posix_time::ptime> >::implementation_type&, boost::posix_time::time_duration const&, boost::system::error_code&) (/home/erl/dev/test/build/prog_ins+0x65b197)
    #6 0x55d7323d6a25 in boost::asio::deadline_timer_service<boost::posix_time::ptime, boost::asio::time_traits<boost::posix_time::ptime> >::expires_from_now(boost::asio::detail::deadline_timer_service<boost::asio::time_traits<boost::posix_time::ptime> >::implementation_type&, boost::posix_time::time_duration const&, boost::system::error_code&) /usr/include/boost/asio/deadline_timer_service.hpp:129
    #7 0x55d7323d2ca8 in boost::asio::basic_deadline_timer<boost::posix_time::ptime, boost::asio::time_traits<boost::posix_time::ptime>, boost::asio::deadline_timer_service<boost::posix_time::ptime, boost::asio::time_traits<boost::posix_time::ptime> > >::basic_deadline_timer(boost::asio::io_service&, boost::posix_time::time_duration const&) /usr/include/boost/asio/basic_deadline_timer.hpp:187
    #8 0x55d7323b7f22 in InsHandler::InsHandler(InsConfig*, spdlog::logger*) /home/erl/dev/test/src/InsHandler.cpp:57
    #9 0x55d7323a3fb0 in main /home/erl/dev/test/src/prog_ins.cpp:74
    #10 0x7f369ed89bf6 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21bf6)
    #11 0x55d7322894d9 in _start (/home/erl/dev/test/build/prog_ins+0x5094d9)

Address 0x7ffe4a7621d0 is located in stack of thread T0 at offset 480 in frame
    #0 0x55d7323d426f in boost::date_time::microsec_clock<boost::posix_time::ptime>::create_time(tm* (*)(long const*, tm*)) /usr/include/boost/date_time/microsec_time_clock.hpp:80

  This frame has 10 object(s):
    [32, 34) '<unknown>'
    [96, 98) '<unknown>'
    [160, 162) '<unknown>'
    [224, 228) 'd'
    [288, 296) 't'
    [352, 360) 'td'
    [416, 424) '<unknown>'
    [480, 488) '<unknown>' <== Memory access at offset 480 partially overflows this variable
    [544, 560) 'tv'
    [608, 664) 'curr'
HINT: this may be a false positive if your program uses some custom stack unwind mechanism or swapcontext
      (longjmp and C++ exceptions *are* supported)
SUMMARY: AddressSanitizer: stack-buffer-overflow (/home/erl/dev/test/build/prog_ins+0x61950b) in boost::date_time::base_time<boost::posix_time::ptime, boost::date_time::split_timedate_system<boost::posix_time::posix_time_system_config> >::base_time(boost::gregorian::date const&, boost::posix_time::time_duration const&, boost::date_time::dst_flags)
Shadow bytes around the buggy address:
  0x1000494e43e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x1000494e43f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 f1 f1
  0x1000494e4400: f1 f1 f8 f2 f2 f2 f2 f2 f2 f2 f8 f2 f2 f2 f2 f2
  0x1000494e4410: f2 f2 f8 f2 f2 f2 f2 f2 f2 f2 04 f2 f2 f2 f2 f2
  0x1000494e4420: f2 f2 00 f2 f2 f2 f2 f2 f2 f2 00 f2 f2 f2 f2 f2
=>0x1000494e4430: f2 f2 00 f2 f2 f2 f2 f2 f2 f2[00]f2 f2 f2 f2 f2
  0x1000494e4440: f2 f2 00 00 f2 f2 f2 f2 f2 f2 00 00 00 00 00 00
  0x1000494e4450: 00 f2 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x1000494e4460: 00 00 00 00 f1 f1 f1 f1 00 f2 f2 f2 f2 f2 f2 f2
  0x1000494e4470: 00 f2 f2 f2 00 00 00 00 00 00 00 00 00 00 00 00
  0x1000494e4480: 00 00 00 00 00 00 00 00 f1 f1 f1 f1 00 00 f2 f2
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
==20441==ABORTING

From this error printout it seems as if there is a bug in the Boost library that writes 16 bytes to something that only 8 bytes were allocated to. But why should that surface so intermittently? Also I notice that we have a few words that are marked as stack-use-after-scope which is f8. Could that mean that we have another part of the program is using a pointer to a stack-allocated object after its out of scope?

Running with valgrind gives me this

==27251== Conditional jump or move depends on uninitialised value(s)
==27251==    at 0x578FA1: boost::date_time::int_adapter<long>::is_infinity() const (int_adapter.hpp:114)
==27251==    by 0x5772A9: boost::date_time::int_adapter<long>::is_special() const (int_adapter.hpp:131)
==27251==    by 0x5A1069: boost::date_time::counted_time_rep<boost::posix_time::millisec_posix_time_system_config>::is_special() const (time_system_counted.hpp:108)
==27251==    by 0x59FCD3: boost::date_time::counted_time_system<boost::date_time::counted_time_rep<boost::posix_time::millisec_posix_time_system_config> >::add_time_duration(boost::date_time::counted_time_rep<boost::posix_time::millisec_posix_time_system_config> const&, boost::posix_time::time_duration) (time_system_counted.hpp:226)
==27251==    by 0x59EA90: boost::date_time::base_time<boost::posix_time::ptime, boost::date_time::counted_time_system<boost::date_time::counted_time_rep<boost::posix_time::millisec_posix_time_system_config> > >::operator+(boost::posix_time::time_duration const&) const (time.hpp:163)
==27251==    by 0x59E46B: boost::asio::time_traits<boost::posix_time::ptime>::add(boost::posix_time::ptime const&, boost::posix_time::time_duration const&) (time_traits.hpp:57)
==27251==    by 0x5A1BEC: boost::asio::detail::deadline_timer_service<boost::asio::time_traits<boost::posix_time::ptime> >::expires_from_now(boost::asio::detail::deadline_timer_service<boost::asio::time_traits<boost::posix_time::ptime> >::implementation_type&, boost::posix_time::time_duration const&, boost::system::error_code&) (deadline_timer_service.hpp:161)
==27251==    by 0x5A0811: boost::asio::deadline_timer_service<boost::posix_time::ptime, boost::asio::time_traits<boost::posix_time::ptime> >::expires_from_now(boost::asio::detail::deadline_timer_service<boost::asio::time_traits<boost::posix_time::ptime> >::implementation_type&, boost::posix_time::time_duration const&, boost::system::error_code&) (deadline_timer_service.hpp:129)
==27251==    by 0x59F20B: boost::asio::basic_deadline_timer<boost::posix_time::ptime, boost::asio::time_traits<boost::posix_time::ptime>, boost::asio::deadline_timer_service<boost::posix_time::ptime, boost::asio::time_traits<boost::posix_time::ptime> > >::basic_deadline_timer(boost::asio::io_service&, boost::posix_time::time_duration const&) (basic_deadline_timer.hpp:187)
==27251==    by 0x59DA57: OutputTimer::OutputTimer(boost::asio::io_service*, unsigned int, boost::function<OutputStates ()>) (output_timer.cpp:5)
==27251==    by 0x5877D5: InsHandler::InsHandler(InsConfig*, spdlog::logger*) (InsHandler.cpp:57)
==27251==    by 0x57B149: main (senti_ins.cpp:74)
==27251==  Uninitialised value was created by a stack allocation
==27251==    at 0x59FB3C: boost::date_time::microsec_clock<boost::posix_time::ptime>::create_time(tm* (*)(long const*, tm*)) (microsec_time_clock.hpp:80)

I am really lost here. There is really no connection between the changes I make to the source code and the resulting behaviour. I am able to remove the error by removing an inclusion of a totally unrelated header file. But the error surfaces again when including a mock_header with some function definitions and enums. So it really seems to be random when this error surfaces.

I would be extremely happy for any advice on how to attack such a problem.

I am very grateful for any advice on this

Answer 1

UDPATE to the edited question

I see loads of dynamic allocation (Why should C++ programmers minimize use of 'new'?).

I see repeated magic constants (1s, 2048), failure to NUL-terminate the recv_buf and then treating it as a C string, swallowing errors.

Removing all these:

Live On Coliru

Live On Wandbox

• udp_timer.h

   //#define BOOST_BIND_NO_PLACEHOLDERS
   #include <boost/asio.hpp>
  
   using boost::asio::ip::udp;
   using namespace std::chrono_literals;
  
   class UdpTimer {
     public:
       UdpTimer();
       void run();
  
     private:
       using error_code = boost::system::error_code;
       void timer_callback(error_code e);
       void udp_callback(error_code e, size_t bytes_recvd);
  
       void do_recv();
       void do_timer();
  
       boost::asio::io_service io;
       udp::endpoint ep { {}, 30042 };
       udp::socket socket { io, ep };
       boost::asio::steady_timer timer { io };
  
       std::array<char, 2048> recv_buf{};
       unsigned int tot_bytes_recved = 0;
   };
  

• udp_timer.cpp

   #include "udp_timer.hpp"
   using namespace boost::asio::placeholders;
   #include <boost/bind/bind.hpp>
   #include <iostream>
   #include <iomanip>
  
   UdpTimer::UdpTimer() {
       do_recv();
       do_timer();
   }
  
   void UdpTimer::do_recv() {
       socket.async_receive_from(boost::asio::buffer(recv_buf), ep,
           boost::bind(&UdpTimer::udp_callback, this, error, bytes_transferred));
   }
  
   void UdpTimer::do_timer() {
       timer.expires_from_now(1s);
       timer.async_wait(boost::bind(&UdpTimer::timer_callback, this, error));
   }
  
   void UdpTimer::run() {
       io.run(); // Never returns
   }
  
   // Timer callback. Print info and reset timer
   void UdpTimer::timer_callback(error_code e)
   {
       if (e) {
           std::cout << "timer_callback: " << e.message() << std::endl;
           return;
       }
  
       static int count = 0;
       std::cout << "Timer Callback #" << count++
                 << " Bytes received = " << tot_bytes_recved << std::endl
                 << " Last received: " << std::quoted(recv_buf.data()) << std::endl;
  
       do_timer();
   }
  
   // Udp callback. Update bytes received count
   void UdpTimer::udp_callback(error_code e, size_t bytes_recvd) {
       if (e) {
           std::cout << "timer_callback: " << e.message() << std::endl;
           recv_buf[0] = '\0';
           return;
       }
  
       // because you want to print the buffer, you will also want to make sure it
       // is actually NUL terminated
       assert(bytes_recvd < recv_buf.size());
       recv_buf[bytes_recvd] = '\0';
       tot_bytes_recved += bytes_recvd;
  
       do_recv();
   }
  

• main.cpp

   int main()
   {
       UdpTimer udp_timer;
       udp_timer.run();
   }
  

Running Demo, with ASAN+UBSAN enabled

OLD ANSWER:

boost::asio::io_service io2;
boost::asio::deadline_timer* t = new boost::asio::deadline_timer(io2, boost::posix_time::seconds(1)); 

This is merely a memory leak, but in the absence of other code it cannot possibly lead to any symptom, simply because no more code is generated: Live On Compiler Explorer

Now all the other observations make you suspicious. And rightfully so!

I am not able to reproduce the bug in just a standalone source file.

This is the key. There is Undefined Behaviour in your code. It may or may not have something to do with the timer, but it certainly isn't caused by this instantiation.

One obvious problem with the code is the memory leak, and the fact that you're doing manual allocation in the first place. This opens up the door for lifetime issues.

E.g. it is conceivable that

• you have these lines in a function, the io2 goes out of scope and the time holds a stale reference to it.

  In fact this directly corresponds to the "stack-use-after-scope" detection

• many other scenarios assuming that you also t->async_wait() somehwere

Side observations are that io2 implies that you use two io services (why?). Besides all of this I hope you use better names in your real code, because it's really easy to get lost in a sea of io2, i, m3, t etc :)