Re: [boost] [log] Segfault in "rotating_file" example

Subject: Re: [boost] [log] Segfault in "rotating_file" example
From: Jason Roehm (jasonr_at_[hidden])
Date: 2013-04-16 16:03:56

On 04/16/2013 03:11 PM, Andrey Semashev wrote:
> On Tuesday 16 April 2013 11:55:53 Jason wrote:
>> I'm working from SVN trunk revision 83923. I've been experiencing segfaults
>> when trying to set up a file sink that has date/time format specifiers in
>> its file name. I thought I was doing something wrong, but I found that the
>> "rotating_file" example also illustrates the same behavior. Here is a sample
>> backtrace:
>>
>> Looking at the disassembly of where the segfault happens, it seems to have
>> gone off the rails and is executing invalid code. Specifically, the function
>> pointer "converter" inside the date_time::microsec_clock<>:create_time()
>> function seems to be invalid. Any ideas? I'm using gcc 4.7.2 on Ubuntu
>> 12.10.
> I have the same setup and the rotating_file example runs fine for me (I tried
> with revision 83930 though). What compiler switches do you use?

I think I found the problem. I'm using posix_time's extended-precision 
mode, where it provides resolution in nanoseconds instead of 
microseconds (enabled by defining the preprocessor symbol 
BOOST_DATE_TIME_POSIX_TIME_STD_CONFIG). I had this symbol defined in my 
source code, but I did not define it when building Boost. I fixed that, 
and now the example runs successfully. Also, my program also is able to 
log messages.

With that said, I'm now experiencing a segfault at shutdown. It appears 
down in the text_file_backend code:

#0  0x0000000f00000000 in ?? ()
#1  0x00007ffff358c9cd in __dynamic_cast () from 
/usr/lib/x86_64-linux-gnu/libstdc++.so.6
#2  0x00007ffff35d14cb in std::codecvt<wchar_t, char, __mbstate_t> 
const& std::use_facet<std::codecvt<wchar_t, char, __mbstate_t> 
 >(std::locale const&) ()
    from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#3  0x00007ffff753c3e5 in boost::filesystem::path::parent_path() const 
() from 
/home/jasonr/gbot2/cfg/../packages/env/lib/libboost_filesystem.so.1.54.0
#4  0x00007ffff72e03b6 in boost::log::v2_mt_posix::sinks::(anonymous 
namespace)::file_collector::store_file(boost::filesystem::path const&) ()
    from /home/jasonr/gbot2/cfg/../packages/env/lib/libboost_log.so.1.54.0
#5  0x00007ffff72df906 in 
boost::log::v2_mt_posix::sinks::text_file_backend::~text_file_backend() ()
    from /home/jasonr/gbot2/cfg/../packages/env/lib/libboost_log.so.1.54.0
#6  0x00000000004cb189 in destroy (this=0x98f598) at 
/code/env/include/boost/smart_ptr/make_shared_object.hpp:57
#7  destroy (this=0x98f598) at 
/code/env/include/boost/smart_ptr/detail/sp_counted_impl.hpp:151
#8  operator() (this=0x98f598) at 
/code/env/include/boost/smart_ptr/make_shared_object.hpp:87
#9 
boost::detail::sp_counted_impl_pd<boost::log::v2_mt_posix::sinks::text_file_backend*, 
boost::detail::sp_ms_deleter<boost::log::v2_mt_posix::sinks::text_file_backend> 
 >::dispose (this=0x98f580) at 
/code/env/include/boost/smart_ptr/detail/sp_counted_impl.hpp:153
#10 0x00000000004d337a in release (this=0x98f580) at 
/code/env/include/boost/smart_ptr/detail/sp_counted_base_gcc_x86.hpp:146
#11 ~shared_count (this=0x98f2b8, __in_chrg=<optimized out>) at 
/code/env/include/boost/smart_ptr/detail/shared_count.hpp:371
#12 ~shared_ptr (this=0x98f2b0, __in_chrg=<optimized out>) at 
/code/env/include/boost/smart_ptr/shared_ptr.hpp:328
#13 
boost::log::v2_mt_posix::sinks::asynchronous_sink<boost::log::v2_mt_posix::sinks::text_file_backend, 
boost::log::v2_mt_posix::sinks::unbounded_fifo_queue>::~asynchronous_sink (this=0x98f1c0, 
__in_chrg=<optimized out>) at 
/code/env/include/boost/log/sinks/async_frontend.hpp:267
#14 0x00000000004d3429 in 
boost::log::v2_mt_posix::sinks::asynchronous_sink<boost::log::v2_mt_posix::sinks::text_file_backend, 
boost::log::v2_mt_posix::sinks::unbounded_fifo_queue>::~asynchronous_sink (this=0x98f1c0, 
__in_chrg=<optimized out>) at 
/code/env/include/boost/log/sinks/async_frontend.hpp:267
#15 0x00007ffff72bea70 in boost::log::v2_mt_posix::core::~core() () from 
/home/jasonr/gbot2/cfg/../packages/env/lib/libboost_log.so.1.54.0
#16 0x00007ffff72c1e12 in 
boost::detail::sp_counted_impl_p<boost::log::v2_mt_posix::core>::dispose() 
()
    from /home/jasonr/gbot2/cfg/../packages/env/lib/libboost_log.so.1.54.0
#17 0x00000000004cc509 in release (this=0x78fdc0) at 
/code/env/include/boost/smart_ptr/detail/sp_counted_base_gcc_x86.hpp:146
#18 ~shared_count (this=<optimized out>, __in_chrg=<optimized out>) at 
/code/env/include/boost/smart_ptr/detail/shared_count.hpp:371
#19 boost::shared_ptr<boost::log::v2_mt_posix::core>::~shared_ptr 
(this=<optimized out>, __in_chrg=<optimized out>)
     at /code/env/include/boost/smart_ptr/shared_ptr.hpp:328
#20 0x00007ffff2c98901 in __run_exit_handlers (status=0, 
listp=0x7ffff30156a8 <__exit_funcs>, run_list_atexit=true) at exit.c:78
#21 0x00007ffff2c98985 in __GI_exit (status=<optimized out>) at exit.c:100
#22 0x00007ffff2c7e774 in __libc_start_main (main=0x42f630 <main(int, 
char**)>, argc=1, ubp_av=0x7fffffffe148, init=<optimized out>, 
fini=<optimized out>,
     rtld_fini=<optimized out>, stack_end=0x7fffffffe138) at 
libc-start.c:258
#23 0x0000000000431481 in _start ()

However, I don't see this problem with any examples that I've tried, so 
it's not clear to me where the problem is. The crash is down in 
boost::filesystem. I'm not sure whether it's trying to access some 
resource too late in the shutdown process or what.

On a side note, I wanted to point out that Boost.Log looks fantastic. It 
may seem a bit complex at first, but the amount of flexibility and 
extensibility is well beyond any other logging facility I've seen before.

Jason