failed workflow runs with different error log. Complete successfully during rerun with same settings.

[jzrapp]

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.