Using GCC's function instrumentation, why does using C++ STL containers or stream I/O cause a segfault?

Question

I recently read about using GCC's code generation features (specifically, the -finstrument-functions compiler flag) to easily add instrumentation to my programs. I thought it sounded really cool and went to try it out on a previous C++ project. After several revisions of my patch, I found that any time I tried to use an STL container or print to stdout using C++ stream I/O, my program would immediately crash with a segfault. My first idea was to maintain a std::list of Event structs

typedef struct  
{
    unsigned char event_code;
    intptr_t func_addr;
    intptr_t caller_addr;
    pthread_t thread_id;
    timespec ts;
}Event;

list<Event> events;

which would be written to a file when the program terminated. GDB told me that when I tried to add an Event to the list, calling events.push_back(ev) itself initiated an instrumentation call. This wasn't terrible surprising and made sense after I thought about it for a bit, so on to plan 2.

The example in the blog which got me involved in all this mess didn't do anything crazy, it simply wrote a string to a file using fprintf(). I didn't think there would be any harm in using C++'s stream-based I/O instead of the older (f)printf(), but that assumption proved to be wrong. This time, instead of a nearly-infinite death spiral, GDB reported a fairly normal-looking descent into the standard library... followed by a segfault.

A Short Example

#include <list>
#include <iostream>
#include <stdio.h>

using namespace std;

extern "C" __attribute__ ((no_instrument_function)) void __cyg_profile_func_enter(void*, void*);

list<string> text;

extern "C" void __cyg_profile_func_enter(void* /* unused */, void* /* unused */)
{
    // Method 1
    text.push_back("NOPE");

    // Method 2
    cout << "This explodes" << endl;

    // Method 3
    printf("This works!");
}

Sample GDB Backtrace

Method 1

#0  _int_malloc (av=0x7ffff7380720, bytes=29) at malloc.c:3570
#1  0x00007ffff704ca45 in __GI___libc_malloc (bytes=29) at malloc.c:2924
#2  0x00007ffff7652ded in operator new(unsigned long) ()
   from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#3  0x00007ffff763ba89 in std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#4  0x00007ffff763d495 in char* std::string::_S_construct<char const*>(char const*, char const*, std::allocator<char> const&, std::forward_iterator_tag) () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#5  0x00007ffff763d5e3 in std::basic_string<char, std::char_traits<char>,  std::allocator<char> >::basic_string(char const*, std::allocator<char> const&) () from  /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#6  0x00000000004028c1 in __cyg_profile_func_enter () at src/instrumentation.cpp:82
#7  0x0000000000402c6f in std::move<std::string&> (__t=...) at     /usr/include/c++/4.6/bits/move.h:82
#8  0x0000000000402af5 in std::list<std::string, std::allocator<std::string>   >::push_back(std::string&&) (this=0x6055c0, __x=...) at   /usr/include/c++/4.6/bits/stl_list.h:993
#9  0x00000000004028d2 in __cyg_profile_func_enter () at src/instrumentation.cpp:82
#10 0x0000000000402c6f in std::move<std::string&> (__t=...) at /usr/include/c++/4.6/bits/move.h:82
#11 0x0000000000402af5 in std::list<std::string, std::allocator<std::string> >::push_back(std::string&&) (this=0x6055c0, __x=...) at /usr/include/c++/4.6/bits/stl_list.h:993
#12 0x00000000004028d2 in __cyg_profile_func_enter () at src/instrumentation.cpp:82
#13 0x0000000000402c6f in std::move<std::string&> (__t=...) at /usr/include/c++/4.6/bits/move.h:82
#14 0x0000000000402af5 in std::list<std::string, std::allocator<std::string> >::push_back(std::string&
...

Method 2

#0  0x00007ffff76307d1 in std::ostream::sentry::sentry(std::ostream&) ()
    from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#1  0x00007ffff7630ee9 in std::basic_ostream<char, std::char_traits<char> >&  std::__ostream_insert<char, std::char_traits<char> >(std::basic_ostream<char, std::char_traits<char> >&, char const*, long) ()
   from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#2  0x00007ffff76312ef in std::basic_ostream<char, std::char_traits<char> >& std::operator<< <std::char_traits<char> >(std::basic_ostream<char, std::char_traits<char> >&, char const*) ()
   from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#3  0x000000000040251e in __cyg_profile_func_enter () at src/instrumentation.cpp:81
#4  0x000000000040216d in _GLOBAL__sub_I__ZN8GLWindow7attribsE () at src/glwindow.cpp:164
#5  0x0000000000402f2d in __libc_csu_init ()
#6  0x00007ffff6feb700 in __libc_start_main (main=0x402cac <main()>, argc=1, ubp_av=0x7fffffffe268, 
init=0x402ed0 <__libc_csu_init>, fini=<optimized out>, rtld_fini=<optimized out>, 
stack_end=0x7fffffffe258) at libc-start.c:185
#7  0x0000000000401589 in _start ()

Environment:

• Ubuntu Linux 12.04 (x64)
• GCC 4.6.3
• Intel 3750K CPU
• 8GB RAM

Answer 1

The problem with using cout in the instrumentation function is that the instrumentation function is being called by __libc_csu_init() which is a very early part of the runtime's initialization - before global C++ objects get a chance to be constructed (in fact, I think __libc_csu_init() is responsible for kicking off those constructors - at least indirectly).

So cout hasn't had a chance to be constructed yet and trying to use it doesn't work very well...

And that may well be the problem you run into with trying to use std::List after fixing the infinite recursion (mentioned in Dave S' answer).

If you're willing to lose some instrumentation during initialization, you can do something like:

#include <iostream>
#include <stdio.h>

int initialization_complete = 0;

using namespace std;

extern "C" __attribute__ ((no_instrument_function)) void __cyg_profile_func_enter(void*, void*);

extern "C" void __cyg_profile_func_enter(void* /* unused */, void* /* unused */)
{
    if (!initialization_complete) return;

    // Method 2
    cout << "This explodes" << endl;

    // Method 3
    printf("This works! ");
}

void foo()
{
    cout << "foo()" << endl;
}

int main()
{
    initialization_complete = 1;
    foo();
}

Answer 2

The first case seems to be an infinite loop, resulting in stack overflow. This is probably because std::list is a template, and it's code is generated as part of the translation unit where you're using it. This causes it to get instrumented as well. So you call push_back, which calls the handler, which calls push_back, ...

The second, if I had to guess, might be similar, though it's harder to tell.

The solution is to compile the instrumentation functions separately, without the -finstrument-functions. Note, the example blog compiled the trace.c separately, without the option.