ilastik/lazyflow

TestRequest.testMemoryLeaks -- FAIL: As requests become inaccessible, they should be freed immediately, along with any data they held.

jakirkham opened this issue · 7 comments

FAIL: As requests become inaccessible, they should be freed immediately, along with any data they held.

Traceback (most recent call last):
  File "/xopt_ilastik/local/Frameworks/Python.framework/Versions/2.7/lib/python2.7/site-packages/nose-1.2.1-py2.7.egg/nose/case.py", line 197, in runTest
    self.test(*self.arg)
  File "/xopt_ilastik/local/src/ilastik/lazyflow/tests/testRequestRewrite.py", line 669, in testMemoryLeaks
    test_impl(False)
  File "/xopt_ilastik/local/src/ilastik/lazyflow/tests/testRequestRewrite.py", line 665, in test_impl
    result = rootReq.wait()
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 449, in wait
    return self._wait(timeout)
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 472, in _wait
    self._wait_within_foreign_thread( timeout )
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 293, in _execute
    self._result = self.fn()
  File "/xopt_ilastik/local/src/ilastik/lazyflow/tests/testRequestRewrite.py", line 652, in getBigArray
    result = req.wait() + 1
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 449, in wait
    return self._wait(timeout)
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 472, in _wait
    self._wait_within_foreign_thread( timeout )
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 293, in _execute
    self._result = self.fn()
  File "/xopt_ilastik/local/src/ilastik/lazyflow/tests/testRequestRewrite.py", line 652, in getBigArray
    result = req.wait() + 1
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 449, in wait
    return self._wait(timeout)
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 475, in _wait
    self._wait_within_request( current_request )
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 293, in _execute
    self._result = self.fn()
  File "/xopt_ilastik/local/src/ilastik/lazyflow/tests/testRequestRewrite.py", line 652, in getBigArray
    result = req.wait() + 1
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 449, in wait
    return self._wait(timeout)
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 475, in _wait
    self._wait_within_request( current_request )
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 293, in _execute
    self._result = self.fn()
  File "/xopt_ilastik/local/src/ilastik/lazyflow/tests/testRequestRewrite.py", line 652, in getBigArray
    result = req.wait() + 1
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 449, in wait
    return self._wait(timeout)
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 475, in _wait
    self._wait_within_request( current_request )
  File "/xopt_ilastik/local/src/ilastik/lazyflow/lazyflow/request/request.py", line 293, in _execute
    self._result = self.fn()
  File "/xopt_ilastik/local/src/ilastik/lazyflow/tests/testRequestRewrite.py", line 658, in getBigArray
    assert memory_increase < 2.5*resultSize, "Memory from finished requests didn't get freed!"
AssertionError: Memory from finished requests didn't get freed!
-------------------- >> begin captured logging << --------------------
tests.testRequestRewrite: DEBUG: Usage delta before depth 5: -2273280
tests.testRequestRewrite: DEBUG: Usage delta before depth 4: -2297856
tests.testRequestRewrite: DEBUG: Usage delta before depth 3: -2297856
tests.testRequestRewrite: DEBUG: Usage delta before depth 2: -2297856
tests.testRequestRewrite: DEBUG: Usage delta before depth 1: -2297856
tests.testRequestRewrite: DEBUG: Usage delta before depth 0: -2297856
tests.testRequestRewrite: DEBUG: Usage delta after depth 0: 496816128
tests.testRequestRewrite: DEBUG: Usage delta after depth 1: 996630528
tests.testRequestRewrite: DEBUG: Usage delta after depth 2: 997175296
tests.testRequestRewrite: DEBUG: Usage delta after depth 3: 1010556928
tests.testRequestRewrite: DEBUG: Usage delta after depth 4: 1008279552
lazyflow.operators.arrayCacheMemoryMgr.ArrayCacheMemoryMgr: INFO: RAM: 1.742 GB (12%), CPU: Avg=17%, [17.1, 1.8, 8.1, 1.8, 100.0, 0.0, 10.0, 0.9]
tests.testRequestRewrite: DEBUG: Usage delta after depth 5: 1024024576
tests.testRequestRewrite: DEBUG: Usage delta before depth 5: 274743296
tests.testRequestRewrite: DEBUG: Usage delta before depth 4: 280387584
tests.testRequestRewrite: DEBUG: Usage delta before depth 3: 283537408
tests.testRequestRewrite: DEBUG: Usage delta before depth 2: 286330880
tests.testRequestRewrite: DEBUG: Usage delta before depth 1: 293613568
tests.testRequestRewrite: DEBUG: Usage delta before depth 0: 301162496
tests.testRequestRewrite: DEBUG: Usage delta after depth 0: 802832384
tests.testRequestRewrite: DEBUG: Usage delta after depth 1: 1319460864
--------------------- >> end captured logging << ---------------------

Failure appears in-between commits ( 96278e7..902e232 ).

@jakirkham To avoid spamming all ilastik developers, you can also use the "edit" button if you have changes to your message shortly after you sent it. :-)

Sorry @martinsch. I will keep that in mind.

I can't reproduce this test failure on either of my machines. Do you see this failure consistently, or intermittently?

PS -- Ignore my accidental close-from-commit from earlier in this thread.

Here was a travis build with a similar error ( https://travis-ci.org/jakirkham/lazyflow/builds/54961029 ).

I figure that this will keep popping up every once in a while, because the RSS is not guaranteed to reduce immediately after a free() occured. We should probably replace this test by something like

object_to_delete = id(this_should_be_gone)
assert all(map(lambda obj: id(obj) != object_to_delete, gc.get_objects()))

A couple tests in the test suite use the weakref module to make an equivalent check:

With those tests, the testMemoryLeak check is redundant. I've deleted it.