fmriprep 1.4.1 file not found error

[justbennet]

I am running a Singularity container of fmriprep 1.4.1. When we try to run the following command, we get a Traceback error indicating that it cannot find a file which I think it was supposed to have created itself.

The command I run is

singularity run -B /sw:/sw /tmp/fmriprep-1.4.1.simg $PWD --fs-license-file=/sw/arcts/centos7/freesurfer/6.0.0/license.txt --participant-label=sub-NDARINVZZZNB0XC output participant

I get the same traceback using that same command but with the added options --nthreads 1 --omp-nthreads 1.

It runs through setting up the nipype nodes successfully it seems, then prints up to the ### References, at which point it produces this output

190820-15:39:04,174 nipype.workflow INFO:
     [Node] Setting-up "fmriprep_wf.single_subject_NDARINVZZZNB0XC_wf.func_preproc_ses_baselineYear1Arm1_task_mid_run_01_wf.func_derivatives_wf.raw_sources" in "/tmp/fmriprep/work/fmriprep_wf/single_subject_NDARINVZZZNB0XC_wf/func_preproc_ses_baselineYear1Arm1_task_mid_run_01_wf/func_derivatives_wf/raw_sources".
190820-15:39:04,175 nipype.workflow INFO:
     [Node] Running "raw_sources" ("nipype.interfaces.utility.wrappers.Function")
exception calling callback for <Future at 0x2af37ff648d0 state=finished raised OSError>
concurrent.futures.process._RemoteTraceback: 
"""
Traceback (most recent call last):
  File "/usr/local/miniconda/lib/python3.7/site-packages/nipype/pipeline/plugins/multiproc.py", line 69, in run_node
    result['result'] = node.run(updatehash=updatehash)
  File "/usr/local/miniconda/lib/python3.7/site-packages/nipype/pipeline/engine/nodes.py", line 487, in run
    self, report_type='postexec', is_mapnode=isinstance(self, MapNode))
  File "/usr/local/miniconda/lib/python3.7/site-packages/nipype/pipeline/engine/utils.py", line 149, in write_report
    result = node.result  # Locally cache result
  File "/usr/local/miniconda/lib/python3.7/site-packages/nipype/pipeline/engine/nodes.py", line 197, in result
    return _load_resultfile(self.output_dir(), self.name)[0]
  File "/usr/local/miniconda/lib/python3.7/site-packages/nipype/pipeline/engine/utils.py", line 359, in load_resultfile
    basedir=path).items()):
  File "/usr/local/miniconda/lib/python3.7/site-packages/nipype/pipeline/engine/utils.py", line 478, in modify_paths
    val, relative=relative, basedir=basedir)
  File "/usr/local/miniconda/lib/python3.7/site-packages/nipype/pipeline/engine/utils.py", line 484, in modify_paths
    modify_paths(val, relative=relative, basedir=basedir))
  File "/usr/local/miniconda/lib/python3.7/site-packages/nipype/pipeline/engine/utils.py", line 498, in modify_paths
    raise IOError('File %s not found' % out)
OSError: File /tmp/fmriprep/work/fmriprep_wf/single_subject_NDARINVZZZNB0XC_wf/func_preproc_ses_baselineYear1Arm1_task_mid_run_01_wf/func_derivatives_wf/raw_sources/sub-NDARINVZZZNB0XC/ses-baselineYear1Arm1/func/sub-NDARINVZZZNB0XC_ses-baselineYear1Arm1_task-mid_run-01_bold.nii not found

It appears that this directory does exist: /tmp/fmriprep/work/fmriprep_wf/single_subject_NDARINVZZZNB0XC_wf/func_preproc_ses_baselineYear1Arm1_task_mid_run_01_wf/func_derivatives_wf/raw_sources, but that there is no subject directory underneath it.

$ ls /tmp/fmriprep/work/fmriprep_wf/single_subject_NDARINVZZZNB0XC_wf/func_preproc_ses_baselineYear1Arm1_task_mid_run_01_wf/func_derivatives_wf/raw_sources
_0x763007af6eb61212a00403b1b1920887.json  _inputs.pklz  _node.pklz  _report  result_raw_sources.pklz

Under the BIDS_ROOT directory, the path sub-NDARINVZZZNB0XC/ses-baselineYear1Arm1/func/sub-NDARINVZZZNB0XC_ses-baselineYear1Arm1_task-mid_run-01_bold.nii.

The same subject gets a good deal past that stage when run using a Singularity container built for fmriprep-1.1.8, so I think it is not a problem with the data. Since we tried this with the options to limit threading to 1 process and 1 thread, it should not be asynchronous threading.

The system on which I am running is CentOS Linux release 7.6.1810 (Core) on a Dell R740 with dual Intel(R) Xeon(R) Gold 6140 CPU @ 2.30GHz chips. The kernel version is 3.10.0-957.10.1.el7.x86_64.

[mangstad]

This error appears to be intermittent. When testing yesterday we had 1 run that got passed that section without the error. It was the first time we'd used the --nthreads 1 option, so we initially thought parallelization or a race condition problem. But repeated testing shows that we sometimes get the error and sometimes don't. I've replicated this on a different system (Ubuntu 16.04) with a separate build of the container. First time no error. Removed the work and output folders and tried again and get the error.

Is it possible there's a dependency of raw_sources not being set properly or something? So that sometimes the proper node runs first and things operate fine, but other times they're run out of order so the files aren't populated there yet?

[bbfrederick]

We've been tearing our hair out over the same error. fmriprep 1.4.1 running in a singularity container, works on some subjects, throws the same error you got on others. I'm glad it's not just us...

[justbennet]

I am pretty sure that the problem is that fmriprep and/or NiPype is not getting the order correct when it sets up and/or processes the pipeline. As reported, if we run it enough times restricting to a single processor, it eventually creates that file and will proceed. That could indicate that it's a bug in NiPype, or in the in the way that fmriprep specifies the dependencies to NiPype. I am somewhat surprised that it hasn't been reported by more people. We were looking for the more recent version because of SIFTI support.

[dmd]

Our workaround for the time being:

Create a fileworkaround.yml:

plugin: LegacyMultiProc
plugin_args: {maxtasksperchild: 1, memory_gb: 250, n_procs: 16, raise_insufficient: false}

and then call with --use-plugin /path/to/workaround.yml

[mangstad]

Our workaround for the time being:

Create a fileworkaround.yml:

plugin: LegacyMultiProc
plugin_args: {maxtasksperchild: 1, memory_gb: 250, n_procs: 16, raise_insufficient: false}

and then call with --use-plugin /path/to/workaround.yml

In my limited testing so far, this does seem to prevent the error from popping up, but also seems to cause fmriprep to just stall at
[Node] Running "raw_sources" ("nipype.interfaces.utility.wrappers.Function")
for about 18 hours now.

[bbfrederick]

Yes, we were prematurely jubilant, because we got past our initial blocker. We ran into the same problem.

[mangstad]

Okay, my fault. I still had --nthreads 1 --omp-nthreads 1 in my command when testing that and it seems to interact poorly. Now with that removed it does seem to run and does get past the previous error location. I'm going to run it a few more times to ensure that it continues getting past that portion of the processing each time.

[effigies]

--nthreads 1 --omp-nthreads 1 should work, although slowly.

[dmd]

Define "slowly"? We have no progress after 20 hours.

[effigies]

Well, you certainly shouldn't be stuck on that job. That's very, very strange, as that job should take no time at all. But I mean slowly in the sense that every single job has to go one at a time and will never take advantage of multiple cores, so FreeSurfer and ANTs in particular will simply crawl. I would expect FreeSurfer to take >12 hours. I have never run ANTs T1w-MNI normalization on a single core, but since 30 minutes on 8 cores is not unusual, I would expect 4 more hours. And then at some point you'll work on functional data.

But you should definitely get output at shorter intervals than 20 hours. I think we should start a separate issue to figure out that one...

[dmd]

We aren't even running with freesurfer turned on.

[mangstad]

Define "slowly"? We have no progress after 20 hours.

Yep. Similar here. It sat on [Node] Running "raw_sources" ("nipype.interfaces.utility.wrappers.Function") for about 18 hours before I killed it. When I ran the same with -vvvv it was stuck issuing a bunch of messages like
190905-14:21:51,684 nipype.workflow DEBUG: No resources available

[effigies]

@mangstad Thanks for copying your comment to #1758. @dmd Shall we continue conversation over there?

[mangstad]

@effigies just an FYI, this issue does seem to be very related to issue #1758. I tried launching fmriprep in the same way as in the end of that thread, but without using the workaround.yml file and it does seem to get beyond the raw_sources step quickly.

[dmd]

We seem to be succeeding now if we (1) DO use the workaround.yml referenced above, and do NOT use omp-nthreads, e.g.:

/cm/shared/singularity/bin/singularity run \
    -B /data:/data -B /data1:/data1 -B /data2:/data2 -B /data3:/data3 -B /cm/shared:/cm/shared \
    --cleanenv \
    /cm/shared/singularity/images/fmriprep-1.4.1.simg \
    /data/ddrucker/testdatafordaniel \
    /data/ddrucker/testdatafordaniel/derivatives \
    participant \
    --fs-license-file /cm/shared/freesurfer-6.0.1/license.txt \
    --participant_label 000 \
    --output-spaces MNI152NLin6Asym:res-2 anat func fsaverage \
    --n_cpus 4 \
    --nthreads 4 \
    --mem-mb 8192 \
    --use-plugin /data/ddrucker/workaround.yml \
    --use-syn-sdc \
    -vvvv \
    -w  /data/ddrucker/work

[effigies]

Closing in favor of some granular to-dos. See https://github.com/poldracklab/fmriprep/issues/1758#issuecomment-529646139.