snakemake - workflow fails after performing several jobs

Question

I have prepared a Snakemake pipeline (Snakemake v5.2.2, Python v3.6.5) for analysing RRBS data (full pipeline viewable on GitHub) and put it into Singularity (v2.5.2, made with Ubuntu 18.04 - also viewable on GitHub). I have tested this workflow with 5 shortened FASTQ files and it worked well.

Problems started when I increased number of my short, test FASTQ files to 20 (my unit of analysis for this experiment). After running several steps, pipeline failed with Error 127: command not found. This error is not specific to any file or rule - sometimes it crashed during trim galore rule, sometimes bismark.

After some investigation I managed to find a solution: adding restriction of memory usage for each rule (e.g. resources: 32000) and running Snakemake with the flag --resources mem_mb=100000. Sadly, when I started the actual analysis using full-sized files, the error returned. I already tried even most desperate things that crossed my mind:

removing all mv commands in snakefile and leaving each rule with only single line of shell commands
running snakemake with various flags (--wait-for-files, --latency-wait 30 --nolock --force-use-threads --restart-times 2)
putting all programs used in the pipeline into Singularity PATH
increasing resources restriction up to 50GB of RAM per rule
running smaller number of samples in one workflow instance

The error appears both while using Singularity container and not, both on my PC and on a server at work. The same commands that fail, work properly when run on their own via command line. I do not use Snakemake's cluster mode.

I've tried and checked generally all I could think of, and I already (stupidly) told my supervisor that the analysis is running (It was! T__T). I would be very grateful for help. Any ideas what is going on and how I can resolve this?

Here is a full, exemplary snakemake output with error:

https://github.com/AdrianS85/varia/blob/master/error_snakemake

And here is the meat of the problem:

[Thu Sep  6 22:05:40 2018]
rule Bismark:
    input: Diversity/B_Control-NM_86_S1_R1_001_val_1.fq_trimmed.fq.gz, Diversity/B_Control-NM_86_S1_R3_001_val_2.fq_trimmed.fq.gz
    output: Bismark_Raw/B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam, Reports/Bismark_Raw/B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_PE_report.txt
    jobid: 5
    wildcards: b=B_Control-NM_86_S1
    threads: 10
    resources: mem_mb=32000

/Bismark*/bismark --bowtie2 --genome_folder ./Genome/ -1 Diversity/B_Control-NM_86_S1_R1_001_val_1.fq_trimmed.fq.gz -2 Diversity/B_Control-NM_86_S1_R3_001_val_2.fq_trimmed.fq.gz &>> Reports/Bismark_Raw/Bismark_Log.txt || error_exit && /Bismark*/bam2nuc --genome_folder ./Genome/ B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam &>> Reports/Bismark_Raw/Bam2nuc_Log.txt || error_exit && /Bismark*/bismark2summary B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bismark2sum_Log.txt && /Bismark*/bismark2report B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bismark2rep_Log.txt && /Bamqc/bamqc B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bamqc_Raw_Log.txt && mv B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam ./Bismark_Raw/ && mv B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_PE_report.txt B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.nucleotide_stats.txt B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_PE_report.html B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe_bamqc.html B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe_bamqc.zip ./Reports/Bismark_Raw/
/bin/bash: error_exit: command not found
/bin/bash: error_exit: command not found
Full Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/snakemake/executors.py", line 1313, in run_wrapper
    singularity_args, use_singularity, None, jobid, is_shell)
  File "/Analysis/Snakefile", line 218, in __rule_Bismark
  File "/usr/local/lib/python3.6/dist-packages/snakemake/shell.py", line 133, in __new__
    raise sp.CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command ' set -euo pipefail;  /Bismark*/bismark --bowtie2 --genome_folder ./Genome/ -1 Diversity/B_Control-NM_86_S1_R1_001_val_1.fq_trimmed.fq.gz -2 Diversity/B_Control-NM_86_S1_R3_001_val_2.fq_trimmed.fq.gz &>> Reports/Bismark_Raw/Bismark_Log.txt || error_exit && /Bismark*/bam2nuc --genome_folder ./Genome/ B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam &>> Reports/Bismark_Raw/Bam2nuc_Log.txt || error_exit && /Bismark*/bismark2summary B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bismark2sum_Log.txt && /Bismark*/bismark2report B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bismark2rep_Log.txt && /Bamqc/bamqc B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bamqc_Raw_Log.txt && mv B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam ./Bismark_Raw/ && mv B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_PE_report.txt B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.nucleotide_stats.txt B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_PE_report.html B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe_bamqc.html B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe_bamqc.zip ./Reports/Bismark_Raw/ ' returned non-zero exit status 127.

    [Thu Sep  6 22:05:41 2018]
    Error in rule Bismark:
        jobid: 5
        output: Bismark_Raw/B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam, Reports/Bismark_Raw/B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_PE_report.txt

Full Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/snakemake/executors.py", line 1313, in run_wrapper
    singularity_args, use_singularity, None, jobid, is_shell)
  File "/Analysis/Snakefile", line 218, in __rule_Bismark
  File "/usr/local/lib/python3.6/dist-packages/snakemake/shell.py", line 133, in __new__
    raise sp.CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command ' set -euo pipefail;  /Bismark*/bismark --bowtie2 --genome_folder ./Genome/ -1 Diversity/B_Control-NM_86_S1_R1_001_val_1.fq_trimmed.fq.gz -2 Diversity/B_Control-NM_86_S1_R3_001_val_2.fq_trimmed.fq.gz &>> Reports/Bismark_Raw/Bismark_Log.txt || error_exit && /Bismark*/bam2nuc --genome_folder ./Genome/ B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam &>> Reports/Bismark_Raw/Bam2nuc_Log.txt || error_exit && /Bismark*/bismark2summary B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bismark2sum_Log.txt && /Bismark*/bismark2report B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bismark2rep_Log.txt && /Bamqc/bamqc B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bamqc_Raw_Log.txt && mv B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam ./Bismark_Raw/ && mv B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_PE_report.txt B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.nucleotide_stats.txt B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_PE_report.html B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe_bamqc.html B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe_bamqc.zip ./Reports/Bismark_Raw/ ' returned non-zero exit status 127.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/snakemake/executors.py", line 346, in _callback
    raise ex
  File "/usr/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.6/dist-packages/snakemake/executors.py", line 1325, in run_wrapper
    show_traceback=True))
snakemake.exceptions.RuleException: CalledProcessError in line 119 of /Analysis/Snakefile:
Command ' set -euo pipefail;  /Bismark*/bismark --bowtie2 --genome_folder ./Genome/ -1 Diversity/B_Control-NM_86_S1_R1_001_val_1.fq_trimmed.fq.gz -2 Diversity/B_Control-NM_86_S1_R3_001_val_2.fq_trimmed.fq.gz &>> Reports/Bismark_Raw/Bismark_Log.txt || error_exit && /Bismark*/bam2nuc --genome_folder ./Genome/ B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam &>> Reports/Bismark_Raw/Bam2nuc_Log.txt || error_exit && /Bismark*/bismark2summary B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bismark2sum_Log.txt && /Bismark*/bismark2report B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bismark2rep_Log.txt && /Bamqc/bamqc B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bamqc_Raw_Log.txt && mv B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam ./Bismark_Raw/ && mv B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_PE_report.txt B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.nucleotide_stats.txt B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_PE_report.html B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe_bamqc.html B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe_bamqc.zip ./Reports/Bismark_Raw/ ' returned non-zero exit status 127.
  File "/Analysis/Snakefile", line 119, in __rule_Bismark

RuleException:
CalledProcessError in line 119 of /Analysis/Snakefile:
Command ' set -euo pipefail;  /Bismark*/bismark --bowtie2 --genome_folder ./Genome/ -1 Diversity/B_Control-NM_86_S1_R1_001_val_1.fq_trimmed.fq.gz -2 Diversity/B_Control-NM_86_S1_R3_001_val_2.fq_trimmed.fq.gz &>> Reports/Bismark_Raw/Bismark_Log.txt || error_exit && /Bismark*/bam2nuc --genome_folder ./Genome/ B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam &>> Reports/Bismark_Raw/Bam2nuc_Log.txt || error_exit && /Bismark*/bismark2summary B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bismark2sum_Log.txt && /Bismark*/bismark2report B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bismark2rep_Log.txt && /Bamqc/bamqc B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam  &>> Reports/Bismark_Raw/Bamqc_Raw_Log.txt && mv B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.bam ./Bismark_Raw/ && mv B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_PE_report.txt B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe.nucleotide_stats.txt B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_PE_report.html B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe_bamqc.html B_Control-NM_86_S1_R1_001_val_1.fq_trimmed_bismark_bt2_pe_bamqc.zip ./Reports/Bismark_Raw/ ' returned non-zero exit status 127.
  File "/Analysis/Snakefile", line 119, in __rule_Bismark
  File "/usr/lib/python3.6/concurrent/futures/thread.py", line 56, in run
[Thu Sep  6 22:08:09 2018]
Finished job 6.
8 of 47 steps (17%) done
[Thu Sep  6 22:58:49 2018]
Finished job 42.
9 of 47 steps (19%) done
Shutting down, this might take some time.
Exiting because a job execution failed. Look above for error message
Complete log: /Analysis/.snakemake/log/2018-09-06T191518.240813.snakemake.log
unlocking
removing lock
removing lock
removed all locks

Edit

I think I've already found a workaround for this issue. Unfortunately, I still don't know what caused original error. Nevertheless - please don't waste Your time on this problem, unless someone else reports it below...

Snakemake fails here due to unavailability of `error_exit` command. `error_exit` is a custom function/command but it was never defined in your Snakefile. Define them [as done here](https://stackoverflow.com/a/44625951/3998252). However, taking a step back, why do you need to use `error_exit`? On side note, bismark is the one that seemed to have failed here, and you need to figure out why. That is, your primary problem is not due to snakemake but due to `bismark`. — Manavalan Gajapathy, Sep 07 '18 at 15:40
Good point, thank You! Ive tested and changed everything around the program so much that I forgot to add error_exit as a function to bash. While this causes the error to have number -127-, it does not help with the underlying issue - the error_exit function executes only when an error happens. Nevertheless, since I already solved my problem by using different workflow menager, I see no point in wasting somebody's time with this issue... — AdrianS85, Sep 12 '18 at 13:54

snakemake - workflow fails after performing several jobs

Edit

0 Answers0