[ARROW-2831] [Plasma] MemoryError in teardown

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Cannot Reproduce
• Fix Version/s: 0.12.0
• Component/s: C++ - Plasma
• External issue URL: https://github.com/apache/arrow/issues/19208
• Assignee: Unassigned
• Reporter: Uwe Korn
• Created: 11/Jul/18 11:35
• Updated: 11/Jan/23 07:23
• Resolved: 19/Nov/18 19:59

Description

There seems to be some flakiness in Plasma tests, e.g. see: https://api.travis-ci.org/v3/job/402544643/log.txt

==================================== ERRORS ====================================
_____________ ERROR at teardown of TestPlasmaClient.test_subscribe _____________

self = <pyarrow.tests.test_plasma.TestPlasmaClient object at 0x7f9a3dcd5f50>
test_method = <bound method TestPlasmaClient.test_subscribe of <pyarrow.tests.test_plasma.TestPlasmaClient object at 0x7f9a3dcd5f50>>

    def teardown_method(self, test_method):
        try:
            # Check that the Plasma store is still alive.
            assert self.p.poll() is None
            # Ensure Valgrind and/or coverage have a clean exit
            self.p.send_signal(signal.SIGTERM)
            if sys.version_info >= (3, 3):
                self.p.wait(timeout=5)
            else:
                self.p.wait()
>           assert self.p.returncode == 0
E           assert 1 == 0
E            +  where 1 = <subprocess.Popen object at 0x7f9a3dcd5850>.returncode
E            +    where <subprocess.Popen object at 0x7f9a3dcd5850> = <pyarrow.tests.test_plasma.TestPlasmaClient object at 0x7f9a3dcd5f50>.p

pyarrow/tests/test_plasma.py:132: AssertionError
---------------------------- Captured stderr setup -----------------------------
==20909== Memcheck, a memory error detector
==20909== Copyright (C) 2002-2013, and GNU GPL'd, by Julian Seward et al.
==20909== Using Valgrind-3.10.1 and LibVEX; rerun with -h for copyright info
==20909== Command: /home/travis/build/apache/arrow/python/pyarrow/plasma_store -s /tmp/test_plasma-Dzj8IQ/plasma.sock -m 100000000
==20909== 
Allowing the Plasma store to use up to 0.1GB of memory.
Connection to IPC socket failed for pathname /tmp/test_plasma-Dzj8IQ/plasma.sock, retrying 50 more times
Starting object store with directory /dev/shm and huge page support disabled
Connection to IPC socket failed for pathname /tmp/test_plasma-Dzj8IQ/plasma.sock, retrying 49 more times
--------------------------- Captured stderr teardown ---------------------------
==20909== Invalid free() / delete / delete[] / realloc()
==20909==    at 0x4C2C83C: operator delete[](void*) (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==20909==    by 0x4A870A: std::default_delete<unsigned char []>::operator()(unsigned char*) const (unique_ptr.h:99)
==20909==    by 0x4A0D6C: std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >::~unique_ptr() (unique_ptr.h:377)
==20909==    by 0x4C3AE1: void std::_Destroy<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > >(std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*) (stl_construct.h:93)
==20909==    by 0x4C2DD4: void std::_Destroy_aux<false>::__destroy<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>(std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*) (stl_construct.h:103)
==20909==    by 0x4C1999: void std::_Destroy<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>(std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*) (stl_construct.h:126)
==20909==    by 0x4BF460: void std::_Destroy<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > >(std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*, std::allocator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > >&) (stl_construct.h:151)
==20909==    by 0x4B9D41: std::deque<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::allocator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > > >::_M_destroy_data_aux(std::_Deque_iterator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >&, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>, std::_Deque_iterator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >&, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>) (deque.tcc:806)
==20909==    by 0x4B17DA: std::deque<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::allocator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > > >::_M_destroy_data(std::_Deque_iterator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >&, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>, std::_Deque_iterator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >&, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>, std::allocator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > > const&) (stl_deque.h:1853)
==20909==    by 0x4C06F8: std::deque<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::allocator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > > >::~deque() (stl_deque.h:918)
==20909==    by 0x4BBC83: plasma::NotificationQueue::~NotificationQueue() (store.h:38)
==20909==    by 0x4BBCC5: std::pair<int const, plasma::NotificationQueue>::~pair() (stl_pair.h:96)
==20909==  Address 0x600a6d0 is 0 bytes inside a block of size 104 free'd
==20909==    at 0x4C2C83C: operator delete[](void*) (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==20909==    by 0x4A870A: std::default_delete<unsigned char []>::operator()(unsigned char*) const (unique_ptr.h:99)
==20909==    by 0x4A0D6C: std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >::~unique_ptr() (unique_ptr.h:377)
==20909==    by 0x4C3AE1: void std::_Destroy<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > >(std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*) (stl_construct.h:93)
==20909==    by 0x4C2DD4: void std::_Destroy_aux<false>::__destroy<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>(std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*) (stl_construct.h:103)
==20909==    by 0x4C1999: void std::_Destroy<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>(std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*) (stl_construct.h:126)
==20909==    by 0x4BF460: void std::_Destroy<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > >(std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*, std::allocator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > >&) (stl_construct.h:151)
==20909==    by 0x4B9D41: std::deque<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::allocator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > > >::_M_destroy_data_aux(std::_Deque_iterator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >&, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>, std::_Deque_iterator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >&, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>) (deque.tcc:806)
==20909==    by 0x4B17DA: std::deque<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::allocator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > > >::_M_destroy_data(std::_Deque_iterator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >&, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>, std::_Deque_iterator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >&, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>, std::allocator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > > const&) (stl_deque.h:1853)
==20909==    by 0x4A82DC: std::deque<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::allocator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > > >::_M_erase_at_end(std::_Deque_iterator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >&, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>) (stl_deque.h:1870)
==20909==    by 0x4A7DF5: std::deque<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::allocator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > > >::clear() (stl_deque.h:1617)
==20909==    by 0x4A043D: std::deque<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::allocator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> > > >::erase(std::_Deque_iterator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >&, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>, std::_Deque_iterator<std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >&, std::unique_ptr<unsigned char [], std::default_delete<unsigned char []> >*>) (deque.tcc:223)
==20909== 
==20909== 
==20909== HEAP SUMMARY:
==20909==     in use at exit: 75,009 bytes in 6 blocks
==20909==   total heap usage: 35,200 allocs, 35,195 frees, 4,080,337 bytes allocated
==20909== 
==20909== 33 bytes in 1 blocks are still reachable in loss record 1 of 3
==20909==    at 0x4C2B0E0: operator new(unsigned long) (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==20909==    by 0x510EBBE: allocate (new_allocator.h:111)
==20909==    by 0x510EBBE: std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) (basic_string.tcc:1057)
==20909==    by 0x510ED47: std::string::_M_mutate(unsigned long, unsigned long, unsigned long) (basic_string.tcc:929)
==20909==    by 0x510F16B: std::string::_M_replace_safe(unsigned long, unsigned long, char const*, unsigned long) (basic_string.tcc:1134)
==20909==    by 0x497D4E: main (store.cc:912)
==20909== 
==20909== 2,272 bytes in 4 blocks are still reachable in loss record 2 of 3
==20909==    at 0x4C2AB80: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==20909==    by 0x5914C81: fdopen@@GLIBC_2.2.5 (iofdopen.c:138)
==20909==    by 0x4DEF51: create_buffer(long) (malloc.cc:105)
==20909==    by 0x4DFA1D: fake_mmap (malloc.cc:135)
==20909==    by 0x4E05EC: sys_alloc (dlmalloc.c:4155)
==20909==    by 0x4E05EC: dlmalloc (dlmalloc.c:4680)
==20909==    by 0x4E39D9: internal_memalign (dlmalloc.c:4917)
==20909==    by 0x4E39D9: dlmemalign (dlmalloc.c:5275)
==20909==    by 0x48A912: plasma::PlasmaStore::create_object(plasma::UniqueID const&, long, long, int, plasma::Client*, plasma::PlasmaObject*) (store.cc:175)
==20909==    by 0x492BE4: plasma::PlasmaStore::process_message(plasma::Client*) (store.cc:715)
==20909==    by 0x48FCB3: plasma::PlasmaStore::connect_client(int)::{lambda(int)#1}::operator()(int) const (store.cc:525)
==20909==    by 0x498F05: std::_Function_handler<void (int), plasma::PlasmaStore::connect_client(int)::{lambda(int)#1}>::_M_invoke(std::_Any_data const&, int) (functional:2071)
==20909==    by 0x4CDFAB: std::function<void (int)>::operator()(int) const (functional:2471)
==20909==    by 0x4CD3FC: plasma::EventLoop::FileEventCallback(aeEventLoop*, int, void*, int) (events.cc:28)
==20909== 
==20909== 72,704 bytes in 1 blocks are still reachable in loss record 3 of 3
==20909==    at 0x4C2AB80: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==20909==    by 0x50E6795: pool (eh_alloc.cc:123)
==20909==    by 0x50E6795: __static_initialization_and_destruction_0 (eh_alloc.cc:262)
==20909==    by 0x50E6795: _GLOBAL__sub_I_eh_alloc.cc (eh_alloc.cc:338)
==20909==    by 0x40101D9: call_init.part.0 (dl-init.c:78)
==20909==    by 0x40102C2: call_init (dl-init.c:36)
==20909==    by 0x40102C2: _dl_init (dl-init.c:126)
==20909==    by 0x4001299: ??? (in /lib/x86_64-linux-gnu/ld-2.19.so)
==20909==    by 0x4: ???
==20909==    by 0xFFEFFEFF6: ???
==20909==    by 0xFFEFFF032: ???
==20909==    by 0xFFEFFF035: ???
==20909==    by 0xFFEFFF059: ???
==20909==    by 0xFFEFFF05C: ???
==20909== 
==20909== LEAK SUMMARY:
==20909==    definitely lost: 0 bytes in 0 blocks
==20909==    indirectly lost: 0 bytes in 0 blocks
==20909==      possibly lost: 0 bytes in 0 blocks
==20909==    still reachable: 75,009 bytes in 6 blocks
==20909==                       of which reachable via heuristic:
==20909==                         stdstring          : 33 bytes in 1 blocks
==20909==         suppressed: 0 bytes in 0 blocks
==20909== 
==20909== For counts of detected and suppressed errors, rerun with: -v
==20909== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 0 from 0)