[CD] test_profiler failing for cpu on python 2

[perdasilva]

Description

The python 2 tests are failing against the statically linked cpu variant of libmxnet:

Jenkins log

======================================================================
ERROR: test_profiler.test_continuous_profile_and_instant_marker
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/nose/case.py", line 197, in runTest
    self.test(*self.arg)
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 222, in test_continuous_profile_and_instant_marker
    enable_profiler(file_name, True, True, True)
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 37, in enable_profiler
    aggregate_stats=aggregate_stats
  File "/work/mxnet/python/mxnet/profiler.py", line 67, in set_config
    profiler_kvstore_handle))
  File "/work/mxnet/python/mxnet/base.py", line 254, in check_call
    raise MXNetError(py_str(_LIB.MXGetLastError()))
MXNetError: [20:07:40] /work/mxnet/3rdparty/dmlc-core/include/dmlc/thread_group.h:227: Check failed: auto_remove_ == false (1 vs. 0) : 
Stack trace:
  [bt] (0) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x2ee6cb) [0x7f0d452a56cb]
  [bt] (1) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x338332c) [0x7f0d4833a32c]
  [bt] (2) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x3387893) [0x7f0d4833e893]
  [bt] (3) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x338837a) [0x7f0d4833f37a]
  [bt] (4) /work/mxnet/python/mxnet/../../lib/libmxnet.so(MXSetProcessProfilerConfig+0x4ba) [0x7f0d47b1584a]
  [bt] (5) /usr/lib/x86_64-linux-gnu/libffi.so.6(ffi_call_unix64+0x4c) [0x7f0d58a5fe40]
  [bt] (6) /usr/lib/x86_64-linux-gnu/libffi.so.6(ffi_call+0x2eb) [0x7f0d58a5f8ab]
  [bt] (7) /usr/lib/python2.7/lib-dynload/_ctypes.x86_64-linux-gnu.so(_ctypes_callproc+0x48f) [0x7f0d58c6f3df]
  [bt] (8) /usr/lib/python2.7/lib-dynload/_ctypes.x86_64-linux-gnu.so(+0x11d82) [0x7f0d58c73d82]

======================================================================
ERROR: test_profiler.test_aggregate_stats_valid_json_return
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/nose/case.py", line 197, in runTest
    self.test(*self.arg)
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 242, in test_aggregate_stats_valid_json_return
    enable_profiler(file_name, True, True, True)
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 37, in enable_profiler
    aggregate_stats=aggregate_stats
  File "/work/mxnet/python/mxnet/profiler.py", line 67, in set_config
    profiler_kvstore_handle))
  File "/work/mxnet/python/mxnet/base.py", line 254, in check_call
    raise MXNetError(py_str(_LIB.MXGetLastError()))
MXNetError: [20:07:40] /work/mxnet/3rdparty/dmlc-core/include/dmlc/thread_group.h:227: Check failed: auto_remove_ == false (1 vs. 0) : 
Stack trace:
  [bt] (0) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x2ee6cb) [0x7f0d452a56cb]
  [bt] (1) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x338332c) [0x7f0d4833a32c]
  [bt] (2) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x3387893) [0x7f0d4833e893]
  [bt] (3) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x338837a) [0x7f0d4833f37a]
  [bt] (4) /work/mxnet/python/mxnet/../../lib/libmxnet.so(MXSetProcessProfilerConfig+0x4ba) [0x7f0d47b1584a]
  [bt] (5) /usr/lib/x86_64-linux-gnu/libffi.so.6(ffi_call_unix64+0x4c) [0x7f0d58a5fe40]
  [bt] (6) /usr/lib/x86_64-linux-gnu/libffi.so.6(ffi_call+0x2eb) [0x7f0d58a5f8ab]
  [bt] (7) /usr/lib/python2.7/lib-dynload/_ctypes.x86_64-linux-gnu.so(_ctypes_callproc+0x48f) [0x7f0d58c6f3df]
  [bt] (8) /usr/lib/python2.7/lib-dynload/_ctypes.x86_64-linux-gnu.so(+0x11d82) [0x7f0d58c73d82]

======================================================================
ERROR: test_profiler.test_aggregate_stats_sorting
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/nose/case.py", line 197, in runTest
    self.test(*self.arg)
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 272, in test_aggregate_stats_sorting
    enable_profiler(file_name, True, True, True)
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 37, in enable_profiler
    aggregate_stats=aggregate_stats
  File "/work/mxnet/python/mxnet/profiler.py", line 67, in set_config
    profiler_kvstore_handle))
  File "/work/mxnet/python/mxnet/base.py", line 254, in check_call
    raise MXNetError(py_str(_LIB.MXGetLastError()))
MXNetError: [20:07:40] /work/mxnet/3rdparty/dmlc-core/include/dmlc/thread_group.h:227: Check failed: auto_remove_ == false (1 vs. 0) : 
Stack trace:
  [bt] (0) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x2ee6cb) [0x7f0d452a56cb]
  [bt] (1) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x338332c) [0x7f0d4833a32c]
  [bt] (2) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x3387893) [0x7f0d4833e893]
  [bt] (3) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x338837a) [0x7f0d4833f37a]
  [bt] (4) /work/mxnet/python/mxnet/../../lib/libmxnet.so(MXSetProcessProfilerConfig+0x4ba) [0x7f0d47b1584a]
  [bt] (5) /usr/lib/x86_64-linux-gnu/libffi.so.6(ffi_call_unix64+0x4c) [0x7f0d58a5fe40]
  [bt] (6) /usr/lib/x86_64-linux-gnu/libffi.so.6(ffi_call+0x2eb) [0x7f0d58a5f8ab]
  [bt] (7) /usr/lib/python2.7/lib-dynload/_ctypes.x86_64-linux-gnu.so(_ctypes_callproc+0x48f) [0x7f0d58c6f3df]
  [bt] (8) /usr/lib/python2.7/lib-dynload/_ctypes.x86_64-linux-gnu.so(+0x11d82) [0x7f0d58c73d82]

======================================================================
ERROR: test_profiler.test_aggregate_duplication
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/nose/case.py", line 197, in runTest
    self.test(*self.arg)
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 284, in test_aggregate_duplication
    aggregate_stats=True)
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 37, in enable_profiler
    aggregate_stats=aggregate_stats
  File "/work/mxnet/python/mxnet/profiler.py", line 67, in set_config
    profiler_kvstore_handle))
  File "/work/mxnet/python/mxnet/base.py", line 254, in check_call
    raise MXNetError(py_str(_LIB.MXGetLastError()))
MXNetError: [20:07:40] /work/mxnet/3rdparty/dmlc-core/include/dmlc/thread_group.h:227: Check failed: auto_remove_ == false (1 vs. 0) : 
Stack trace:
  [bt] (0) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x2ee6cb) [0x7f0d452a56cb]
  [bt] (1) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x338332c) [0x7f0d4833a32c]
  [bt] (2) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x3387893) [0x7f0d4833e893]
  [bt] (3) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x338837a) [0x7f0d4833f37a]
  [bt] (4) /work/mxnet/python/mxnet/../../lib/libmxnet.so(MXSetProcessProfilerConfig+0x4ba) [0x7f0d47b1584a]
  [bt] (5) /usr/lib/x86_64-linux-gnu/libffi.so.6(ffi_call_unix64+0x4c) [0x7f0d58a5fe40]
  [bt] (6) /usr/lib/x86_64-linux-gnu/libffi.so.6(ffi_call+0x2eb) [0x7f0d58a5f8ab]
  [bt] (7) /usr/lib/python2.7/lib-dynload/_ctypes.x86_64-linux-gnu.so(_ctypes_callproc+0x48f) [0x7f0d58c6f3df]
  [bt] (8) /usr/lib/python2.7/lib-dynload/_ctypes.x86_64-linux-gnu.so(+0x11d82) [0x7f0d58c73d82]

======================================================================
ERROR: test_profiler.test_custom_operator_profiling
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/nose/case.py", line 197, in runTest
    self.test(*self.arg)
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 344, in test_custom_operator_profiling
    aggregate_stats=True)
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 37, in enable_profiler
    aggregate_stats=aggregate_stats
  File "/work/mxnet/python/mxnet/profiler.py", line 67, in set_config
    profiler_kvstore_handle))
  File "/work/mxnet/python/mxnet/base.py", line 254, in check_call
    raise MXNetError(py_str(_LIB.MXGetLastError()))
MXNetError: [20:07:40] /work/mxnet/3rdparty/dmlc-core/include/dmlc/thread_group.h:227: Check failed: auto_remove_ == false (1 vs. 0) : 
Stack trace:
  [bt] (0) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x2ee6cb) [0x7f0d452a56cb]
  [bt] (1) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x338332c) [0x7f0d4833a32c]
  [bt] (2) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x3387893) [0x7f0d4833e893]
  [bt] (3) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x338837a) [0x7f0d4833f37a]
  [bt] (4) /work/mxnet/python/mxnet/../../lib/libmxnet.so(MXSetProcessProfilerConfig+0x4ba) [0x7f0d47b1584a]
  [bt] (5) /usr/lib/x86_64-linux-gnu/libffi.so.6(ffi_call_unix64+0x4c) [0x7f0d58a5fe40]
  [bt] (6) /usr/lib/x86_64-linux-gnu/libffi.so.6(ffi_call+0x2eb) [0x7f0d58a5f8ab]
  [bt] (7) /usr/lib/python2.7/lib-dynload/_ctypes.x86_64-linux-gnu.so(_ctypes_callproc+0x48f) [0x7f0d58c6f3df]
  [bt] (8) /usr/lib/python2.7/lib-dynload/_ctypes.x86_64-linux-gnu.so(+0x11d82) [0x7f0d58c73d82]

======================================================================
ERROR: test_profiler.test_custom_operator_profiling_multiple_custom_ops_symbolic
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/nose/case.py", line 197, in runTest
    self.test(*self.arg)
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 441, in test_custom_operator_profiling_multiple_custom_ops_symbolic
    'test_custom_operator_profiling_multiple_custom_ops_symbolic.json')
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 417, in custom_operator_profiling_multiple_custom_ops
    aggregate_stats=True)
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 37, in enable_profiler
    aggregate_stats=aggregate_stats
  File "/work/mxnet/python/mxnet/profiler.py", line 67, in set_config
    profiler_kvstore_handle))
  File "/work/mxnet/python/mxnet/base.py", line 254, in check_call
    raise MXNetError(py_str(_LIB.MXGetLastError()))
MXNetError: [20:07:40] /work/mxnet/3rdparty/dmlc-core/include/dmlc/thread_group.h:227: Check failed: auto_remove_ == false (1 vs. 0) : 
Stack trace:
  [bt] (0) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x2ee6cb) [0x7f0d452a56cb]
  [bt] (1) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x338332c) [0x7f0d4833a32c]
  [bt] (2) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x3387893) [0x7f0d4833e893]
  [bt] (3) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x338837a) [0x7f0d4833f37a]
  [bt] (4) /work/mxnet/python/mxnet/../../lib/libmxnet.so(MXSetProcessProfilerConfig+0x4ba) [0x7f0d47b1584a]
  [bt] (5) /usr/lib/x86_64-linux-gnu/libffi.so.6(ffi_call_unix64+0x4c) [0x7f0d58a5fe40]
  [bt] (6) /usr/lib/x86_64-linux-gnu/libffi.so.6(ffi_call+0x2eb) [0x7f0d58a5f8ab]
  [bt] (7) /usr/lib/python2.7/lib-dynload/_ctypes.x86_64-linux-gnu.so(_ctypes_callproc+0x48f) [0x7f0d58c6f3df]
  [bt] (8) /usr/lib/python2.7/lib-dynload/_ctypes.x86_64-linux-gnu.so(+0x11d82) [0x7f0d58c73d82]

======================================================================
ERROR: test_profiler.test_custom_operator_profiling_multiple_custom_ops_imperative
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/nose/case.py", line 197, in runTest
    self.test(*self.arg)
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 446, in test_custom_operator_profiling_multiple_custom_ops_imperative
    'test_custom_operator_profiling_multiple_custom_ops_imperative.json')
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 417, in custom_operator_profiling_multiple_custom_ops
    aggregate_stats=True)
  File "/work/mxnet/tests/python/unittest/test_profiler.py", line 37, in enable_profiler
    aggregate_stats=aggregate_stats
  File "/work/mxnet/python/mxnet/profiler.py", line 67, in set_config
    profiler_kvstore_handle))
  File "/work/mxnet/python/mxnet/base.py", line 254, in check_call
    raise MXNetError(py_str(_LIB.MXGetLastError()))
MXNetError: [20:07:40] /work/mxnet/3rdparty/dmlc-core/include/dmlc/thread_group.h:227: Check failed: auto_remove_ == false (1 vs. 0) : 
Stack trace:
  [bt] (0) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x2ee6cb) [0x7f0d452a56cb]
  [bt] (1) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x338332c) [0x7f0d4833a32c]
  [bt] (2) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x3387893) [0x7f0d4833e893]
  [bt] (3) /work/mxnet/python/mxnet/../../lib/libmxnet.so(+0x338837a) [0x7f0d4833f37a]
  [bt] (4) /work/mxnet/python/mxnet/../../lib/libmxnet.so(MXSetProcessProfilerConfig+0x4ba) [0x7f0d47b1584a]
  [bt] (5) /usr/lib/x86_64-linux-gnu/libffi.so.6(ffi_call_unix64+0x4c) [0x7f0d58a5fe40]
  [bt] (6) /usr/lib/x86_64-linux-gnu/libffi.so.6(ffi_call+0x2eb) [0x7f0d58a5f8ab]
  [bt] (7) /usr/lib/python2.7/lib-dynload/_ctypes.x86_64-linux-gnu.so(_ctypes_callproc+0x48f) [0x7f0d58c6f3df]
  [bt] (8) /usr/lib/python2.7/lib-dynload/_ctypes.x86_64-linux-gnu.so(+0x11d82) [0x7f0d58c73d82]

Environment info (Required)

ubuntu_cpu docker environment.

[mxnet-label-bot]

Hey, this is the MXNet Label Bot.
Thank you for submitting the issue! I will try and suggest some labels so that the appropriate MXNet community members can help resolve it.
Here are my recommended label(s): Test

[samskalicky]

@zachgk close this issue as the problem is resolved

[zachgk]

This issue also reoccurred on http://jenkins.mxnet-ci-dev.amazon-ml.com/blue/organizations/jenkins/restricted-mxnet-cd%2Fmxnet-cd-release-job/detail/mxnet-cd-release-job/227/pipeline/. I am not sure that it is resolved

[szha]

http://jenkins.mxnet-ci.amazon-ml.com/blue/rest/organizations/jenkins/pipelines/mxnet-validation/pipelines/unix-gpu/branches/PR-18146/runs/33/nodes/417/steps/529/log/?start=0

=================================== FAILURES ===================================
_________ test_custom_operator_profiling_multiple_custom_ops_symbolic __________
[gw1] linux -- Python 3.6.9 /opt/rh/rh-python36/root/usr/bin/python

    def test_custom_operator_profiling_multiple_custom_ops_symbolic():
        custom_operator_profiling_multiple_custom_ops(None, 'symbolic', \
>               'test_custom_operator_profiling_multiple_custom_ops_symbolic.json')

tests/python/unittest/test_profiler.py:442:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
tests/python/unittest/test_profiler.py:418: in custom_operator_profiling_multiple_custom_ops
    aggregate_stats=True)
tests/python/unittest/test_profiler.py:40: in enable_profiler
    aggregate_stats=aggregate_stats)
python/mxnet/profiler.py:69: in set_config
    profiler_kvstore_handle))
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

ret = -1

    def check_call(ret):
        """Check the return value of C API call.

        This function will raise an exception when an error occurs.
        Wrap every API call with this function.

        Parameters
        ----------
        ret : int
            return value from API calls.
        """
        if ret != 0:
>           raise get_last_ffi_error()
E           mxnet.base.MXNetError: Traceback (most recent call last):
E             File "/work/mxnet/include/dmlc/thread_group.h", line 226
E           MXNetError: Check failed: auto_remove_ == false (1 vs. 0) :

python/mxnet/base.py:246: MXNetError
---------------------------- Captured stderr setup -----------------------------
DEBUG:root:np/mx/python random seeds are set to 1919136079, use MXNET_TEST_SEED=1919136079 to reproduce.
------------------------------ Captured log setup ------------------------------
DEBUG    root:conftest.py:187 np/mx/python random seeds are set to 1919136079, use MXNET_TEST_SEED=1919136079 to reproduce.
--------------------------- Captured stderr teardown ---------------------------
INFO:root:np/mx/python random seeds are set to 1919136079, use MXNET_TEST_SEED=1919136079 to reproduce.
---------------------------- Captured log teardown -----------------------------
INFO     root:conftest.py:204 np/mx/python random seeds are set to 1919136079, use MXNET_TEST_SEED=1919136079 to reproduce.
________ test_custom_operator_profiling_multiple_custom_ops_imperative _________
[gw1] linux -- Python 3.6.9 /opt/rh/rh-python36/root/usr/bin/python

    def test_custom_operator_profiling_multiple_custom_ops_imperative():
        custom_operator_profiling_multiple_custom_ops(None, 'imperative', \
>               'test_custom_operator_profiling_multiple_custom_ops_imperative.json')

tests/python/unittest/test_profiler.py:447:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
tests/python/unittest/test_profiler.py:418: in custom_operator_profiling_multiple_custom_ops
    aggregate_stats=True)
tests/python/unittest/test_profiler.py:40: in enable_profiler
    aggregate_stats=aggregate_stats)
python/mxnet/profiler.py:69: in set_config
    profiler_kvstore_handle))
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

ret = -1

    def check_call(ret):
        """Check the return value of C API call.

        This function will raise an exception when an error occurs.
        Wrap every API call with this function.

        Parameters
        ----------
        ret : int
            return value from API calls.
        """
        if ret != 0:
>           raise get_last_ffi_error()
E           mxnet.base.MXNetError: Traceback (most recent call last):
E             File "/work/mxnet/include/dmlc/thread_group.h", line 226
E           MXNetError: Check failed: auto_remove_ == false (1 vs. 0) :

python/mxnet/base.py:246: MXNetError
---------------------------- Captured stderr setup -----------------------------
DEBUG:root:np/mx/python random seeds are set to 1280101854, use MXNET_TEST_SEED=1280101854 to reproduce.
------------------------------ Captured log setup ------------------------------
DEBUG    root:conftest.py:187 np/mx/python random seeds are set to 1280101854, use MXNET_TEST_SEED=1280101854 to reproduce.
----------------------------- Captured stderr call -----------------------------
[00:44:25] /work/mxnet/src/c_api/../operator/custom/custom-inl.h:57: New registration is overriding existing custom operator MyAdd1
[00:44:25] /work/mxnet/src/c_api/../operator/custom/custom-inl.h:57: New registration is overriding existing custom operator MyAdd2
--------------------------- Captured stderr teardown ---------------------------
INFO:root:np/mx/python random seeds are set to 1280101854, use MXNET_TEST_SEED=1280101854 to reproduce.
---------------------------- Captured log teardown -----------------------------
INFO     root:conftest.py:204 np/mx/python random seeds are set to 1280101854, use MXNET_TEST_SEED=1280101854 to reproduce.