failed workflow runs with different error log. Complete successfully during rerun with same settings. #29
Description
Hi @mshakya,
I ran a total of 11 small metaT workflows today, 9 finished successfully, 2 failed. I re-run the two that failed and they finished successfully after the second run. I don't understand the error log, but you probably will :)
Log 1:
Generate WDL and inputs json
submit workflow to cromwell
Cromwell job status: Running
Cromwell job status: Failed
nmdc_metat.cs2
nmdc_metat.cs2
nmdc_metat.cs2
nmdc_metat.cs2
nmdc_metat.cs2
nmdc_metat.cs2
nmdc_metat.tdc
nmdc_metat.tdc
nmdc_metat.tdc
nmdc_metat.tdc
nmdc_metat.tdc
nmdc_metat.tdc
nmdc_metat.create_gffdb
nmdc_metat.bbm
/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/dd8c6581-9e17-4a42-baa9-d33a7cafd5ad/call-nmdc_metat/Metatranscriptome.nmdc_metat/9ad3279d-4499-4d63-9fe4-57b2ee9b2aef/call-bbm/execution/script: line 23: [[true: command not found
java -ea -Xmx84623m -Xms84623m -cp /bbmap/current/ align2.BBMap build=1 overwrite=true fastareadlen=500 nodisk=true interleaved=true t=16 samestrandpairs=f ambiguous=best in=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/dd8c6581-9e17-4a42-baa9-d33a7cafd5ad/call-nmdc_metat/Metatranscriptome.nmdc_metat/9ad3279d-4499-4d63-9fe4-57b2ee9b2aef/call-bbm/inputs/1566719536/RNA02.anqrpht.fastq.gz ref=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/dd8c6581-9e17-4a42-baa9-d33a7cafd5ad/call-nmdc_metat/Metatranscriptome.nmdc_metat/9ad3279d-4499-4d63-9fe4-57b2ee9b2aef/call-bbm/inputs/-1017959710/RNA02.contigs.fa out=mapped_sorted.bam covstats=covstats.txt bamscript=to_bam.sh nhtag=t
Picked up _JAVA_OPTIONS: -Djava.io.tmpdir=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/dd8c6581-9e17-4a42-baa9-d33a7cafd5ad/call-nmdc_metat/Metatranscriptome.nmdc_metat/9ad3279d-4499-4d63-9fe4-57b2ee9b2aef/call-bbm/tmp.0ce5b52d
Executing align2.BBMap [build=1, overwrite=true, fastareadlen=500, nodisk=true, interleaved=true, t=16, samestrandpairs=f, ambiguous=best, in=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/dd8c6581-9e17-4a42-baa9-d33a7cafd5ad/call-nmdc_metat/Metatranscriptome.nmdc_metat/9ad3279d-4499-4d63-9fe4-57b2ee9b2aef/call-bbm/inputs/1566719536/RNA02.anqrpht.fastq.gz, ref=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/dd8c6581-9e17-4a42-baa9-d33a7cafd5ad/call-nmdc_metat/Metatranscriptome.nmdc_metat/9ad3279d-4499-4d63-9fe4-57b2ee9b2aef/call-bbm/inputs/-1017959710/RNA02.contigs.fa, out=mapped_sorted.bam, covstats=covstats.txt, bamscript=to_bam.sh, nhtag=t]
Version 38.92
.....[deleted some info in between because my post was too long]
//================================= Running ==================================\\
|| ||
|| Load annotation file clean.gff ... ||
|| Features : 15 ||
|| Meta-features : 15 ||
|| Chromosomes/contigs : 15 ||
|| ||
|| Process BAM file mapped_sorted.bam... ||
|| Strand specific : reversely stranded ||
|| Paired-end reads are included. ||
|| Total alignments : 20598 ||
|| Successfully assigned alignments : 361 (1.8%) ||
|| Running time : 0.00 minutes ||
|| ||
|| Write the final count table. ||
|| Write the read assignment summary. ||
|| ||
|| Summary of counting results can be found in file "tmRNA_antisense.count.s ||
|| ummary" ||
|| ||
\\============================================================================//
nmdc_metat.tdc2
nmdc_metat.tdc2
nmdc_metat.tdc2
nmdc_metat.tdc2
nmdc_metat.tdc2
Log 2:
Generate WDL and inputs json
submit workflow to cromwell
Cromwell job status: Running
Cromwell job status: Failed
nmdc_metat.int
java -ea -Xms300m -cp /bbmap/current/ jgi.ReformatReads in1=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/f15be96e-2f01-4dac-8ebf-5e6233bdee65/call-nmdc_metat/Metatranscriptome.nmdc_metat/90d1fad7-95d9-4217-81fd-4910a527c5ae/call-int/inputs/788432829/Rapp-RNA08_S104_L001_R1_001.fastq.gz in2=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/f15be96e-2f01-4dac-8ebf-5e6233bdee65/call-nmdc_metat/Metatranscriptome.nmdc_metat/90d1fad7-95d9-4217-81fd-4910a527c5ae/call-int/inputs/788432829/Rapp-RNA08_S104_L001_R2_001.fastq.gz out=RNA08.fastq.gz
Picked up _JAVA_OPTIONS: -Djava.io.tmpdir=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/f15be96e-2f01-4dac-8ebf-5e6233bdee65/call-nmdc_metat/Metatranscriptome.nmdc_metat/90d1fad7-95d9-4217-81fd-4910a527c5ae/call-int/tmp.edcdc0d8
Executing jgi.ReformatReads [in1=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/f15be96e-2f01-4dac-8ebf-5e6233bdee65/call-nmdc_metat/Metatranscriptome.nmdc_metat/90d1fad7-95d9-4217-81fd-4910a527c5ae/call-int/inputs/788432829/Rapp-RNA08_S104_L001_R1_001.fastq.gz, in2=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/f15be96e-2f01-4dac-8ebf-5e6233bdee65/call-nmdc_metat/Metatranscriptome.nmdc_metat/90d1fad7-95d9-4217-81fd-4910a527c5ae/call-int/inputs/788432829/Rapp-RNA08_S104_L001_R2_001.fastq.gz, out=RNA08.fastq.gz]
Set INTERLEAVED to false
Input is being processed as paired
Writing interleaved.
Input: 37056 reads 8161014 bases
Output: 37056 reads (100.00%) 8161014 bases (100.00%)
Time: 0.595 seconds.
Reads Processed: 37056 62.23k reads/sec
Bases Processed: 8161k 13.71m bases/sec
nmdc_metat.stage
nmdc_metat.asm
2023-06-01 01:10:59 - MEGAHIT v1.2.9
2023-06-01 01:10:59 - Using megahit_core with POPCNT and BMI2 support
2023-06-01 01:10:59 - Convert reads to binary library
2023-06-01 01:10:59 - b'INFO sequence/io/sequence_lib.cpp : 75 - Lib 0 (/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/f15be96e-2f01-4dac-8ebf-5e6233bdee65/call-nmdc_metat/Metatranscriptome.nmdc_metat/90d1fad7-95d9-4217-81fd-4910a527c5ae/call-asm/inputs/1191633694/RNA08.anqrpht.fastq.gz): interleaved, 27826 reads, 300 max length'
2023-06-01 01:10:59 - b'INFO utils/utils.h : 152 - Real: 0.0836\tuser: 0.0293\tsys: 0.0069\tmaxrss: 7100'
2023-06-01 01:10:59 - Start assembly. Number of CPU threads 64
2023-06-01 01:10:59 - k list: 23,43,63,83,103,123
2023-06-01 01:10:59 - Memory used: 243011801088
2023-06-01 01:10:59 - Extract solid (k+1)-mers for k = 23
2023-06-01 01:11:00 - Build graph for k = 23
2023-06-01 01:11:01 - Assemble contigs from SdBG for k = 23
2023-06-01 01:11:02 - Local assembly for k = 23
2023-06-01 01:11:03 - Extract iterative edges from k = 23 to 43
2023-06-01 01:11:03 - Build graph for k = 43
2023-06-01 01:11:03 - Assemble contigs from SdBG for k = 43
2023-06-01 01:11:04 - Local assembly for k = 43
2023-06-01 01:11:05 - Extract iterative edges from k = 43 to 63
2023-06-01 01:11:05 - Build graph for k = 63
2023-06-01 01:11:05 - Assemble contigs from SdBG for k = 63
2023-06-01 01:11:06 - Local assembly for k = 63
2023-06-01 01:11:07 - Extract iterative edges from k = 63 to 83
2023-06-01 01:11:07 - Build graph for k = 83
2023-06-01 01:11:07 - Assemble contigs from SdBG for k = 83
2023-06-01 01:11:08 - Local assembly for k = 83
2023-06-01 01:11:08 - Extract iterative edges from k = 83 to 103
2023-06-01 01:11:08 - Build graph for k = 103
2023-06-01 01:11:09 - Assemble contigs from SdBG for k = 103
2023-06-01 01:11:09 - Local assembly for k = 103
2023-06-01 01:11:09 - Extract iterative edges from k = 103 to 123
2023-06-01 01:11:09 - Build graph for k = 123
2023-06-01 01:11:10 - Assemble contigs from SdBG for k = 123
2023-06-01 01:11:10 - Merging to output final contigs
2023-06-01 01:11:10 - 1324 contigs, total 530797 bp, min 259 bp, max 1938 bp, avg 400 bp, N50 369 bp
2023-06-01 01:11:10 - ALL DONE. Time elapsed: 11.099815 seconds
nmdc_metat.bbm
/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/f15be96e-2f01-4dac-8ebf-5e6233bdee65/call-nmdc_metat/Metatranscriptome.nmdc_metat/90d1fad7-95d9-4217-81fd-4910a527c5ae/call-bbm/execution/script: line 23: [[true: command not found
java -ea -Xmx104848m -Xms104848m -cp /bbmap/current/ align2.BBMap build=1 overwrite=true fastareadlen=500 nodisk=true interleaved=true t=16 samestrandpairs=f ambiguous=best in=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/f15be96e-2f01-4dac-8ebf-5e6233bdee65/call-nmdc_metat/Metatranscriptome.nmdc_metat/90d1fad7-95d9-4217-81fd-4910a527c5ae/call-bbm/inputs/1191633694/RNA08.anqrpht.fastq.gz ref=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/f15be96e-2f01-4dac-8ebf-5e6233bdee65/call-nmdc_metat/Metatranscriptome.nmdc_metat/90d1fad7-95d9-4217-81fd-4910a527c5ae/call-bbm/inputs/-109818102/RNA08.contigs.fa out=mapped_sorted.bam covstats=covstats.txt bamscript=to_bam.sh nhtag=t
Picked up _JAVA_OPTIONS: -Djava.io.tmpdir=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/f15be96e-2f01-4dac-8ebf-5e6233bdee65/call-nmdc_metat/Metatranscriptome.nmdc_metat/90d1fad7-95d9-4217-81fd-4910a527c5ae/call-bbm/tmp.6ae13d62
Executing align2.BBMap [build=1, overwrite=true, fastareadlen=500, nodisk=true, interleaved=true, t=16, samestrandpairs=f, ambiguous=best, in=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/f15be96e-2f01-4dac-8ebf-5e6233bdee65/call-nmdc_metat/Metatranscriptome.nmdc_metat/90d1fad7-95d9-4217-81fd-4910a527c5ae/call-bbm/inputs/1191633694/RNA08.anqrpht.fastq.gz, ref=/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/f15be96e-2f01-4dac-8ebf-5e6233bdee65/call-nmdc_metat/Metatranscriptome.nmdc_metat/90d1fad7-95d9-4217-81fd-4910a527c5ae/call-bbm/inputs/-109818102/RNA08.contigs.fa, out=mapped_sorted.bam, covstats=covstats.txt, bamscript=to_bam.sh, nhtag=t]
Version 38.92
Set INTERLEAVED to true
Set threads to 16
Retaining first best site only for ambiguous mappings.
Found samtools 1.10
Executing dna.FastaToChromArrays2 [/expanse/projects/nmdc/cromwell/cromwell-executions/main_workflow/f15be96e-2f01-4dac-8ebf-5e6233bdee65/call-nmdc_metat/Metatranscriptome.nmdc_metat/90d1fad7-95d9-4217-81fd-4910a527c5ae/call-bbm/inputs/-109818102/RNA08.contigs.fa, 1, writeinthread=false, genscaffoldinfo=true, retain, waitforwriting=false, gz=true, maxlen=536670912, writechroms=false, minscaf=1, midpad=300, startpad=8000, stoppad=8000, nodisk=true]
Set genScaffoldInfo=true
Set genome to 1
Loaded Reference: 0.006 seconds.
Loading index for chunk 1-1, build 1
Indexing threads started for block 0-1
Indexing threads finished for block 0-1
Generated Index: 0.226 seconds.
Analyzed Index: 2.330 seconds.
Started output stream: 0.065 seconds.
Cleared Memory: 0.166 seconds.
Processing reads in paired-ended mode.
Started read stream.
Started 16 mapping threads.
Detecting finished threads: 0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15
------------------ Results ------------------
Genome: 1
Key Length: 13
Max Indel: 16000
Minimum Score Ratio: 0.56
Mapping Mode: normal
Reads Used: 27826 (5773025 bases)
Mapping: 2.000 seconds.
Reads/sec: 13910.82
kBases/sec: 2886.06
Pairing data: pct pairs num pairs pct bases num bases
mated pairs: 43.3120% 6026 45.8585% 2647422
bad pairs: 0.0288% 4 0.0223% 1290
insert size avg: 286.92
Read 1 data: pct reads num reads pct bases num bases
mapped: 43.6786% 6077 46.2530% 1333850
unambiguous: 43.5204% 6055 46.1553% 1331030
ambiguous: 0.1581% 22 0.0978% 2820
low-Q discards: 0.0000% 0 0.0000% 0
perfect best site: 27.9451% 3888 30.0771% 867365
semiperfect site: 28.2685% 3933 30.4032% 876770
rescued: 0.4097% 57
Match Rate: NA NA 98.6601% 1317472
Error Rate: 35.2806% 2144 1.1279% 15061
Sub Rate: 34.5236% 2098 0.9730% 12993
Del Rate: 2.8633% 174 0.1135% 1515
Ins Rate: 3.6531% 222 0.0414% 553
N Rate: 2.0076% 122 0.2121% 2832
Read 2 data: pct reads num reads pct bases num bases
mapped: 43.5133% 6054 46.0311% 1329937
unambiguous: 43.3336% 6029 45.9243% 1326852
ambiguous: 0.1797% 25 0.1068% 3085
low-Q discards: 0.0000% 0 0.0000% 0
perfect best site: 25.4079% 3535 26.5581% 767322
semiperfect site: 25.7385% 3581 26.8736% 776437
rescued: 0.7331% 102
Match Rate: NA NA 98.5308% 1311808
Error Rate: 40.8490% 2473 1.2650% 16842
Sub Rate: 40.1222% 2429 1.0700% 14245
Del Rate: 2.7420% 166 0.1076% 1432
Ins Rate: 3.7496% 227 0.0875% 1165
N Rate: 2.0648% 125 0.2042% 2719
Reads: 27826
Mapped reads: 12131
Mapped bases: 2675918
Ref scaffolds: 1324
Ref bases: 530797
Percent mapped: 43.596
Percent proper pairs: 43.312
Average coverage: 5.041
Average coverage with deletions: 5.010
Standard deviation: 17.029
Percent scaffolds with any coverage: 99.92
Percent of reference bases covered: 99.79
Total time: 5.427 seconds.