Loading...

Details

Type: Bug
Resolution: Incomplete
Priority: Major
Fix Version/s: None
Affects Version/s: master
Component/s: phosphor
Labels:
- WillG

Triage:
Untriaged
Is this a Regression?:
Unknown

Description

Issue is seen when using a fixed size buffer and save-on-stop.
Once the buffer fills up the event tracing is stopped. At this point the FileStopCallback is invoked which calls the FixedTraceBuffer destructor.
This results in the deallocation of a large amount of memory.
Unfortunately ep-engine's memory tracking records this deallocation as part of its own memory deallocation and therefore the ep-engine memory tracking get corrupted.

See below for a backtrace, when the following assert is added to ObjectRegistry::memoryDeallocated

    cb_assert(stats.totalMemory < uint64_t{1} << 63);

* thread #1: tid = 0x32e04b, 0x00007fff962bcf06 libsystem_kernel.dylib`__pthread_kill + 10, queue = 'com.apple.main-thread, stop reason = signal SIGABRT

  * frame #0: 0x00007fff962bcf06 libsystem_kernel.dylib` __pthread_kill  + 10

    frame #1: 0x00007fff89c594ec libsystem_pthread.dylib` pthread_kill  + 90

    frame #2: 0x00007fff8e7466df libsystem_c.dylib` abort  + 129

    frame #3: 0x00000001000a61eb libplatform_so.0.1.0.dylib` cb_assert_die(expression=<unavailable>, file=<unavailable>, line=<unavailable>)  + 91 at cbassert.c:46

    frame #4: 0x00000001012fa446 ep.dylib` ObjectRegistry::memoryDeallocated(mem=<unavailable>)  + 118 at objectregistry.cc:207

    frame #5: 0x00000001000a5eba libplatform_so.0.1.0.dylib` ::cb_free(void *) [inlined] cb_invoke_delete_hook(void const*)  + 26 at cb_malloc.cc:140

    frame #6: 0x00000001000a5ea9 libplatform_so.0.1.0.dylib` ::cb_free(ptr=0x0000000104800000)  + 9 at cb_malloc.cc:80

    frame #7: 0x00000001000c11fc libphosphor.dylib` phosphor::FixedTraceBuffer::~FixedTraceBuffer() [inlined] gsl_p::dyn_array<phosphor::TraceChunk>::__deallocate(phosphor::TraceChunk*)  + 28 at dyn_array.h:379

    frame #8: 0x00000001000c11f7 libphosphor.dylib` phosphor::FixedTraceBuffer::~FixedTraceBuffer() [inlined] gsl_p::dyn_array<phosphor::TraceChunk>::~dyn_array()  + 4 at dyn_array.h:482

    frame #9: 0x00000001000c11f3 libphosphor.dylib` phosphor::FixedTraceBuffer::~FixedTraceBuffer() [inlined] gsl_p::dyn_array<phosphor::TraceChunk>::~dyn_array()  at dyn_array.h:478

    frame #10: 0x00000001000c11f3 libphosphor.dylib` phosphor::FixedTraceBuffer::~FixedTraceBuffer() [inlined] phosphor::FixedTraceBuffer::~FixedTraceBuffer(this=0x000000010101a2f0)  + 10 at trace_buffer.cc:104

    frame #11: 0x00000001000c11e9 libphosphor.dylib` phosphor::FixedTraceBuffer::~FixedTraceBuffer() [inlined] phosphor::FixedTraceBuffer::~FixedTraceBuffer(this=0x000000010101a2f0)  at trace_buffer.cc:104

    frame #12: 0x00000001000c11e9 libphosphor.dylib` phosphor::FixedTraceBuffer::~FixedTraceBuffer(this=0x000000010101a2f0)  + 9 at trace_buffer.cc:104

    frame #13: 0x00000001000cac6f libphosphor.dylib` phosphor::tools::FileStopCallback::operator()(phosphor::TraceLog&, std::__1::lock_guard<phosphor::TraceLog>&) [inlined] std::__1::default_delete<phosphor::TraceBuffer>::operator(__ptr=<unavailable>)(phosphor::TraceBuffer*) const  + 639 at memory:2516

    frame #14: 0x00000001000cac69 libphosphor.dylib` phosphor::tools::FileStopCallback::operator()(phosphor::TraceLog&, std::__1::lock_guard<phosphor::TraceLog>&) [inlined] std::__1::unique_ptr<phosphor::TraceBuffer, std::__1::default_delete<phosphor::TraceBuffer> >::reset(phosphor::TraceBuffer*)  + 23 at memory:2715

    frame #15: 0x00000001000cac52 libphosphor.dylib` phosphor::tools::FileStopCallback::operator()(phosphor::TraceLog&, std::__1::lock_guard<phosphor::TraceLog>&) [inlined] std::__1::unique_ptr<phosphor::TraceBuffer, std::__1::default_delete<phosphor::TraceBuffer> >::~unique_ptr()  at memory:2683

    frame #16: 0x00000001000cac52 libphosphor.dylib` phosphor::tools::FileStopCallback::operator()(phosphor::TraceLog&, std::__1::lock_guard<phosphor::TraceLog>&) [inlined] std::__1::unique_ptr<phosphor::TraceBuffer, std::__1::default_delete<phosphor::TraceBuffer> >::~unique_ptr()  at memory:2683

    frame #17: 0x00000001000cac52 libphosphor.dylib` phosphor::tools::FileStopCallback::operator()(phosphor::TraceLog&, std::__1::lock_guard<phosphor::TraceLog>&) [inlined] phosphor::TraceContext::~TraceContext()  + 89 at trace_context.h:37

    frame #18: 0x00000001000cabf9 libphosphor.dylib` phosphor::tools::FileStopCallback::operator()(phosphor::TraceLog&, std::__1::lock_guard<phosphor::TraceLog>&) [inlined] phosphor::TraceContext::~TraceContext()  at trace_context.h:37

    frame #19: 0x00000001000cabf9 libphosphor.dylib` phosphor::tools::FileStopCallback::operator(this=<unavailable>, log=<unavailable>, lh=<unavailable>)(phosphor::TraceLog&, std::__1::lock_guard<phosphor::TraceLog>&)  + 521 at export.cc:160

    frame #20: 0x00000001000c7ba6 libphosphor.dylib` phosphor::TraceLog::stop(std::__1::lock_guard<phosphor::TraceLog>&, bool) [inlined] std::__1::function<void (phosphor::TraceLog&, std::__1::lock_guard<phosphor::TraceLog>&)>::operator()(phosphor::TraceLog&, std::__1::lock_guard<phosphor::TraceLog>&) const  + 166 at functional:1817

    frame #21: 0x00000001000c7b8e libphosphor.dylib` phosphor::TraceLog::stop(this=<unavailable>, lh=<unavailable>, shutdown=<unavailable>)  + 142 at trace_log.cc:91

    frame #22: 0x00000001000c8676 libphosphor.dylib` phosphor::TraceLog::getChunkTenant() [inlined] phosphor::TraceLog::stop(shutdown=false)  + 30 at trace_log.cc:82

    frame #23: 0x00000001000c8658 libphosphor.dylib` phosphor::TraceLog::getChunkTenant(this=<unavailable>)  + 232 at trace_log.cc:229

    frame #24: 0x0000000101206ae4 ep.dylib` phosphor::TraceLog::logEvent(this=<unavailable>, tpi=0x0000000101347818, type=SyncStart)  + 36 at trace_log.h:208

    frame #25: 0x00000001012fcaaf ep.dylib` Configuration::addStats(this=0x000000010103da28, add_stat=(ep_perfsuite.dylib`::add_stats(const char *, uint16_t, const char *, uint32_t, const void *) at ep_test_apis.cc:227), c=0x000000010102e0c0)(char const*, unsigned short, char const*, unsigned int, void const*), void const*) const  + 1103 at configuration.cc:344

    frame #26: 0x000000010126a600 ep.dylib` EventuallyPersistentEngine::doEngineStats(this=0x000000010103d000, cookie=0x000000010102e0c0, add_stat=(ep_perfsuite.dylib`::add_stats(const char *, uint16_t, const char *, uint32_t, const void *) at ep_test_apis.cc:227))(char const*, unsigned short, char const*, unsigned int, void const*))  + 2128 at ep_engine.cc:3131

    frame #27: 0x0000000101270f55 ep.dylib` EventuallyPersistentEngine::getStats(this=0x000000010103d000, cookie=0x000000010102e0c0, stat_key=<unavailable>, nkey=<unavailable>, add_stat=(ep_perfsuite.dylib`::add_stats(const char *, uint16_t, const char *, uint32_t, const void *) at ep_test_apis.cc:227))(char const*, unsigned short, char const*, unsigned int, void const*))  + 341 at ep_engine.cc:4708

    frame #28: 0x0000000101263568 ep.dylib` EvpGetStats(handle=0x000000010103d000, cookie=<unavailable>, stat_key=<unavailable>, nkey=<unavailable>, add_stat=<unavailable>)(char const*, unsigned short, char const*, unsigned int, void const*))  + 56 at ep_engine.cc:230

    frame #29: 0x0000000100005f32 engine_testapp` mock_get_stats(engine_interface*, void const*, char const*, int, void (*)(char const*, unsigned short, char const*, unsigned int, void const*)) [inlined] std::__1::function<ENGINE_ERROR_CODE ()>::operator()() const  + 24 at functional:1817

    frame #30: 0x0000000100005f1a engine_testapp` mock_get_stats(engine_interface*, void const*, char const*, int, void (*)(char const*, unsigned short, char const*, unsigned int, void const*)) [inlined] call_engine_and_handle_EWOULDBLOCK(engine_interface*, mock_connstruct*, std::__1::function<ENGINE_ERROR_CODE ()>)  + 27 at engine_testapp.cc:128

    frame #31: 0x0000000100005eff engine_testapp` mock_get_stats(handle=<unavailable>, cookie=0x000000010102e0c0, stat_key=<unavailable>, nkey=<unavailable>, add_stat=(ep_perfsuite.dylib`::add_stats(const char *, uint16_t, const char *, uint32_t, const void *) at ep_test_apis.cc:227))(char const*, unsigned short, char const*, unsigned int, void const*))  + 127 at engine_testapp.cc:220

    frame #32: 0x000000010011ec16 ep_perfsuite.dylib` perf_stat_latency_baseline(engine_interface*, engine_interface_v1*)  + 81 at ep_perfsuite.cc:403

    frame #33: 0x000000010011ebc5 ep_perfsuite.dylib` perf_stat_latency_baseline(engine_interface*, engine_interface_v1*) [inlined] perf_stat_latency(num_docs=100000)  + 509 at ep_perfsuite.cc:428

    frame #34: 0x000000010011e9c8 ep_perfsuite.dylib` perf_stat_latency_baseline(h=0x000000010102b000, h1=0x000000010102b000)  + 72 at ep_perfsuite.cc:1186

    frame #35: 0x0000000100004b57 engine_testapp` main [inlined] execute_test(test=<unavailable>, engine="/Users/danielowen/master/build/ep-engine/ep.so", default_cfg="dbname=./value_eviction_perf")  + 42 at engine_testapp.cc:962

    frame #36: 0x0000000100004b2d engine_testapp` main(argc=<unavailable>, argv=0x00007fff5fbff8a8)  + 8701 at engine_testapp.cc:1359

    frame #37: 0x00007fff94aa95ad libdyld.dylib` start  + 1

    frame #38: 0x00007fff94aa95ad libdyld.dylib` start  + 1

Attachments

Sub-Tasks

1.

Add allocator support to phosphor dyn_array

Open

Unassigned

Gerrit Reviews

- Show All Reviews
- Show Open Reviews
- Show All Issues
- Show Open Issues

No reviews matched the request. Check your Options in the drop-down menu of this sections header.

Phosphor: Memory deletion interacting badly with EP engine memory tracking

Details

Description

Attachments

Sub-Tasks

Gerrit Reviews

Activity

People

Dates

Gerrit Reviews

PagerDuty