Logs report "fMRIPrep finished successfully" despite errors

[psadil]

What happened?

The final messages in the logs seem to contradict that there were errors reported. Given that crashfiles were generated, I was expecting a note like Workflow did not execute cleanly and/or fMRIprep failed

What command did you use?

ROOT="${SLURM_SUBMIT_DIR}"
IMAGE=code/containers/fmriprep_25_2_4.sif
SOURCEDATA="${ROOT}"/sourcedata
RAWDATA="${SOURCEDATA}"/raw

apptainer run \
    --bind "${ROOT}" \
    --env TEMPLATEFLOW_HOME="${SOURCEDATA}"/templateflow \
    ${IMAGE} \
    --fs-license "${ROOT}"/code/license \
    --skip-bids-validation \
    --ignore slicetiming \
    --dummy-scans 20 \
    --output-spaces MNI152NLin2009cAsym:res-3 \
    --output-spaces MNI152NLin6Asym:res-native \
    -w ${SCRATCH}/work2 \
    sourcedata/raw "${ROOT}"/derivatives/fmriprep participant

What version of fMRIPrep are you running?

25.2.4

How are you running fMRIPrep?

Singularity

Is your data BIDS valid?

Yes

Are you reusing any previously computed results?

No

Please copy and paste any relevant log output.

$ tail logs/log 
260216-04:16:42,165 nipype.workflow INFO:
	 [Node] Setting-up "_msmsulc1" in "/scratch2/08266/psadil/work2/fmriprep_25_2_wf/sub_052_wf/anat_fit_wf/msm_sulc_wf/msmsulc/mapflow/_msmsulc1".
260216-04:16:42,171 nipype.workflow INFO:
	 [Node] Cached "_msmsulc1" - collecting precomputed outputs
260216-04:16:42,171 nipype.workflow INFO:
	 [Node] "_msmsulc1" found cached.
260216-04:16:59,127 nipype.workflow IMPORTANT:
	 fMRIPrep finished successfully!
260216-04:16:59,132 nipype.workflow IMPORTANT:
	 Works derived from this fMRIPrep execution should include the boilerplate text found in <OUTPUT_PATH>/logs/CITATION.md.


 grep -m1 -A 52 "Saving crash" logs/log 
	 Saving crash info to /scratch2/08266/psadil/tops-study2/derivatives/fmriprep/sub-054/log/20260214-084703_9338118b-0a7a-431a-84be-65c443c2a651/crash-20260214-092605-psadil-select_tpl.a0-6e3341c3-40e7-449e-8a23-319a0c0e4f99.txt
Traceback (most recent call last):
  File "/app/.pixi/envs/fmriprep/lib/python3.12/site-packages/nipype/pipeline/plugins/multiproc.py", line 389, in _send_procs_to_workers
    self.procs[jobid].run(updatehash=updatehash)
  File "/app/.pixi/envs/fmriprep/lib/python3.12/site-packages/nipype/pipeline/engine/nodes.py", line 525, in run
    result = self._run_interface(execute=True)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/.pixi/envs/fmriprep/lib/python3.12/site-packages/nipype/pipeline/engine/nodes.py", line 643, in _run_interface
    return self._run_command(execute)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/.pixi/envs/fmriprep/lib/python3.12/site-packages/nipype/pipeline/engine/nodes.py", line 769, in _run_command
    raise NodeExecutionError(msg)
nipype.pipeline.engine.nodes.NodeExecutionError: Exception raised while executing Node select_tpl.

Traceback:
	Traceback (most recent call last):
	  File "/app/.pixi/envs/fmriprep/lib/python3.12/site-packages/nipype/interfaces/base/traits_extension.py", line 129, in validate
	    value = Path(value)  # Use pathlib's validation
	            ^^^^^^^^^^^
	  File "/app/.pixi/envs/fmriprep/lib/python3.12/pathlib.py", line 1162, in __init__
	    super().__init__(*args)
	  File "/app/.pixi/envs/fmriprep/lib/python3.12/pathlib.py", line 373, in __init__
	    raise TypeError(
	TypeError: argument should be a str or an os.PathLike object where __fspath__ returns a str, not 'list'

	During handling of the above exception, another exception occurred:

	Traceback (most recent call last):
	  File "/app/.pixi/envs/fmriprep/lib/python3.12/site-packages/nipype/interfaces/base/core.py", line 457, in aggregate_outputs
	    setattr(outputs, key, val)
	  File "/app/.pixi/envs/fmriprep/lib/python3.12/site-packages/nipype/interfaces/base/traits_extension.py", line 325, in validate
	    value = super().validate(objekt, name, value, return_pathlike=True)
	            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
	  File "/app/.pixi/envs/fmriprep/lib/python3.12/site-packages/nipype/interfaces/base/traits_extension.py", line 131, in validate
	    self.error(objekt, name, str(value))
	  File "/app/.pixi/envs/fmriprep/lib/python3.12/site-packages/traits/base_trait_handler.py", line 74, in error
	    raise TraitError(
	traits.trait_errors.TraitError: The 't1w_file' trait of a _TemplateFlowSelectOutputSpec instance must be a pathlike object or string representing an existing file, but a value of '[]' <class 'str'> was specified.

	During handling of the above exception, another exception occurred:

	Traceback (most recent call last):
	  File "/app/.pixi/envs/fmriprep/lib/python3.12/site-packages/nipype/interfaces/base/core.py", line 404, in run
	    outputs = self.aggregate_outputs(runtime)
	              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
	  File "/app/.pixi/envs/fmriprep/lib/python3.12/site-packages/nipype/interfaces/base/core.py", line 464, in aggregate_outputs
	    raise FileNotFoundError(msg)
	FileNotFoundError: No such file or directory '[]' for output 't1w_file' of a TemplateFlowSelect interface


260214-09:26:10,701 nipype.workflow WARNING:
	 Storing result file without outputs
260214-09:26:10,703 nipype.workflow WARNING:

Additional information / screenshots

I'm guessing that the error itself was caused by my use of res-3 instead of res-03 in the output-space definition.

[mgxd]

This is a result of our (over?) usage of run_without_submitting - local errors (rather than jobs being managed by the plugins) are caught rather than propagated when using the distributed plugins (MultiProc, LegacyMultiProc, etc).

@effigies @oesteban this is before my time, what was the initial motivation for run_without_submitting? I'm leaning towards removing it in order to catch these false positives.

[oesteban]

@psadil can you confirm that the output log and the crash file correspond to the same run? Timestamps are some 48h apart

[mgxd]

I verified with a dummy example:

Script

from nipype import Workflow, Node
from nipype.interfaces.utility import IdentityInterface, Function



def func1(x):
    return x + 5


def func2(x):
    raise Exception('Nope')


inputnode = Node(IdentityInterface(fields=["int"]), name="inputnode")
node1 = Node(Function(function=func1), name="node1")

node2 = Node(
    Function(function=func2),
    name="node2",
    run_without_submitting=True,
)

wf = Workflow(name="rws_workflow", base_dir='.')
wf.connect([
    (inputnode, node1, [("int", "x")]),
    (node1, node2, [("out", "x")]),
])


import sys
inputnode.inputs.int = int(sys.argv[-1])
try:
    result = wf.run(plugin='MultiProc')
except Exception as e:
    print('Failed!')
else:
    print('Success!')

260219-17:06:57,547 nipype.workflow INFO:
	 Workflow rws_workflow settings: ['check', 'execution', 'logging', 'monitoring']
260219-17:06:57,549 nipype.workflow INFO:
	 Running in parallel.
260219-17:06:57,550 nipype.workflow INFO:
	 [MultiProc] Running 0 tasks, and 1 jobs ready. Free memory (GB): 32.40/32.40, Free processors: 14/14, Free GPU slot:0/0.
260219-17:06:57,973 nipype.workflow INFO:
	 Workflow rws_workflow settings: ['check', 'execution', 'logging', 'monitoring']
260219-17:06:57,974 nipype.workflow INFO:
	 Running in parallel.
260219-17:06:57,975 nipype.workflow INFO:
	 [MultiProc] Running 0 tasks, and 1 jobs ready. Free memory (GB): 32.40/32.40, Free processors: 14/14, Free GPU slot:0/0.
Failed!
260219-17:06:57,987 nipype.workflow INFO:
	 [Node] Setting-up "rws_workflow.node1" in "/Users/mathiasg/occ/sandbox/nipype-test/rws_workflow/node1".
260219-17:06:57,988 nipype.workflow INFO:
	 [Node] Executing "node1" <nipype.interfaces.utility.wrappers.Function>
260219-17:06:58,8 nipype.workflow INFO:
	 [Node] Finished "node1", elapsed time 0.000342s.
260219-17:06:59,558 nipype.workflow INFO:
	 [Job 0] Completed (rws_workflow.node1).
260219-17:06:59,560 nipype.workflow INFO:
	 [MultiProc] Running 0 tasks, and 1 jobs ready. Free memory (GB): 32.40/32.40, Free processors: 14/14, Free GPU slot:0/0.
260219-17:06:59,587 nipype.workflow INFO:
	 [Node] Setting-up "rws_workflow.node2" in "/Users/mathiasg/occ/sandbox/nipype-test/rws_workflow/node2".
260219-17:06:59,590 nipype.workflow INFO:
	 [Node] Executing "node2" <nipype.interfaces.utility.wrappers.Function>
260219-17:06:59,614 nipype.workflow INFO:
	 [Node] Finished "node2", elapsed time 0.000163s.
260219-17:06:59,614 nipype.workflow WARNING:
	 Storing result file without outputs
260219-17:06:59,614 nipype.workflow WARNING:
	 [Node] Error on "rws_workflow.node2" (/Users/mathiasg/occ/sandbox/nipype-test/rws_workflow/node2)
260219-17:06:59,615 nipype.workflow ERROR:
	 Node node2 failed to run on host amarna.
260219-17:06:59,616 nipype.workflow ERROR:
	 Saving crash info to /Users/mathiasg/occ/sandbox/nipype-test/crash-20260219-170659-mathiasg-node2-12716880-7a99-45cc-8d16-bd500467374c.pklz
Traceback (most recent call last):
  File "/Users/mathiasg/occ/fmriprep/.venv/lib/python3.13/site-packages/nipype/pipeline/plugins/multiproc.py", line 389, in _send_procs_to_workers
    self.procs[jobid].run(updatehash=updatehash)
    ~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/mathiasg/occ/fmriprep/.venv/lib/python3.13/site-packages/nipype/pipeline/engine/nodes.py", line 525, in run
    result = self._run_interface(execute=True)
  File "/Users/mathiasg/occ/fmriprep/.venv/lib/python3.13/site-packages/nipype/pipeline/engine/nodes.py", line 643, in _run_interface
    return self._run_command(execute)
           ~~~~~~~~~~~~~~~~~^^^^^^^^^
  File "/Users/mathiasg/occ/fmriprep/.venv/lib/python3.13/site-packages/nipype/pipeline/engine/nodes.py", line 769, in _run_command
    raise NodeExecutionError(msg)
nipype.pipeline.engine.nodes.NodeExecutionError: Exception raised while executing Node node2.

Traceback:
	Traceback (most recent call last):
	  File "/Users/mathiasg/occ/fmriprep/.venv/lib/python3.13/site-packages/nipype/interfaces/base/core.py", line 401, in run
	    runtime = self._run_interface(runtime)
	  File "/Users/mathiasg/occ/fmriprep/.venv/lib/python3.13/site-packages/nipype/interfaces/utility/wrappers.py", line 139, in _run_interface
	    out = function_handle(**args)
	  File "<string>", line 2, in func2
	Exception: Nope


260219-17:06:59,616 nipype.workflow INFO:
	 [Job 1] Completed (rws_workflow.node2).
Success!

[psadil]

@psadil can you confirm that the output log and the crash file correspond to the same run? Timestamps are some 48h apart

Yeah. Here's a log from a shorter run showing the same thing

log.txt

FWIW, this was the node (which, yes, does appear to use run_without_submitting): https://github.com/nipreps/smriprep/blob/e8c2180d0779918721f29464012d8b2137f385d5/src/smriprep/workflows/outputs.py#L1238

I'm guessing that the error itself was caused by my use of res-3 instead of res-03 in the output-space definition.

No, perhaps it's more simply that, while res-03 exists within this template, there isn't a res-03_t1w