+1 for including this in the debug builds Sent from my Windows Phone From: Leif Hedstrom Sent: 11-3-2014 21:40 To: [email protected] Subject: Re: Stack traces across scheduled events
On Mar 11, 2014, at 2:01 PM, Brian Geffon <[email protected]> wrote: > Hi all, > There has been discussion on IRC about techniques for following requests > across events. I've slapped together a simple patch that attaches > backtraces to Continuations every time an event is scheduled. Since some > people may find this useful I wanted to "archive" it via the mailing list. > If it's very useful we can consider cleaning it up and adding it to master > via autoconf. This sounds like a potential candidate for inclusion with debug builds ? -- Leif > > Brian > > > Example via gdb: > (gdb) p *((Continuation*)(contp)).bt@ > ((Continuation*)(contp))->current_bt_size > $10 = {0x4cc0f3 <EventProcessor::schedule(Event*, int, bool)+231>, 0x4cc279 > <EventProcessor::schedule_imm(Continuation*, int, int, void*)+153>, > 0x4f2209 <INKVConnInternal::reenable(VIO*)+97>, 0x50a893 > <VIO::reenable()+63>, 0x5b6061 <HttpTunnel::producer_handler(int, > HttpTunnelProducer*)+1213>, 0x5b568e > <HttpTunnel::producer_run(HttpTunnelProducer*)+2732>, 0x5b4b1b > <HttpTunnel::tunnel_run(HttpTunnelProducer*)+155>, 0x57c46c > <HttpSM::set_next_state()+3450>, 0x57b6eb > <HttpSM::call_transact_and_set_next_state(void > (*)(HttpTransact::State*))+439>, 0x56883f > <HttpSM::handle_api_return()+313>, 0x568613 <HttpSM::state_api_callout(int, > void*)+2185>, 0x567d0f <HttpSM::state_api_callback(int, void*)+419>, > 0x4fd83c <TSHttpTxnReenable(TSHttpTxn, TSEvent)+386>, 0x7ffff302814c > <(anonymous namespace)::handleGlobalPluginEvents(TSCont, TSEvent, > void*)+92>, 0x4f1a94 <INKContInternal::handle_event(int, void*)+176>, > 0x4e8d82 <Continuation::handleEvent(int, void*)+108>, ...} > > > > diff --git a/iocore/eventsystem/I_Continuation.h > b/iocore/eventsystem/I_Continuation.h > index 1de095b..cd8c297 100644 > --- a/iocore/eventsystem/I_Continuation.h > +++ b/iocore/eventsystem/I_Continuation.h > @@ -56,6 +56,20 @@ class EThread; > #define CONTINUATION_DONE 0 > #define CONTINUATION_CONT 1 > > +#ifndef CROSS_EVENT_STACK_TRACES > +#define CROSS_EVENT_STACK_TRACES > +#endif > + > +#ifdef CROSS_EVENT_STACK_TRACES > +#ifdef __GNUG__ > +#define CROSS_EVENT_STACK_TRACES_ALWAYS_INLINE inline > __attribute__((always_inline)) > +#else > +#define CROSS_EVENT_STACK_TRACES_ALWAYS_INLINE inline > +#endif > +#include <execinfo.h> > +#define BT_LIMIT_PER_EVENT 128 > +#endif > + > typedef int (Continuation::*ContinuationHandler) (int event, void *data); > > class force_VFPT_to_top > @@ -93,6 +107,27 @@ public: > > class Continuation: private force_VFPT_to_top > { > +#ifdef CROSS_EVENT_STACK_TRACES > +public: > + size_t current_bt_size; > + size_t max_bt_size; > + void **bt; > + > + void CROSS_EVENT_STACK_TRACES_ALWAYS_INLINE attach_current_stack_trace() > { > + if (max_bt_size < (current_bt_size + BT_LIMIT_PER_EVENT)) { > + // we need more space so we can attach at least BT_LIMIT_PER_EVENT > pointers > + if (max_bt_size == 0) { > + max_bt_size = BT_LIMIT_PER_EVENT; > + bt = static_cast<void**>(ats_malloc(sizeof(void *) * max_bt_size)); > + } else { > + max_bt_size <<= 1; > + bt = static_cast<void **>(ats_realloc(bt, sizeof(void *) * > max_bt_size)); > + } > + } > + current_bt_size += backtrace (bt + current_bt_size, > BT_LIMIT_PER_EVENT); > + } > +private: > +#endif > public: > > /** > @@ -167,9 +202,14 @@ public: > #define SET_HANDLER(_h) \ > (handler = ((ContinuationHandler)_h),handler_name = #_h) > #else > +#ifdef CROSS_EVENT_STACK_TRACES > +#define SET_HANDLER(_h) \ > + (handler = ((ContinuationHandler)_h), current_bt_size = 0) > +#else > #define SET_HANDLER(_h) \ > (handler = ((ContinuationHandler)_h)) > #endif > +#endif > > /** > Sets a Continuation's handler. > @@ -184,13 +224,22 @@ public: > #define SET_CONTINUATION_HANDLER(_c,_h) \ > (_c->handler = ((ContinuationHandler) _h),_c->handler_name = #_h) > #else > +#ifdef CROSS_EVENT_STACK_TRACES > #define SET_CONTINUATION_HANDLER(_c,_h) \ > - (_c->handler = ((ContinuationHandler) _h)) > + (_c->handler = ((ContinuationHandler) _h), _c->current_bt_size = 0); > +#else > +#define SET_CONTINUATION_HANDLER(_c,_h) \ > + (_c->handler = ((ContinuationHandler) _h)); > +#endif > #endif > > inline > Continuation::Continuation(ProxyMutex * amutex) > - : handler(NULL), > + : > +#ifdef CROSS_EVENT_STACK_TRACES > + current_bt_size(0), max_bt_size(0), bt(NULL), > +#endif > +handler(NULL), > #ifdef DEBUG > handler_name(NULL), > #endif > diff --git a/iocore/eventsystem/P_UnixEThread.h > b/iocore/eventsystem/P_UnixEThread.h > index 462de69..1f2c4e7 100644 > --- a/iocore/eventsystem/P_UnixEThread.h > +++ b/iocore/eventsystem/P_UnixEThread.h > @@ -91,6 +91,9 @@ EThread::schedule_every(Continuation * cont, ink_hrtime > t, int callback_event, v > TS_INLINE Event * > EThread::schedule(Event * e, bool fast_signal) > { > +#ifdef CROSS_EVENT_STACK_TRACES > + e->continuation->attach_current_stack_trace(); > +#endif > e->ethread = this; > ink_assert(tt == REGULAR); > if (e->continuation->mutex) > @@ -141,6 +144,9 @@ EThread::schedule_every_local(Continuation * cont, > ink_hrtime t, int callback_ev > TS_INLINE Event * > EThread::schedule_local(Event * e) > { > +#ifdef CROSS_EVENT_STACK_TRACES > + e->continuation->attach_current_stack_trace(); > +#endif > if (tt != REGULAR) { > ink_assert(tt == DEDICATED); > return eventProcessor.schedule(e, ET_CALL); > diff --git a/iocore/eventsystem/P_UnixEventProcessor.h > b/iocore/eventsystem/P_UnixEventProcessor.h > index d9a1e73..bae525e 100644 > --- a/iocore/eventsystem/P_UnixEventProcessor.h > +++ b/iocore/eventsystem/P_UnixEventProcessor.h > @@ -74,6 +74,9 @@ EventProcessor::assign_thread(EventType etype) > TS_INLINE Event * > EventProcessor::schedule(Event * e, EventType etype, bool fast_signal) > { > +#ifdef CROSS_EVENT_STACK_TRACES > + e->continuation->attach_current_stack_trace(); > +#endif > ink_assert(etype < MAX_EVENT_TYPES); > e->ethread = assign_thread(etype); > if (e->continuation->mutex) > diff --git a/iocore/eventsystem/UnixEvent.cc > b/iocore/eventsystem/UnixEvent.cc > index 634cee9..17ecfbf 100644 > --- a/iocore/eventsystem/UnixEvent.cc > +++ b/iocore/eventsystem/UnixEvent.cc > @@ -34,6 +34,9 @@ ClassAllocator<Event> eventAllocator("eventAllocator", > 256); > void > Event::schedule_imm(int acallback_event) > { > +#ifdef CROSS_EVENT_STACK_TRACES > + continuation->attach_current_stack_trace(); > +#endif > callback_event = acallback_event; > ink_assert(ethread == this_ethread()); > if (in_the_priority_queue) > @@ -49,6 +52,9 @@ Event::schedule_imm(int acallback_event) > void > Event::schedule_at(ink_hrtime atimeout_at, int acallback_event) > { > +#ifdef CROSS_EVENT_STACK_TRACES > + continuation->attach_current_stack_trace(); > +#endif > callback_event = acallback_event; > ink_assert(ethread == this_ethread()); > ink_assert(atimeout_at > 0); > @@ -65,6 +71,9 @@ Event::schedule_at(ink_hrtime atimeout_at, int > acallback_event) > void > Event::schedule_in(ink_hrtime atimeout_in, int acallback_event) > { > +#ifdef CROSS_EVENT_STACK_TRACES > + continuation->attach_current_stack_trace(); > +#endif > callback_event = acallback_event; > ink_assert(ethread == this_ethread()); > if (in_the_priority_queue) > @@ -80,6 +89,9 @@ Event::schedule_in(ink_hrtime atimeout_in, int > acallback_event) > void > Event::schedule_every(ink_hrtime aperiod, int acallback_event) > { > +#ifdef CROSS_EVENT_STACK_TRACES > + continuation->attach_current_stack_trace(); > +#endif > callback_event = acallback_event; > ink_assert(ethread == this_ethread()); > ink_assert(aperiod != 0);
