ERROR: Canvas workflow error: System.ArgumentOutOfRangeException: Index was out of range.

[BenoitFiset]

Finally got to get Tumor-normal-enrichment on a PC with .NET Core 1.1.9 on a PC with version 1.35.1.1316+master of Canvas.

Don't understand why the work flow starts off with Chromosome 2 - CanvasSNV.dll -c 2 but this runs ok.

The jobManager.commands.tsv has the right order of things:

C:\Users\WalshLab\Downloads\Canvas_T1\Logging>more jobManager.commands.tsv
CanvasSNV-'SSXT96_F01_VS_SSXT96_B01'-'1'        C:\Program Files\dotnet\dotnet.exe C:\Users\WalshLab\Downloads\Canvas-1.35.1.1316+master_x64\CanvasSNV\CanvasSNV.dll  -c 1 -v C:\Users\WalshLab\Downloads\Canvas-Ensembl\common_all_20180418.vcf -b C:\Users\WalshLab\Downloads\SSXT96_B01_Aligned_01\Projects\default\default\sorted.bam -o C:\Users\WalshLab\Downloads\Canvas_T1\TempCNV_SSXT96_F01_VS_SSXT96_B01\1-SSXT96_F01_VS_SSXT96_B01.SNV.txt.gz --isSomatic
CanvasSNV-'SSXT96_F01_VS_SSXT96_B01'-'2'        C:\Program Files\dotnet\dotnet.exe C:\Users\WalshLab\Downloads\Canvas-1.35.1.1316+master_x64\CanvasSNV\CanvasSNV.dll  -c 2 -v C:\Users\WalshLab\Downloads\Canvas-Ensembl\common_all_20180418.vcf -b C:\Users\WalshLab\Downloads\SSXT96_B01_Aligned_01\Projects\default\default\sorted.bam -o C:\Users\WalshLab\Downloads\Canvas_T1\TempCNV_SSXT96_F01_VS_SSXT96_B01\2-SSXT96_F01_VS_SSXT96_B01.SNV.txt.gz --isSomatic
CanvasSNV-'SSXT96_F01_VS_SSXT96_B01'-'3'        C:\Program Files\dotnet\dotnet.exe C:\Users\WalshLab\Downloads\Canvas-1.35.1.1316+master_x64\CanvasSNV\CanvasSNV.dll  -c 3 -v C:\Users\WalshLab\Downloads\Canvas-Ensembl\common_all_20180418.vcf -b C:\Users\WalshLab\Downloads\SSXT96_B01_Aligned_01\Projects\default\default\sorted.bam -o C:\Users\WalshLab\Downloads\Canvas_T1\TempCNV_SSXT96_F01_VS_SSXT96_B01\3-SSXT96_F01_VS_SSXT96_B01.SNV.txt.gz --isSomatic

2018-05-22T17:16:46,Checkpoint 01 Validate input complete. Elapsed time (hh/mm/ss): 00:00:00.1
2018-05-22T17:16:47,Normal Vcf path: C:\Users\WalshLab\Downloads\Canvas-Ensembl\common_all_20180418.vcf
2018-05-22T17:16:47,
2018-05-22T17:16:47,Running checkpoint 02: CanvasSNV
2018-05-22T17:16:47,
2018-05-22T17:16:47,Running checkpoint 03: CanvasBin
Invoking 24 processor jobs...for sample SSXT96_F01_VS_SSXT96_B01
CanvasSNV start for sample SSXT96_F01_VS_SSXT96_B01
2018-05-22T17:16:47,DoWorkParallelThreads, attempt 1 of 1
2018-05-22T17:16:47,Launch process: C:\Program Files\dotnet\dotnet.exe C:\Users\WalshLab\Downloads\Canvas-1.35.1.1316+master_x64\CanvasSNV\CanvasSNV.dll  -c 2 -v C:\Users\WalshLab\Downloads\Canvas-Ensembl\common_all_20180418.vcf -b C:\Users\WalshLab\Downloads\SSXT96_B01_Aligned_01\Projects\default\default\sorted.bam -o C:\Users\WalshLab\Downloads\Canvas_T1\TempCNV_SSXT96_F01_VS_SSXT96_B01\2-SSXT96_F01_VS_SSXT96_B01.SNV.txt.gz --isSomatic

Then it starts to run Chromosome 1 and then get the error:

2018-05-22T17:16:47,Launch process: C:\Program Files\dotnet\dotnet.exe C:\Users\WalshLab\Downloads\Canvas-1.35.1.1316+master_x64\CanvasSNV\CanvasSNV.dll  -c 1 -v C:\Users\WalshLab\Downloads\Canvas-Ensembl\common_all_20180418.vcf -b C:\Users\WalshLab\Downloads\SSXT96_B01_Aligned_01\Projects\default\default\sorted.bam -o C:\Users\WalshLab\Downloads\Canvas_T1\TempCNV_SSXT96_F01_VS_SSXT96_B01\1-SSXT96_F01_VS_SSXT96_B01.SNV.txt.gz --isSomatic
2018-05-22T17:16:47,ERROR: Canvas workflow error: System.ArgumentOutOfRangeException: Index was out of range. Must be non-negative and less than the size of the collection.
Parameter name: index

The whole error In the CanvasError.txt file:

>more CanvasError.txt
2018-05-22T17:16:47,ERROR: Canvas workflow error: System.ArgumentOutOfRangeException: Index was out of range. Must be non-negative and less than the size of the collection.
Parameter name: index
   at System.ThrowHelper.ThrowArgumentOutOfRange_IndexException()
   at Canvas.CanvasRunner.GetIntermediateBinnedFilesByBamPath(GenomeMetadata genomeInfo, Boolean isPairedEnd, List`1 sampleIds, IDirectoryLocation tempFolder, String canvasReferencePath, String canvasBedPath, List`1 bamPaths, StringBuilder commandLine, String tempManifestPath) in D:\TeamCity\buildAgent\work\a29a190a11771d97\Src\Canvas\Canvas\CanvasRunner.cs:line 346
   at Canvas.CanvasRunner.InvokeCanvasBin35Mers(CanvasCallset callset, String canvasReferencePath, String canvasBedPath, String ploidyVcfPath) in D:\TeamCity\buildAgent\work\a29a190a11771d97\Src\Canvas\Canvas\CanvasRunner.cs:line 230
   at Canvas.CanvasRunner.InvokeCanvasBin(CanvasCallset callset, String canvasReferencePath, String canvasBedPath, String ploidyVcfPath) in D:\TeamCity\buildAgent\work\a29a190a11771d97\Src\Canvas\Canvas\CanvasRunner.cs:line 197
   at Canvas.CanvasRunner.<>c__DisplayClass38_0.<CallSampleInternal>b__1() in D:\TeamCity\buildAgent\work\a29a190a11771d97\Src\Canvas\Canvas\CanvasRunner.cs:line 805
   at Isas.Framework.Checkpointing.Internals.SerializingCheckpointRunner.<>c__DisplayClass8_0`1.<RunCheckpoint>b__0(Checkpoint checkpoint)
   at Isas.Framework.Checkpointing.Internals.CoreCheckpointRunner.RunCheckpoint[TResult](String name, Func`2 run)
   at Isas.Framework.Checkpointing.Internals.SerializingCheckpointRunner.RunCheckpoint[TResult](String checkpointName, Func`2 run)
   at Canvas.CanvasRunner.<CallSampleInternal>d__38.MoveNext() in D:\TeamCity\buildAgent\work\a29a190a11771d97\Src\Canvas\Canvas\CanvasRunner.cs:line 805
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Canvas.CanvasRunner.CallSample(CanvasCallset callset) in D:\TeamCity\buildAgent\work\a29a190a11771d97\Src\Canvas\Canvas\CanvasRunner.cs:line 767
   at Canvas.ModeLauncher.Launch() in D:\TeamCity\buildAgent\work\a29a190a11771d97\Src\Canvas\Canvas\ModeLauncher.cs:line 64

And there are no errors in the CanvasSNV-'SSXT96_F01_VS_SSXT96_B01'-'1'.stdout.txt file

more "CanvasSNV-'SSXT96_F01_VS_SSXT96_B01'-'1'.stdout.txt"
>>>Command-line arguments:
-c 1 -v C:\Users\WalshLab\Downloads\Canvas-Ensembl\common_all_20180418.vcf -b C:\Users\WalshLab\Downloads\SSXT96_B01_Aligned_01\Projects\default\default\sorted.bam -o C:\Users\WalshLab\Downloads\Canvas_T1\TempCNV_SSXT96_F01_VS_SSXT96_B01\1-SSXT96_F01_VS_SSXT96_B01.SNV.txt.gz --isSomatic
2018-05-22 5:16:50 PM Loading variants of interest from C:\Users\WalshLab\Downloads\Canvas-Ensembl\common_all_20180418.vcf
Retained 2177785 variants, out of 2823256 records for 1
2018-05-22 5:17:26 PM Looping over bam records from C:\Users\WalshLab\Downloads\SSXT96_B01_Aligned_01\Projects\default\default\sorted.bam
Jump to refid 0 1
Record 1000000 at 15929902...
Record 2000000 at 28646963...
Record 3000000 at 40076862...
Record 4000000 at 52028879...
Record 5000000 at 70994903...
Record 6000000 at 92843814...
Record 7000000 at 111759462...
Record 8000000 at 148776015...
Record 9000000 at 155610977...
Record 10000000 at 166620829...
Record 11000000 at 180014442...
Record 12000000 at 197435003...
Record 13000000 at 209938150...
Record 14000000 at 226309248...
Record 15000000 at 241679341...
Looped over 15487563 bam records in all
2018-05-22 5:17:47 PM Results written to C:\Users\WalshLab\Downloads\Canvas_T1\TempCNV_SSXT96_F01_VS_SSXT96_B01\1-SSXT96_F01_VS_SSXT96_B01.SNV.txt.gz

Then no errors for the rest of the other Chromosomes.... till the end

2018-05-22T17:41:06,Launch process: C:\Program Files\dotnet\dotnet.exe C:\Users\WalshLab\Downloads\Canvas-1.35.1.1316+master_x64\CanvasSNV\CanvasSNV.dll  -c X -v C:\Users\WalshLab\Downloads\Canvas-Ensembl\common_all_20180418.vcf -b C:\Users\WalshLab\Downloads\SSXT96_B01_Aligned_01\Projects\default\default\sorted.bam -o C:\Users\WalshLab\Downloads\Canvas_T1\TempCNV_SSXT96_F01_VS_SSXT96_B01\X-SSXT96_F01_VS_SSXT96_B01.SNV.txt.gz --isSomatic
2018-05-22T17:42:15,Launch process: C:\Program Files\dotnet\dotnet.exe C:\Users\WalshLab\Downloads\Canvas-1.35.1.1316+master_x64\CanvasSNV\CanvasSNV.dll  -c Y -v C:\Users\WalshLab\Downloads\Canvas-Ensembl\common_all_20180418.vcf -b C:\Users\WalshLab\Downloads\SSXT96_B01_Aligned_01\Projects\default\default\sorted.bam -o C:\Users\WalshLab\Downloads\Canvas_T1\TempCNV_SSXT96_F01_VS_SSXT96_B01\Y-SSXT96_F01_VS_SSXT96_B01.SNV.txt.gz --isSomatic
CanvasSNV complete for sample SSXT96_F01_VS_SSXT96_B01
2018-05-22T17:45:10,Begin converting 'C:\Users\WalshLab\Downloads\Canvas_T1\TempCNV_SSXT96_F01_VS_SSXT96_B01\VFResultsSSXT96_F01_VS_SSXT96_B01.txt.gz.baf' to 'C:\Users\WalshLab\Downloads\Canvas_T1\TempCNV_SSXT96_F01_VS_SSXT96_B01\ballele.bedgraph.gz'
2018-05-22T17:45:27,Launching process for job tabix-index-tmp-ballele.bedgraph.gz.1:
cmd /c "C:\Users\WalshLab\Downloads\Canvas-1.35.1.1316+master_x64\tabix.exe -p bed -f C:\Users\WalshLab\Downloads\Canvas_T1\TempCNV_SSXT96_F01_VS_SSXT96_B01\ballele.bedgraph.gz"
2018-05-22T17:45:31,Job tabix-index-tmp-ballele.bedgraph.gz.1 took 00:00:04.5 seconds
2018-05-22T17:45:31,Finished converting 'C:\Users\WalshLab\Downloads\Canvas_T1\TempCNV_SSXT96_F01_VS_SSXT96_B01\VFResultsSSXT96_F01_VS_SSXT96_B01.txt.gz.baf' to 'C:\Users\WalshLab\Downloads\Canvas_T1\TempCNV_SSXT96_F01_VS_SSXT96_B01\ballele.bedgraph.gz'. Elapsed time: 00:00:21.3
2018-05-22T17:45:31,Checkpoint 02 CanvasSNV complete. Elapsed time (hh/mm/ss): 00:28:44.6

Any tips on debugging this as I don't know where this stems from.

Thanks.

[eroller]

This is a known bug. Please see #62
With version 1.11 you should be able to use mono on Linux or it should also run on a PC without using dotnet:

https://github.com/Illumina/canvas/releases/download/v1.11.0/Canvas-1.11.0_x64.zip

[BenoitFiset]

Hi Eric,

You are suggesting to use Canvas 1.11.0 ? So In all the versions after 1.11.0, the Tumor-normal-enrichment analysis not changed, except the added bug as you were focusing on WGS ?

What version of mono should i use to run 1.11.0 ?

Is this bug the reason that the CNV.vcf.gz file is not created even though the following files are created:

ballele.bedgraph.gz
ballele.bedgraph.gz.tbi
VFResultsSSXT96_F01_VS_SSXT96_B01.txt.gz
VFResultsSSXT96_F01_VS_SSXT96_B01.txt.gz.baf

Thanks,

[eroller]

You are suggesting to use Canvas 1.11.0 ? So In all the versions after 1.11.0, the Tumor-normal-enrichment analysis not changed, except the added bug as you were focusing on WGS ?

correct

What version of mono should i use to run 1.11.0 ?

we stopped testing after mono 4.2.3, but newer mono versions should be fine

Is this bug the reason that the CNV.vcf.gz file is not created

yes. the workflow is terminating part way through so you get some intermediate files, but not the final output file (CNV.vcf.gz)

[BenoitFiset]

Ok, installed 1.11.0. adjusted things and ran... Ran for about 25 minutes with this error on screen. This message is not logged in any file on only onscreen and all the processes are stuck... had to kill all of them manually.

Example of what I had to manually kill

bfiset   29488     1 44 19:07 pts/14   00:18:06 CentOS6/mono/5.10.1.15/bin/mono /mnt/parallel_scratch_mp2_wipe_on_december_2018/pfiset1/bfiset/Canvas/1.11.0/CanvasSNV.exe Y /mnt/parallel_scratch_mp2_wipe_on_december_2018/pfiset1/bfiset/Ensembl91/Canvas-Data_Ensembl/common_all_20180418.vcf /mnt/parallel_scratch_mp2_wipe_on_december_2018/pfiset1/bfiset/Ensembl91/SSXT96_B01_Aligned_01/Projects/default/default/sorted.bam /mnt/parallel_scratch_mp2_wipe_on_december_2018/pfiset1/bfiset/Ensembl91/Canvas_T1/TempCNV_SSXT96_F01_VS_SSXT96_B01/Y-SSXT96_F01_VS_SSXT96_B01.SNV.txt.gz

Onscreen error:

Unhandled Exception:
System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'Isas.Shared.Logger'.
  at Isas.Shared.Logger.Log (Isas.Shared.LogEntry entry) [0x00028] in <50a58fca929d4779b288da9d5fc7e23a>:0 
  at Isas.Shared.LoggerExtensions.Info (Isas.Shared.ILogger logger, System.String message) [0x00013] in <50a58fca929d4779b288da9d5fc7e23a>:0 
  at Isas.Shared.JobManager.OnLog (System.String message) [0x00008] in <50a58fca929d4779b288da9d5fc7e23a>:0 
  at Isas.Shared.JobManager.RunJob (Isas.Shared.UnitOfWork job, System.Boolean redirectOutput, System.Boolean throwExceptionOnBadExitCode, System.Boolean& cancelJobs, System.Int64& maxVMem, System.TimeSpan& maxWallTime) [0x00469] in <50a58fca929d4779b288da9d5fc7e23a>:0 
  at Isas.Shared.JobManager+<>c__DisplayClass24_0.<ProcessJobs>b__0 (System.Object o) [0x00000] in <50a58fca929d4779b288da9d5fc7e23a>:0 
  at System.Threading.ThreadHelper.ThreadStart_Context (System.Object state) [0x00025] in <f415f907c05145afa647b7695e3b314f>:0 
  at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00071] in <f415f907c05145afa647b7695e3b314f>:0 
  at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <f415f907c05145afa647b7695e3b314f>:0 
  at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state) [0x0002b] in <f415f907c05145afa647b7695e3b314f>:0 
  at System.Threading.ThreadHelper.ThreadStart (System.Object obj) [0x0000f] in <f415f907c05145afa647b7695e3b314f>:0 

[ERROR] FATAL UNHANDLED EXCEPTION: System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'Isas.Shared.Logger'.
  at Isas.Shared.Logger.Log (Isas.Shared.LogEntry entry) [0x00028] in <50a58fca929d4779b288da9d5fc7e23a>:0 
  at Isas.Shared.LoggerExtensions.Info (Isas.Shared.ILogger logger, System.String message) [0x00013] in <50a58fca929d4779b288da9d5fc7e23a>:0 
  at Isas.Shared.JobManager.OnLog (System.String message) [0x00008] in <50a58fca929d4779b288da9d5fc7e23a>:0 
  at Isas.Shared.JobManager.RunJob (Isas.Shared.UnitOfWork job, System.Boolean redirectOutput, System.Boolean throwExceptionOnBadExitCode, System.Boolean& cancelJobs, System.Int64& maxVMem, System.TimeSpan& maxWallTime) [0x00469] in <50a58fca929d4779b288da9d5fc7e23a>:0 
  at Isas.Shared.JobManager+<>c__DisplayClass24_0.<ProcessJobs>b__0 (System.Object o) [0x00000] in <50a58fca929d4779b288da9d5fc7e23a>:0 
  at System.Threading.ThreadHelper.ThreadStart_Context (System.Object state) [0x00025] in <f415f907c05145afa647b7695e3b314f>:0 
  at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00071] in <f415f907c05145afa647b7695e3b314f>:0 
  at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <f415f907c05145afa647b7695e3b314f>:0 
  at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state) [0x0002b] in <f415f907c05145afa647b7695e3b314f>:0 
  at System.Threading.ThreadHelper.ThreadStart (System.Object obj) [0x0000f] in <f415f907c05145afa647b7695e3b314f>:0 

This happened after: [End of file: SSXT96_F01_VS_SSXT96_B01.stdout.txt]

Time elapsed: 00:00:01.1120997
5/22/2018 7:15:44 PM Deserialization complete
Launch CalculateNumberOfPossibleAlignmentsPerBin jobs...

CalculateNumberOfPossibleAlignmentsPerBin jobs complete.

In the CanvasError.txt file there is this....

5/22/2018,19:29:32.343,ERROR: Canvas workflow error: Isas.Shared.JobFailedException: mono returned error code 137

Would all this be caused by memory issues ? How much Memory would be recommended ?

This always seems to be a grasp away to work but i'm starting to lose faith in getting this to run. The rest of the Illumina workflow is all running (Isaac, Manta, Strelka, Nirvana....) just Canvas which is killing me !!!!

Thanks again for the help.

[BenoitFiset]

Finally ! See what I have .... with 512GB of RAM, version 1.11.0 using mono on Centos 6:

5/23/2018,14:31:23.715,Max job memory (GB): 0.3
5/23/2018,14:31:23.716,Longest job runtime (Hours): 0.01
5/23/2018,14:31:23.716,Elapsed time (step/time(sec)/name)	6	00:00:25.0	Variant calling
5/23/2018,14:31:23.716,Saving checkpoint results to /mnt/parallel_scratch_mp2_wipe_on_december_2018/pfiset1/bfiset/Ensembl91/Canvas_T2/Checkpoints/06-Variantcalling.json

Now off to look at the results ...