[BUG] Test fails from time to time

[oesteban]

Very scarcely, a test on memory profiling fails this way (see below). Re-running the build in Travis fixes the problem in almost all the times.

======================================================================
FAIL: nipype.pipeline.plugins.tests.test_multiproc.test_do_not_use_more_memory_then_specified(False, True)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/travis/miniconda/lib/python3.5/site-packages/nose/case.py", line 198, in runTest
    self.test(*self.arg)
  File "/home/travis/miniconda/lib/python3.5/site-packages/numpy/testing/utils.py", line 379, in assert_equal
    raise AssertionError(msg)
AssertionError: 
Items are not equal:
 ACTUAL: False
 DESIRED: True
-------------------- >> begin captured logging << --------------------
workflow: INFO: ['check', 'execution', 'logging']
workflow: INFO: Running in parallel.
workflow: INFO: Executing: n1 ID: 0
callback: DEBUG: {"name": "n1", "estimated_memory_gb": 1, "start": "2016-09-08 17:03:00.480465", "num_threads": 1, "id": "n1"}
workflow: INFO: [Job finished] jobname: n1 jobid: 0
callback: DEBUG: {"name": "n1", "runtime_memory_gb": "Unknown", "num_threads": 1, "runtime_threads": "Unknown", "id": "n1", "estimated_memory_gb": 1, "finish": "2016-09-08 17:03:01.402406"}
workflow: INFO: Executing: n2 ID: 1
callback: DEBUG: {"name": "n2", "estimated_memory_gb": 1, "start": "2016-09-08 17:03:01.406857", "num_threads": 1, "id": "n2"}
workflow: INFO: Executing: n3 ID: 2
callback: DEBUG: {"name": "n3", "estimated_memory_gb": 1, "start": "2016-09-08 17:03:01.410650", "num_threads": 1, "id": "n3"}
workflow: INFO: [Job finished] jobname: n2 jobid: 1
callback: DEBUG: {"name": "n2", "runtime_memory_gb": "Unknown", "num_threads": 1, "runtime_threads": "Unknown", "id": "n2", "estimated_memory_gb": 1, "finish": "2016-09-08 17:03:02.021956"}
workflow: INFO: [Job finished] jobname: n3 jobid: 2
callback: DEBUG: {"name": "n3", "runtime_memory_gb": "Unknown", "num_threads": 1, "runtime_threads": "Unknown", "id": "n3", "estimated_memory_gb": 1, "finish": "2016-09-08 17:03:02.024234"}
workflow: INFO: Executing: n4 ID: 3
callback: DEBUG: {"name": "n4", "estimated_memory_gb": 1, "start": "2016-09-08 17:03:02.026717", "num_threads": 1, "id": "n4"}
workflow: INFO: [Job finished] jobname: n4 jobid: 3
callback: DEBUG: {"name": "n4", "runtime_memory_gb": "Unknown", "num_threads": 1, "runtime_threads": "Unknown", "id": "n4", "estimated_memory_gb": 1, "finish": "2016-09-08 17:03:02.957813"}
--------------------- >> end captured logging << ---------------------

[chrisgorgo]

Let's disable this test in master until we figure it out.

On Thu, Sep 8, 2016 at 10:14 AM, Oscar Esteban notifications@github.com
wrote:

Very scarcely, a test on memory profiling fails this way (see below).
Re-running the build in Travis fixes the problem in almost all the times.

FAIL: nipype.pipeline.plugins.tests.test_multiproc.test_do_not_use_more_memory_then_specified(False, True)

Traceback (most recent call last):
File "/home/travis/miniconda/lib/python3.5/site-packages/nose/case.py", line 198, in runTest
self.test(*self.arg)
File "/home/travis/miniconda/lib/python3.5/site-packages/numpy/testing/utils.py", line 379, in assert_equal
raise AssertionError(msg)
AssertionError:
Items are not equal:
ACTUAL: False
DESIRED: True
-------------------- >> begin captured logging << --------------------
workflow: INFO: ['check', 'execution', 'logging']
workflow: INFO: Running in parallel.
workflow: INFO: Executing: n1 ID: 0
callback: DEBUG: {"name": "n1", "estimated_memory_gb": 1, "start": "2016-09-08 17:03:00.480465", "num_threads": 1, "id": "n1"}
workflow: INFO: [Job finished] jobname: n1 jobid: 0
callback: DEBUG: {"name": "n1", "runtime_memory_gb": "Unknown", "num_threads": 1, "runtime_threads": "Unknown", "id": "n1", "estimated_memory_gb": 1, "finish": "2016-09-08 17:03:01.402406"}
workflow: INFO: Executing: n2 ID: 1
callback: DEBUG: {"name": "n2", "estimated_memory_gb": 1, "start": "2016-09-08 17:03:01.406857", "num_threads": 1, "id": "n2"}
workflow: INFO: Executing: n3 ID: 2
callback: DEBUG: {"name": "n3", "estimated_memory_gb": 1, "start": "2016-09-08 17:03:01.410650", "num_threads": 1, "id": "n3"}
workflow: INFO: [Job finished] jobname: n2 jobid: 1
callback: DEBUG: {"name": "n2", "runtime_memory_gb": "Unknown", "num_threads": 1, "runtime_threads": "Unknown", "id": "n2", "estimated_memory_gb": 1, "finish": "2016-09-08 17:03:02.021956"}
workflow: INFO: [Job finished] jobname: n3 jobid: 2
callback: DEBUG: {"name": "n3", "runtime_memory_gb": "Unknown", "num_threads": 1, "runtime_threads": "Unknown", "id": "n3", "estimated_memory_gb": 1, "finish": "2016-09-08 17:03:02.024234"}
workflow: INFO: Executing: n4 ID: 3
callback: DEBUG: {"name": "n4", "estimated_memory_gb": 1, "start": "2016-09-08 17:03:02.026717", "num_threads": 1, "id": "n4"}
workflow: INFO: [Job finished] jobname: n4 jobid: 3
callback: DEBUG: {"name": "n4", "runtime_memory_gb": "Unknown", "num_threads": 1, "runtime_threads": "Unknown", "id": "n4", "estimated_memory_gb": 1, "finish": "2016-09-08 17:03:02.957813"}
--------------------- >> end captured logging << ---------------------

—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub
#1607, or mute the thread
https://github.com/notifications/unsubscribe-auth/AAOkp-Wq5g7DE3mYReOXh47FM_Btb_CCks5qoEKHgaJpZM4J4O6A
.

[berleant]

Looks like it was introduced here: cf16091#diff-6754f59514753626dc2de4293709ce5dL148

Fix (I think): #1650

[berleant]

This makes me think there should be an error thrown if someone tries to set a plugin arg that doesn't exist. Thoughts?

[berleant]

made a new issue for that larger question