Class org.broadinstitute.hellbender.engine.spark.datasources.ReadsSparkSourceUnitTest

all > org.broadinstitute.hellbender.engine.spark.datasources > ReadsSparkSourceUnitTest
28

tests
0

failures
2

ignored
3.235s

duration
100%

successful

Tests

Test Duration Result
loadReadsNonExistentReference 0.001s passed
readsSparkSourceTestLenient[0](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam, null) 0.209s passed
readsSparkSourceTestLenient[1](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram, /gatkCloneMountPoint/src/test/resources/human_g1k_v37.chr17_1Mb.fasta) 0.245s passed
readsSparkSourceTestSilent[0](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam, null) 0.203s passed
readsSparkSourceTestSilent[1](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram, /gatkCloneMountPoint/src/test/resources/human_g1k_v37.chr17_1Mb.fasta) 0.176s passed
readsSparkSourceTestStrict[0](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam, null) 0.033s passed
readsSparkSourceTestStrict[1](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram, /gatkCloneMountPoint/src/test/resources/human_g1k_v37.chr17_1Mb.fasta) 0.056s passed
readsSparkSourceTest[0](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam, null) 0.415s passed
readsSparkSourceTest[1](/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/HiSeq.1mb.1RG.2k_lines.alternate.bam, null) 0.349s passed
readsSparkSourceTest[2](/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/expected.HiSeq.1mb.1RG.2k_lines.alternate.recalibrated.DIQ.bam, null) 0.249s passed
readsSparkSourceTest[3](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram, /gatkCloneMountPoint/src/test/resources/human_g1k_v37.chr17_1Mb.fasta) 0.181s passed
readsSparkSourceTest[4](/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/valid.cram, /gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/valid.fasta) 0.170s passed
readsSparkSourceUnknownHostTest 0.017s passed
shardedReadsSparkSourceTest[0](/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/expected.HiSeq.1mb.1RG.2k_lines.alternate.recalibrated.DIQ.bam, /gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/HiSeq.1mb.1RG.2k_lines.alternate.recalibrated.DIQ.sharded.bam, null) 0.270s passed
testCRAMReferenceFromHDFS - ignored
testCRAMReferenceRequired 0s passed
testCheckCRAMReference 0s passed
testGetHeader[0](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam, null) 0.032s passed
testGetHeader[1](/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/HiSeq.1mb.1RG.2k_lines.alternate.bam, null) 0.031s passed
testGetHeader[2](/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/expected.HiSeq.1mb.1RG.2k_lines.alternate.recalibrated.DIQ.bam, null) 0.032s passed
testGetHeader[3](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram, /gatkCloneMountPoint/src/test/resources/human_g1k_v37.chr17_1Mb.fasta) 0.029s passed
testGetHeader[4](/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/valid.cram, /gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/valid.fasta) 0.026s passed
testHeadersAreStripped 0.181s passed
testIntervals 0.118s passed
testIntervalsWithUnmapped 0.106s passed
testPartitionSizing 0.106s passed
testReadFromFileAndHDFS - ignored
testReject2BitCRAMReference 0s passed

Standard error

22:03:42.220 INFO  MemoryStore - Block broadcast_34 stored as values in memory (estimated size 297.2 KiB, free 1919.5 MiB)
22:03:42.243 INFO  MemoryStore - Block broadcast_34_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1919.5 MiB)
22:03:42.243 INFO  BlockManagerInfo - Added broadcast_34_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1919.9 MiB)
22:03:42.244 INFO  SparkContext - Created broadcast 34 from newAPIHadoopFile at PathSplitSource.java:96
22:03:42.308 INFO  MemoryStore - Block broadcast_35 stored as values in memory (estimated size 297.2 KiB, free 1919.2 MiB)
22:03:42.317 INFO  MemoryStore - Block broadcast_35_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1919.1 MiB)
22:03:42.317 INFO  BlockManagerInfo - Added broadcast_35_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1919.8 MiB)
22:03:42.318 INFO  SparkContext - Created broadcast 35 from newAPIHadoopFile at PathSplitSource.java:96
22:03:42.352 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
22:03:42.353 INFO  DAGScheduler - Got job 20 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
22:03:42.353 INFO  DAGScheduler - Final stage: ResultStage 29 (collect at ReadsSparkSourceUnitTest.java:111)
22:03:42.353 INFO  DAGScheduler - Parents of final stage: List()
22:03:42.353 INFO  DAGScheduler - Missing parents: List()
22:03:42.353 INFO  DAGScheduler - Submitting ResultStage 29 (ParallelCollectionRDD[69] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
22:03:42.354 INFO  MemoryStore - Block broadcast_36 stored as values in memory (estimated size 3.0 KiB, free 1919.1 MiB)
22:03:42.355 INFO  MemoryStore - Block broadcast_36_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1919.1 MiB)
22:03:42.355 INFO  BlockManagerInfo - Added broadcast_36_piece0 in memory on localhost:41281 (size: 1780.0 B, free: 1919.8 MiB)
22:03:42.355 INFO  SparkContext - Created broadcast 36 from broadcast at DAGScheduler.scala:1580
22:03:42.356 INFO  DAGScheduler - Submitting 4 missing tasks from ResultStage 29 (ParallelCollectionRDD[69] at parallelize at ReadsSparkSourceUnitTest.java:310) (first 15 tasks are for partitions Vector(0, 1, 2, 3))
22:03:42.356 INFO  TaskSchedulerImpl - Adding task set 29.0 with 4 tasks resource profile 0
22:03:42.358 INFO  TaskSetManager - Starting task 0.0 in stage 29.0 (TID 67) (localhost, executor driver, partition 0, PROCESS_LOCAL, 47080 bytes) 
22:03:42.359 INFO  TaskSetManager - Starting task 1.0 in stage 29.0 (TID 68) (localhost, executor driver, partition 1, PROCESS_LOCAL, 47194 bytes) 
22:03:42.360 INFO  TaskSetManager - Starting task 2.0 in stage 29.0 (TID 69) (localhost, executor driver, partition 2, PROCESS_LOCAL, 47105 bytes) 
22:03:42.361 INFO  TaskSetManager - Starting task 3.0 in stage 29.0 (TID 70) (localhost, executor driver, partition 3, PROCESS_LOCAL, 47530 bytes) 
22:03:42.362 INFO  Executor - Running task 0.0 in stage 29.0 (TID 67)
22:03:42.362 INFO  Executor - Running task 1.0 in stage 29.0 (TID 68)
22:03:42.362 INFO  Executor - Running task 2.0 in stage 29.0 (TID 69)
22:03:42.362 INFO  Executor - Running task 3.0 in stage 29.0 (TID 70)
22:03:42.369 INFO  Executor - Finished task 0.0 in stage 29.0 (TID 67). 40355 bytes result sent to driver
22:03:42.369 INFO  Executor - Finished task 1.0 in stage 29.0 (TID 68). 40512 bytes result sent to driver
22:03:42.370 INFO  Executor - Finished task 2.0 in stage 29.0 (TID 69). 40380 bytes result sent to driver
22:03:42.371 INFO  Executor - Finished task 3.0 in stage 29.0 (TID 70). 40848 bytes result sent to driver
22:03:42.372 INFO  TaskSetManager - Finished task 1.0 in stage 29.0 (TID 68) in 14 ms on localhost (executor driver) (1/4)
22:03:42.372 INFO  TaskSetManager - Finished task 0.0 in stage 29.0 (TID 67) in 15 ms on localhost (executor driver) (2/4)
22:03:42.372 INFO  TaskSetManager - Finished task 3.0 in stage 29.0 (TID 70) in 12 ms on localhost (executor driver) (3/4)
22:03:42.376 INFO  TaskSetManager - Finished task 2.0 in stage 29.0 (TID 69) in 17 ms on localhost (executor driver) (4/4)
22:03:42.376 INFO  TaskSchedulerImpl - Removed TaskSet 29.0, whose tasks have all completed, from pool 
22:03:42.377 INFO  DAGScheduler - ResultStage 29 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.024 s
22:03:42.377 INFO  DAGScheduler - Job 20 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:42.377 INFO  TaskSchedulerImpl - Killing all running tasks in stage 29: Stage finished
22:03:42.377 INFO  DAGScheduler - Job 20 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.024804 s
22:03:42.393 INFO  FileInputFormat - Total input files to process : 1
22:03:42.443 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
22:03:42.444 INFO  DAGScheduler - Got job 21 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
22:03:42.444 INFO  DAGScheduler - Final stage: ResultStage 30 (collect at ReadsSparkSourceUnitTest.java:112)
22:03:42.444 INFO  DAGScheduler - Parents of final stage: List()
22:03:42.444 INFO  DAGScheduler - Missing parents: List()
22:03:42.444 INFO  DAGScheduler - Submitting ResultStage 30 (MapPartitionsRDD[76] at filter at ReadsSparkSource.java:96), which has no missing parents
22:03:42.466 INFO  MemoryStore - Block broadcast_37 stored as values in memory (estimated size 425.0 KiB, free 1918.7 MiB)
22:03:42.468 INFO  MemoryStore - Block broadcast_37_piece0 stored as bytes in memory (estimated size 152.7 KiB, free 1918.5 MiB)
22:03:42.468 INFO  BlockManagerInfo - Added broadcast_37_piece0 in memory on localhost:41281 (size: 152.7 KiB, free: 1919.7 MiB)
22:03:42.469 INFO  SparkContext - Created broadcast 37 from broadcast at DAGScheduler.scala:1580
22:03:42.469 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 30 (MapPartitionsRDD[76] at filter at ReadsSparkSource.java:96) (first 15 tasks are for partitions Vector(0))
22:03:42.469 INFO  TaskSchedulerImpl - Adding task set 30.0 with 1 tasks resource profile 0
22:03:42.475 INFO  TaskSetManager - Starting task 0.0 in stage 30.0 (TID 71) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7831 bytes) 
22:03:42.475 INFO  Executor - Running task 0.0 in stage 30.0 (TID 71)
22:03:42.547 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam:0+57538
22:03:42.564 INFO  Executor - Finished task 0.0 in stage 30.0 (TID 71). 159615 bytes result sent to driver
22:03:42.566 INFO  TaskSetManager - Finished task 0.0 in stage 30.0 (TID 71) in 96 ms on localhost (executor driver) (1/1)
22:03:42.566 INFO  TaskSchedulerImpl - Removed TaskSet 30.0, whose tasks have all completed, from pool 
22:03:42.566 INFO  DAGScheduler - ResultStage 30 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.120 s
22:03:42.566 INFO  DAGScheduler - Job 21 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:42.566 INFO  TaskSchedulerImpl - Killing all running tasks in stage 30: Stage finished
22:03:42.567 INFO  DAGScheduler - Job 21 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.123840 s
22:03:42.577 INFO  MemoryStore - Block broadcast_38 stored as values in memory (estimated size 297.3 KiB, free 1918.3 MiB)
22:03:42.587 INFO  MemoryStore - Block broadcast_38_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1918.2 MiB)
22:03:42.587 INFO  BlockManagerInfo - Added broadcast_38_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1919.6 MiB)
22:03:42.588 INFO  SparkContext - Created broadcast 38 from newAPIHadoopFile at PathSplitSource.java:96
22:03:42.627 INFO  MemoryStore - Block broadcast_39 stored as values in memory (estimated size 297.3 KiB, free 1917.9 MiB)
22:03:42.636 INFO  MemoryStore - Block broadcast_39_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1917.9 MiB)
22:03:42.637 INFO  BlockManagerInfo - Added broadcast_39_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1919.6 MiB)
22:03:42.637 INFO  SparkContext - Created broadcast 39 from newAPIHadoopFile at PathSplitSource.java:96
22:03:42.668 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
22:03:42.668 INFO  DAGScheduler - Got job 22 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
22:03:42.668 INFO  DAGScheduler - Final stage: ResultStage 31 (collect at ReadsSparkSourceUnitTest.java:111)
22:03:42.668 INFO  DAGScheduler - Parents of final stage: List()
22:03:42.668 INFO  DAGScheduler - Missing parents: List()
22:03:42.669 INFO  DAGScheduler - Submitting ResultStage 31 (ParallelCollectionRDD[82] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
22:03:42.669 INFO  MemoryStore - Block broadcast_40 stored as values in memory (estimated size 3.0 KiB, free 1917.9 MiB)
22:03:42.670 INFO  MemoryStore - Block broadcast_40_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1917.9 MiB)
22:03:42.670 INFO  BlockManagerInfo - Added broadcast_40_piece0 in memory on localhost:41281 (size: 1780.0 B, free: 1919.6 MiB)
22:03:42.671 INFO  SparkContext - Created broadcast 40 from broadcast at DAGScheduler.scala:1580
22:03:42.671 INFO  DAGScheduler - Submitting 4 missing tasks from ResultStage 31 (ParallelCollectionRDD[82] at parallelize at ReadsSparkSourceUnitTest.java:310) (first 15 tasks are for partitions Vector(0, 1, 2, 3))
22:03:42.671 INFO  TaskSchedulerImpl - Adding task set 31.0 with 4 tasks resource profile 0
22:03:42.673 INFO  TaskSetManager - Starting task 0.0 in stage 31.0 (TID 72) (localhost, executor driver, partition 0, PROCESS_LOCAL, 169886 bytes) 
22:03:42.675 INFO  TaskSetManager - Starting task 1.0 in stage 31.0 (TID 73) (localhost, executor driver, partition 1, PROCESS_LOCAL, 170093 bytes) 
22:03:42.676 INFO  TaskSetManager - Starting task 2.0 in stage 31.0 (TID 74) (localhost, executor driver, partition 2, PROCESS_LOCAL, 170081 bytes) 
22:03:42.678 INFO  TaskSetManager - Starting task 3.0 in stage 31.0 (TID 75) (localhost, executor driver, partition 3, PROCESS_LOCAL, 169419 bytes) 
22:03:42.678 INFO  Executor - Running task 0.0 in stage 31.0 (TID 72)
22:03:42.678 INFO  Executor - Running task 1.0 in stage 31.0 (TID 73)
22:03:42.679 INFO  Executor - Running task 3.0 in stage 31.0 (TID 75)
22:03:42.680 INFO  Executor - Running task 2.0 in stage 31.0 (TID 74)
22:03:42.684 INFO  Executor - Finished task 1.0 in stage 31.0 (TID 73). 163454 bytes result sent to driver
22:03:42.685 INFO  TaskSetManager - Finished task 1.0 in stage 31.0 (TID 73) in 12 ms on localhost (executor driver) (1/4)
22:03:42.687 INFO  Executor - Finished task 3.0 in stage 31.0 (TID 75). 162737 bytes result sent to driver
22:03:42.687 INFO  Executor - Finished task 0.0 in stage 31.0 (TID 72). 163204 bytes result sent to driver
22:03:42.689 INFO  TaskSetManager - Finished task 3.0 in stage 31.0 (TID 75) in 12 ms on localhost (executor driver) (2/4)
22:03:42.691 INFO  Executor - Finished task 2.0 in stage 31.0 (TID 74). 163399 bytes result sent to driver
22:03:42.692 INFO  TaskSetManager - Finished task 0.0 in stage 31.0 (TID 72) in 20 ms on localhost (executor driver) (3/4)
22:03:42.694 INFO  TaskSetManager - Finished task 2.0 in stage 31.0 (TID 74) in 19 ms on localhost (executor driver) (4/4)
22:03:42.695 INFO  TaskSchedulerImpl - Removed TaskSet 31.0, whose tasks have all completed, from pool 
22:03:42.695 INFO  DAGScheduler - ResultStage 31 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.026 s
22:03:42.695 INFO  DAGScheduler - Job 22 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:42.695 INFO  TaskSchedulerImpl - Killing all running tasks in stage 31: Stage finished
22:03:42.695 INFO  DAGScheduler - Job 22 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.027393 s
22:03:42.698 INFO  FileInputFormat - Total input files to process : 1
22:03:42.749 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
22:03:42.750 INFO  DAGScheduler - Got job 23 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
22:03:42.750 INFO  DAGScheduler - Final stage: ResultStage 32 (collect at ReadsSparkSourceUnitTest.java:112)
22:03:42.750 INFO  DAGScheduler - Parents of final stage: List()
22:03:42.750 INFO  DAGScheduler - Missing parents: List()
22:03:42.751 INFO  DAGScheduler - Submitting ResultStage 32 (MapPartitionsRDD[89] at filter at ReadsSparkSource.java:96), which has no missing parents
22:03:42.777 INFO  MemoryStore - Block broadcast_41 stored as values in memory (estimated size 425.0 KiB, free 1917.4 MiB)
22:03:42.789 INFO  MemoryStore - Block broadcast_41_piece0 stored as bytes in memory (estimated size 152.7 KiB, free 1917.3 MiB)
22:03:42.790 INFO  BlockManagerInfo - Added broadcast_41_piece0 in memory on localhost:41281 (size: 152.7 KiB, free: 1919.4 MiB)
22:03:42.791 INFO  SparkContext - Created broadcast 41 from broadcast at DAGScheduler.scala:1580
22:03:42.791 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 32 (MapPartitionsRDD[89] at filter at ReadsSparkSource.java:96) (first 15 tasks are for partitions Vector(0))
22:03:42.791 INFO  TaskSchedulerImpl - Adding task set 32.0 with 1 tasks resource profile 0
22:03:42.791 INFO  BlockManagerInfo - Removed broadcast_2_piece0 on localhost:41281 in memory (size: 349.0 B, free: 1919.4 MiB)
22:03:42.792 INFO  TaskSetManager - Starting task 0.0 in stage 32.0 (TID 76) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7875 bytes) 
22:03:42.793 INFO  Executor - Running task 0.0 in stage 32.0 (TID 76)
22:03:42.794 INFO  BlockManagerInfo - Removed broadcast_14_piece0 on localhost:41281 in memory (size: 2.4 KiB, free: 1919.4 MiB)
22:03:42.799 INFO  BlockManagerInfo - Removed broadcast_12_piece0 on localhost:41281 in memory (size: 2.4 KiB, free: 1919.4 MiB)
22:03:42.801 INFO  BlockManagerInfo - Removed broadcast_25_piece0 on localhost:41281 in memory (size: 4.5 KiB, free: 1919.4 MiB)
22:03:42.803 INFO  BlockManagerInfo - Removed broadcast_28_piece0 on localhost:41281 in memory (size: 320.0 B, free: 1919.4 MiB)
22:03:42.806 INFO  BlockManagerInfo - Removed broadcast_19_piece0 on localhost:41281 in memory (size: 2.4 KiB, free: 1919.4 MiB)
22:03:42.808 INFO  BlockManagerInfo - Removed broadcast_11_piece0 on localhost:41281 in memory (size: 2.4 KiB, free: 1919.4 MiB)
22:03:42.812 INFO  BlockManagerInfo - Removed broadcast_1_piece0 on localhost:41281 in memory (size: 143.0 B, free: 1919.4 MiB)
22:03:42.813 INFO  BlockManagerInfo - Removed broadcast_20_piece0 on localhost:41281 in memory (size: 2.4 KiB, free: 1919.4 MiB)
22:03:42.816 INFO  BlockManagerInfo - Removed broadcast_9_piece0 on localhost:41281 in memory (size: 4.7 KiB, free: 1919.5 MiB)
22:03:42.818 INFO  BlockManagerInfo - Removed broadcast_31_piece0 on localhost:41281 in memory (size: 320.0 B, free: 1919.5 MiB)
22:03:42.821 INFO  BlockManagerInfo - Removed broadcast_8_piece0 on localhost:41281 in memory (size: 3.8 KiB, free: 1919.5 MiB)
22:03:42.849 INFO  BlockManagerInfo - Removed broadcast_34_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1919.5 MiB)
22:03:42.852 INFO  BlockManagerInfo - Removed broadcast_29_piece0 on localhost:41281 in memory (size: 3.8 KiB, free: 1919.5 MiB)
22:03:42.856 INFO  BlockManagerInfo - Removed broadcast_35_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1919.6 MiB)
22:03:42.859 INFO  BlockManagerInfo - Removed broadcast_18_piece0 on localhost:41281 in memory (size: 2.4 KiB, free: 1919.6 MiB)
22:03:42.861 INFO  BlockManagerInfo - Removed broadcast_10_piece0 on localhost:41281 in memory (size: 2.4 KiB, free: 1919.6 MiB)
22:03:42.862 INFO  BlockManagerInfo - Removed broadcast_26_piece0 on localhost:41281 in memory (size: 3.2 KiB, free: 1919.6 MiB)
22:03:42.865 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/HiSeq.1mb.1RG.2k_lines.alternate.bam:0+221635
22:03:42.866 INFO  BlockManagerInfo - Removed broadcast_37_piece0 on localhost:41281 in memory (size: 152.7 KiB, free: 1919.7 MiB)
22:03:42.870 INFO  BlockManagerInfo - Removed broadcast_7_piece0 on localhost:41281 in memory (size: 326.0 B, free: 1919.7 MiB)
22:03:42.873 INFO  BlockManagerInfo - Removed broadcast_23_piece0 on localhost:41281 in memory (size: 465.0 B, free: 1919.7 MiB)
22:03:42.879 INFO  BlockManager - Removing RDD 7
22:03:42.883 INFO  BlockManagerInfo - Removed broadcast_13_piece0 on localhost:41281 in memory (size: 2.4 KiB, free: 1919.7 MiB)
22:03:42.888 INFO  BlockManagerInfo - Removed broadcast_15_piece0 on localhost:41281 in memory (size: 2.4 KiB, free: 1919.7 MiB)
22:03:42.890 INFO  BlockManager - Removing RDD 47
22:03:42.892 INFO  BlockManagerInfo - Removed broadcast_36_piece0 on localhost:41281 in memory (size: 1780.0 B, free: 1919.7 MiB)
22:03:42.893 INFO  BlockManagerInfo - Removed broadcast_16_piece0 on localhost:41281 in memory (size: 2.4 KiB, free: 1919.7 MiB)
22:03:42.895 INFO  BlockManagerInfo - Removed broadcast_38_piece0 on localhost:41281 in memory (size: 50.1 KiB, free: 1919.8 MiB)
22:03:42.896 INFO  BlockManagerInfo - Removed broadcast_40_piece0 on localhost:41281 in memory (size: 1780.0 B, free: 1919.8 MiB)
22:03:42.898 INFO  BlockManagerInfo - Removed broadcast_33_piece0 on localhost:41281 in memory (size: 4.8 KiB, free: 1919.8 MiB)
22:03:42.899 INFO  BlockManagerInfo - Removed broadcast_21_piece0 on localhost:41281 in memory (size: 2.4 KiB, free: 1919.8 MiB)
22:03:42.900 INFO  BlockManagerInfo - Removed broadcast_22_piece0 on localhost:41281 in memory (size: 159.0 B, free: 1919.8 MiB)
22:03:42.902 INFO  BlockManagerInfo - Removed broadcast_24_piece0 on localhost:41281 in memory (size: 4.3 KiB, free: 1919.8 MiB)
22:03:42.903 INFO  BlockManagerInfo - Removed broadcast_17_piece0 on localhost:41281 in memory (size: 2.4 KiB, free: 1919.8 MiB)
22:03:42.904 INFO  BlockManagerInfo - Removed broadcast_30_piece0 on localhost:41281 in memory (size: 4.7 KiB, free: 1919.8 MiB)
22:03:42.906 INFO  BlockManagerInfo - Removed broadcast_27_piece0 on localhost:41281 in memory (size: 5.1 KiB, free: 1919.8 MiB)
22:03:42.907 INFO  BlockManagerInfo - Removed broadcast_32_piece0 on localhost:41281 in memory (size: 3.8 KiB, free: 1919.8 MiB)
22:03:42.911 INFO  Executor - Finished task 0.0 in stage 32.0 (TID 76). 650184 bytes result sent to driver
22:03:42.914 INFO  TaskSetManager - Finished task 0.0 in stage 32.0 (TID 76) in 122 ms on localhost (executor driver) (1/1)
22:03:42.915 INFO  TaskSchedulerImpl - Removed TaskSet 32.0, whose tasks have all completed, from pool 
22:03:42.915 INFO  DAGScheduler - ResultStage 32 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.164 s
22:03:42.916 INFO  DAGScheduler - Job 23 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:42.916 INFO  TaskSchedulerImpl - Killing all running tasks in stage 32: Stage finished
22:03:42.916 INFO  DAGScheduler - Job 23 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.166524 s
22:03:42.926 INFO  MemoryStore - Block broadcast_42 stored as values in memory (estimated size 297.3 KiB, free 1918.8 MiB)
22:03:42.938 INFO  MemoryStore - Block broadcast_42_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1918.8 MiB)
22:03:42.939 INFO  BlockManagerInfo - Added broadcast_42_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1919.8 MiB)
22:03:42.939 INFO  SparkContext - Created broadcast 42 from newAPIHadoopFile at PathSplitSource.java:96
22:03:42.972 INFO  MemoryStore - Block broadcast_43 stored as values in memory (estimated size 297.3 KiB, free 1918.5 MiB)
22:03:42.980 INFO  MemoryStore - Block broadcast_43_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1918.4 MiB)
22:03:42.980 INFO  BlockManagerInfo - Added broadcast_43_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1919.7 MiB)
22:03:42.981 INFO  SparkContext - Created broadcast 43 from newAPIHadoopFile at PathSplitSource.java:96
22:03:43.008 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
22:03:43.009 INFO  DAGScheduler - Got job 24 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
22:03:43.009 INFO  DAGScheduler - Final stage: ResultStage 33 (collect at ReadsSparkSourceUnitTest.java:111)
22:03:43.009 INFO  DAGScheduler - Parents of final stage: List()
22:03:43.009 INFO  DAGScheduler - Missing parents: List()
22:03:43.010 INFO  DAGScheduler - Submitting ResultStage 33 (ParallelCollectionRDD[95] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
22:03:43.010 INFO  MemoryStore - Block broadcast_44 stored as values in memory (estimated size 3.0 KiB, free 1918.4 MiB)
22:03:43.011 INFO  MemoryStore - Block broadcast_44_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1918.4 MiB)
22:03:43.011 INFO  BlockManagerInfo - Added broadcast_44_piece0 in memory on localhost:41281 (size: 1780.0 B, free: 1919.7 MiB)
22:03:43.012 INFO  SparkContext - Created broadcast 44 from broadcast at DAGScheduler.scala:1580
22:03:43.012 INFO  DAGScheduler - Submitting 4 missing tasks from ResultStage 33 (ParallelCollectionRDD[95] at parallelize at ReadsSparkSourceUnitTest.java:310) (first 15 tasks are for partitions Vector(0, 1, 2, 3))
22:03:43.012 INFO  TaskSchedulerImpl - Adding task set 33.0 with 4 tasks resource profile 0
22:03:43.014 INFO  TaskSetManager - Starting task 0.0 in stage 33.0 (TID 77) (localhost, executor driver, partition 0, PROCESS_LOCAL, 169886 bytes) 
22:03:43.015 INFO  TaskSetManager - Starting task 1.0 in stage 33.0 (TID 78) (localhost, executor driver, partition 1, PROCESS_LOCAL, 170093 bytes) 
22:03:43.016 INFO  TaskSetManager - Starting task 2.0 in stage 33.0 (TID 79) (localhost, executor driver, partition 2, PROCESS_LOCAL, 170081 bytes) 
22:03:43.016 INFO  TaskSetManager - Starting task 3.0 in stage 33.0 (TID 80) (localhost, executor driver, partition 3, PROCESS_LOCAL, 169419 bytes) 
22:03:43.017 INFO  Executor - Running task 0.0 in stage 33.0 (TID 77)
22:03:43.017 INFO  Executor - Running task 3.0 in stage 33.0 (TID 80)
22:03:43.017 INFO  Executor - Running task 1.0 in stage 33.0 (TID 78)
22:03:43.017 INFO  Executor - Running task 2.0 in stage 33.0 (TID 79)
22:03:43.021 INFO  Executor - Finished task 0.0 in stage 33.0 (TID 77). 163161 bytes result sent to driver
22:03:43.023 INFO  Executor - Finished task 1.0 in stage 33.0 (TID 78). 163411 bytes result sent to driver
22:03:43.024 INFO  Executor - Finished task 2.0 in stage 33.0 (TID 79). 163356 bytes result sent to driver
22:03:43.024 INFO  TaskSetManager - Finished task 0.0 in stage 33.0 (TID 77) in 11 ms on localhost (executor driver) (1/4)
22:03:43.025 INFO  Executor - Finished task 3.0 in stage 33.0 (TID 80). 162737 bytes result sent to driver
22:03:43.026 INFO  TaskSetManager - Finished task 1.0 in stage 33.0 (TID 78) in 12 ms on localhost (executor driver) (2/4)
22:03:43.026 INFO  TaskSetManager - Finished task 2.0 in stage 33.0 (TID 79) in 11 ms on localhost (executor driver) (3/4)
22:03:43.027 INFO  TaskSetManager - Finished task 3.0 in stage 33.0 (TID 80) in 11 ms on localhost (executor driver) (4/4)
22:03:43.027 INFO  TaskSchedulerImpl - Removed TaskSet 33.0, whose tasks have all completed, from pool 
22:03:43.027 INFO  DAGScheduler - ResultStage 33 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.017 s
22:03:43.028 INFO  DAGScheduler - Job 24 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:43.028 INFO  TaskSchedulerImpl - Killing all running tasks in stage 33: Stage finished
22:03:43.028 INFO  DAGScheduler - Job 24 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.019246 s
22:03:43.029 INFO  FileInputFormat - Total input files to process : 1
22:03:43.068 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
22:03:43.068 INFO  DAGScheduler - Got job 25 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
22:03:43.068 INFO  DAGScheduler - Final stage: ResultStage 34 (collect at ReadsSparkSourceUnitTest.java:112)
22:03:43.068 INFO  DAGScheduler - Parents of final stage: List()
22:03:43.068 INFO  DAGScheduler - Missing parents: List()
22:03:43.069 INFO  DAGScheduler - Submitting ResultStage 34 (MapPartitionsRDD[102] at filter at ReadsSparkSource.java:96), which has no missing parents
22:03:43.086 INFO  MemoryStore - Block broadcast_45 stored as values in memory (estimated size 425.0 KiB, free 1918.0 MiB)
22:03:43.088 INFO  MemoryStore - Block broadcast_45_piece0 stored as bytes in memory (estimated size 152.7 KiB, free 1917.8 MiB)
22:03:43.088 INFO  BlockManagerInfo - Added broadcast_45_piece0 in memory on localhost:41281 (size: 152.7 KiB, free: 1919.6 MiB)
22:03:43.088 INFO  SparkContext - Created broadcast 45 from broadcast at DAGScheduler.scala:1580
22:03:43.089 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 34 (MapPartitionsRDD[102] at filter at ReadsSparkSource.java:96) (first 15 tasks are for partitions Vector(0))
22:03:43.089 INFO  TaskSchedulerImpl - Adding task set 34.0 with 1 tasks resource profile 0
22:03:43.090 INFO  TaskSetManager - Starting task 0.0 in stage 34.0 (TID 81) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7905 bytes) 
22:03:43.090 INFO  Executor - Running task 0.0 in stage 34.0 (TID 81)
22:03:43.139 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/expected.HiSeq.1mb.1RG.2k_lines.alternate.recalibrated.DIQ.bam:0+216896
22:03:43.162 INFO  Executor - Finished task 0.0 in stage 34.0 (TID 81). 650184 bytes result sent to driver
22:03:43.164 INFO  TaskSetManager - Finished task 0.0 in stage 34.0 (TID 81) in 75 ms on localhost (executor driver) (1/1)
22:03:43.164 INFO  TaskSchedulerImpl - Removed TaskSet 34.0, whose tasks have all completed, from pool 
22:03:43.165 INFO  DAGScheduler - ResultStage 34 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.096 s
22:03:43.165 INFO  DAGScheduler - Job 25 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:43.165 INFO  TaskSchedulerImpl - Killing all running tasks in stage 34: Stage finished
22:03:43.165 INFO  DAGScheduler - Job 25 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.097136 s
22:03:43.171 INFO  MemoryStore - Block broadcast_46 stored as values in memory (estimated size 528.0 B, free 1917.8 MiB)
22:03:43.172 INFO  MemoryStore - Block broadcast_46_piece0 stored as bytes in memory (estimated size 183.0 B, free 1917.8 MiB)
22:03:43.173 INFO  BlockManagerInfo - Added broadcast_46_piece0 in memory on localhost:41281 (size: 183.0 B, free: 1919.6 MiB)
22:03:43.173 INFO  SparkContext - Created broadcast 46 from broadcast at CramSource.java:114
22:03:43.175 INFO  MemoryStore - Block broadcast_47 stored as values in memory (estimated size 297.2 KiB, free 1917.6 MiB)
22:03:43.182 INFO  MemoryStore - Block broadcast_47_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1917.5 MiB)
22:03:43.182 INFO  BlockManagerInfo - Added broadcast_47_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1919.5 MiB)
22:03:43.183 INFO  SparkContext - Created broadcast 47 from newAPIHadoopFile at PathSplitSource.java:96
22:03:43.209 INFO  MemoryStore - Block broadcast_48 stored as values in memory (estimated size 528.0 B, free 1917.5 MiB)
22:03:43.210 INFO  MemoryStore - Block broadcast_48_piece0 stored as bytes in memory (estimated size 183.0 B, free 1917.5 MiB)
22:03:43.210 INFO  BlockManagerInfo - Added broadcast_48_piece0 in memory on localhost:41281 (size: 183.0 B, free: 1919.5 MiB)
22:03:43.210 INFO  SparkContext - Created broadcast 48 from broadcast at CramSource.java:114
22:03:43.212 INFO  MemoryStore - Block broadcast_49 stored as values in memory (estimated size 297.2 KiB, free 1917.2 MiB)
22:03:43.219 INFO  MemoryStore - Block broadcast_49_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1917.2 MiB)
22:03:43.219 INFO  BlockManagerInfo - Added broadcast_49_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1919.5 MiB)
22:03:43.220 INFO  SparkContext - Created broadcast 49 from newAPIHadoopFile at PathSplitSource.java:96
22:03:43.238 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
22:03:43.238 INFO  DAGScheduler - Got job 26 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
22:03:43.238 INFO  DAGScheduler - Final stage: ResultStage 35 (collect at ReadsSparkSourceUnitTest.java:111)
22:03:43.238 INFO  DAGScheduler - Parents of final stage: List()
22:03:43.238 INFO  DAGScheduler - Missing parents: List()
22:03:43.239 INFO  DAGScheduler - Submitting ResultStage 35 (ParallelCollectionRDD[107] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
22:03:43.239 INFO  MemoryStore - Block broadcast_50 stored as values in memory (estimated size 3.0 KiB, free 1917.2 MiB)
22:03:43.241 INFO  MemoryStore - Block broadcast_50_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1917.2 MiB)
22:03:43.241 INFO  BlockManagerInfo - Added broadcast_50_piece0 in memory on localhost:41281 (size: 1780.0 B, free: 1919.5 MiB)
22:03:43.241 INFO  SparkContext - Created broadcast 50 from broadcast at DAGScheduler.scala:1580
22:03:43.241 INFO  DAGScheduler - Submitting 4 missing tasks from ResultStage 35 (ParallelCollectionRDD[107] at parallelize at ReadsSparkSourceUnitTest.java:310) (first 15 tasks are for partitions Vector(0, 1, 2, 3))
22:03:43.241 INFO  TaskSchedulerImpl - Adding task set 35.0 with 4 tasks resource profile 0
22:03:43.245 INFO  TaskSetManager - Starting task 0.0 in stage 35.0 (TID 82) (localhost, executor driver, partition 0, PROCESS_LOCAL, 45675 bytes) 
22:03:43.247 INFO  TaskSetManager - Starting task 1.0 in stage 35.0 (TID 83) (localhost, executor driver, partition 1, PROCESS_LOCAL, 45855 bytes) 
22:03:43.249 INFO  TaskSetManager - Starting task 2.0 in stage 35.0 (TID 84) (localhost, executor driver, partition 2, PROCESS_LOCAL, 45795 bytes) 
22:03:43.250 INFO  TaskSetManager - Starting task 3.0 in stage 35.0 (TID 85) (localhost, executor driver, partition 3, PROCESS_LOCAL, 46068 bytes) 
22:03:43.251 INFO  Executor - Running task 2.0 in stage 35.0 (TID 84)
22:03:43.251 INFO  Executor - Running task 3.0 in stage 35.0 (TID 85)
22:03:43.251 INFO  Executor - Running task 1.0 in stage 35.0 (TID 83)
22:03:43.251 INFO  Executor - Running task 0.0 in stage 35.0 (TID 82)
22:03:43.254 INFO  Executor - Finished task 3.0 in stage 35.0 (TID 85). 39343 bytes result sent to driver
22:03:43.254 INFO  Executor - Finished task 1.0 in stage 35.0 (TID 83). 39130 bytes result sent to driver
22:03:43.254 INFO  Executor - Finished task 0.0 in stage 35.0 (TID 82). 38993 bytes result sent to driver
22:03:43.255 INFO  TaskSetManager - Finished task 3.0 in stage 35.0 (TID 85) in 6 ms on localhost (executor driver) (1/4)
22:03:43.255 INFO  TaskSetManager - Finished task 1.0 in stage 35.0 (TID 83) in 10 ms on localhost (executor driver) (2/4)
22:03:43.255 INFO  Executor - Finished task 2.0 in stage 35.0 (TID 84). 39070 bytes result sent to driver
22:03:43.256 INFO  TaskSetManager - Finished task 2.0 in stage 35.0 (TID 84) in 8 ms on localhost (executor driver) (3/4)
22:03:43.257 INFO  TaskSetManager - Finished task 0.0 in stage 35.0 (TID 82) in 15 ms on localhost (executor driver) (4/4)
22:03:43.257 INFO  TaskSchedulerImpl - Removed TaskSet 35.0, whose tasks have all completed, from pool 
22:03:43.257 INFO  DAGScheduler - ResultStage 35 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.018 s
22:03:43.257 INFO  DAGScheduler - Job 26 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:43.257 INFO  TaskSchedulerImpl - Killing all running tasks in stage 35: Stage finished
22:03:43.258 INFO  DAGScheduler - Job 26 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.019516 s
22:03:43.259 INFO  FileInputFormat - Total input files to process : 1
22:03:43.285 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
22:03:43.286 INFO  DAGScheduler - Got job 27 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
22:03:43.286 INFO  DAGScheduler - Final stage: ResultStage 36 (collect at ReadsSparkSourceUnitTest.java:112)
22:03:43.286 INFO  DAGScheduler - Parents of final stage: List()
22:03:43.286 INFO  DAGScheduler - Missing parents: List()
22:03:43.286 INFO  DAGScheduler - Submitting ResultStage 36 (MapPartitionsRDD[113] at filter at ReadsSparkSource.java:96), which has no missing parents
22:03:43.298 INFO  MemoryStore - Block broadcast_51 stored as values in memory (estimated size 286.0 KiB, free 1916.9 MiB)
22:03:43.300 INFO  MemoryStore - Block broadcast_51_piece0 stored as bytes in memory (estimated size 103.1 KiB, free 1916.8 MiB)
22:03:43.300 INFO  BlockManagerInfo - Added broadcast_51_piece0 in memory on localhost:41281 (size: 103.1 KiB, free: 1919.4 MiB)
22:03:43.301 INFO  SparkContext - Created broadcast 51 from broadcast at DAGScheduler.scala:1580
22:03:43.301 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 36 (MapPartitionsRDD[113] at filter at ReadsSparkSource.java:96) (first 15 tasks are for partitions Vector(0))
22:03:43.301 INFO  TaskSchedulerImpl - Adding task set 36.0 with 1 tasks resource profile 0
22:03:43.302 INFO  TaskSetManager - Starting task 0.0 in stage 36.0 (TID 86) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7832 bytes) 
22:03:43.303 INFO  Executor - Running task 0.0 in stage 36.0 (TID 86)
22:03:43.331 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram:0+50619
22:03:43.345 INFO  Executor - Finished task 0.0 in stage 36.0 (TID 86). 154101 bytes result sent to driver
22:03:43.346 INFO  TaskSetManager - Finished task 0.0 in stage 36.0 (TID 86) in 44 ms on localhost (executor driver) (1/1)
22:03:43.346 INFO  TaskSchedulerImpl - Removed TaskSet 36.0, whose tasks have all completed, from pool 
22:03:43.346 INFO  DAGScheduler - ResultStage 36 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.059 s
22:03:43.347 INFO  DAGScheduler - Job 27 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:43.347 INFO  TaskSchedulerImpl - Killing all running tasks in stage 36: Stage finished
22:03:43.347 INFO  DAGScheduler - Job 27 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.061238 s
22:03:43.352 INFO  MemoryStore - Block broadcast_52 stored as values in memory (estimated size 600.0 B, free 1916.8 MiB)
22:03:43.354 INFO  MemoryStore - Block broadcast_52_piece0 stored as bytes in memory (estimated size 202.0 B, free 1916.8 MiB)
22:03:43.354 INFO  BlockManagerInfo - Added broadcast_52_piece0 in memory on localhost:41281 (size: 202.0 B, free: 1919.4 MiB)
22:03:43.354 INFO  SparkContext - Created broadcast 52 from broadcast at CramSource.java:114
22:03:43.357 INFO  MemoryStore - Block broadcast_53 stored as values in memory (estimated size 297.3 KiB, free 1916.5 MiB)
22:03:43.363 INFO  MemoryStore - Block broadcast_53_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1916.4 MiB)
22:03:43.364 INFO  BlockManagerInfo - Added broadcast_53_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1919.3 MiB)
22:03:43.364 INFO  SparkContext - Created broadcast 53 from newAPIHadoopFile at PathSplitSource.java:96
22:03:43.384 INFO  MemoryStore - Block broadcast_54 stored as values in memory (estimated size 600.0 B, free 1916.4 MiB)
22:03:43.385 INFO  MemoryStore - Block broadcast_54_piece0 stored as bytes in memory (estimated size 202.0 B, free 1916.4 MiB)
22:03:43.386 INFO  BlockManagerInfo - Added broadcast_54_piece0 in memory on localhost:41281 (size: 202.0 B, free: 1919.3 MiB)
22:03:43.386 INFO  SparkContext - Created broadcast 54 from broadcast at CramSource.java:114
22:03:43.388 INFO  MemoryStore - Block broadcast_55 stored as values in memory (estimated size 297.3 KiB, free 1916.2 MiB)
22:03:43.396 INFO  MemoryStore - Block broadcast_55_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1916.1 MiB)
22:03:43.396 INFO  BlockManagerInfo - Added broadcast_55_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1919.3 MiB)
22:03:43.396 INFO  SparkContext - Created broadcast 55 from newAPIHadoopFile at PathSplitSource.java:96
22:03:43.415 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
22:03:43.415 INFO  DAGScheduler - Got job 28 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
22:03:43.415 INFO  DAGScheduler - Final stage: ResultStage 37 (collect at ReadsSparkSourceUnitTest.java:111)
22:03:43.415 INFO  DAGScheduler - Parents of final stage: List()
22:03:43.415 INFO  DAGScheduler - Missing parents: List()
22:03:43.415 INFO  DAGScheduler - Submitting ResultStage 37 (ParallelCollectionRDD[118] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
22:03:43.416 INFO  MemoryStore - Block broadcast_56 stored as values in memory (estimated size 3.0 KiB, free 1916.1 MiB)
22:03:43.417 INFO  MemoryStore - Block broadcast_56_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1916.1 MiB)
22:03:43.417 INFO  BlockManagerInfo - Added broadcast_56_piece0 in memory on localhost:41281 (size: 1780.0 B, free: 1919.3 MiB)
22:03:43.417 INFO  SparkContext - Created broadcast 56 from broadcast at DAGScheduler.scala:1580
22:03:43.418 INFO  DAGScheduler - Submitting 4 missing tasks from ResultStage 37 (ParallelCollectionRDD[118] at parallelize at ReadsSparkSourceUnitTest.java:310) (first 15 tasks are for partitions Vector(0, 1, 2, 3))
22:03:43.418 INFO  TaskSchedulerImpl - Adding task set 37.0 with 4 tasks resource profile 0
22:03:43.419 INFO  TaskSetManager - Starting task 0.0 in stage 37.0 (TID 87) (localhost, executor driver, partition 0, PROCESS_LOCAL, 8303 bytes) 
22:03:43.419 INFO  TaskSetManager - Starting task 1.0 in stage 37.0 (TID 88) (localhost, executor driver, partition 1, PROCESS_LOCAL, 8292 bytes) 
22:03:43.419 INFO  TaskSetManager - Starting task 2.0 in stage 37.0 (TID 89) (localhost, executor driver, partition 2, PROCESS_LOCAL, 8292 bytes) 
22:03:43.420 INFO  TaskSetManager - Starting task 3.0 in stage 37.0 (TID 90) (localhost, executor driver, partition 3, PROCESS_LOCAL, 8184 bytes) 
22:03:43.424 INFO  Executor - Running task 1.0 in stage 37.0 (TID 88)
22:03:43.424 INFO  Executor - Running task 2.0 in stage 37.0 (TID 89)
22:03:43.424 INFO  Executor - Running task 0.0 in stage 37.0 (TID 87)
22:03:43.424 INFO  Executor - Running task 3.0 in stage 37.0 (TID 90)
22:03:43.427 INFO  Executor - Finished task 3.0 in stage 37.0 (TID 90). 1459 bytes result sent to driver
22:03:43.427 INFO  Executor - Finished task 0.0 in stage 37.0 (TID 87). 1578 bytes result sent to driver
22:03:43.428 INFO  Executor - Finished task 1.0 in stage 37.0 (TID 88). 1567 bytes result sent to driver
22:03:43.428 INFO  Executor - Finished task 2.0 in stage 37.0 (TID 89). 1567 bytes result sent to driver
22:03:43.428 INFO  TaskSetManager - Finished task 0.0 in stage 37.0 (TID 87) in 10 ms on localhost (executor driver) (1/4)
22:03:43.429 INFO  TaskSetManager - Finished task 2.0 in stage 37.0 (TID 89) in 9 ms on localhost (executor driver) (2/4)
22:03:43.429 INFO  TaskSetManager - Finished task 3.0 in stage 37.0 (TID 90) in 10 ms on localhost (executor driver) (3/4)
22:03:43.429 INFO  TaskSetManager - Finished task 1.0 in stage 37.0 (TID 88) in 10 ms on localhost (executor driver) (4/4)
22:03:43.429 INFO  TaskSchedulerImpl - Removed TaskSet 37.0, whose tasks have all completed, from pool 
22:03:43.430 INFO  DAGScheduler - ResultStage 37 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.014 s
22:03:43.430 INFO  DAGScheduler - Job 28 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:43.430 INFO  TaskSchedulerImpl - Killing all running tasks in stage 37: Stage finished
22:03:43.430 INFO  DAGScheduler - Job 28 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.015014 s
22:03:43.432 INFO  FileInputFormat - Total input files to process : 1
22:03:43.461 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
22:03:43.461 INFO  DAGScheduler - Got job 29 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
22:03:43.461 INFO  DAGScheduler - Final stage: ResultStage 38 (collect at ReadsSparkSourceUnitTest.java:112)
22:03:43.461 INFO  DAGScheduler - Parents of final stage: List()
22:03:43.461 INFO  DAGScheduler - Missing parents: List()
22:03:43.462 INFO  DAGScheduler - Submitting ResultStage 38 (MapPartitionsRDD[124] at filter at ReadsSparkSource.java:96), which has no missing parents
22:03:43.475 INFO  MemoryStore - Block broadcast_57 stored as values in memory (estimated size 286.0 KiB, free 1915.8 MiB)
22:03:43.477 INFO  MemoryStore - Block broadcast_57_piece0 stored as bytes in memory (estimated size 103.1 KiB, free 1915.7 MiB)
22:03:43.477 INFO  BlockManagerInfo - Added broadcast_57_piece0 in memory on localhost:41281 (size: 103.1 KiB, free: 1919.2 MiB)
22:03:43.477 INFO  SparkContext - Created broadcast 57 from broadcast at DAGScheduler.scala:1580
22:03:43.478 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 38 (MapPartitionsRDD[124] at filter at ReadsSparkSource.java:96) (first 15 tasks are for partitions Vector(0))
22:03:43.478 INFO  TaskSchedulerImpl - Adding task set 38.0 with 1 tasks resource profile 0
22:03:43.479 INFO  TaskSetManager - Starting task 0.0 in stage 38.0 (TID 91) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7844 bytes) 
22:03:43.479 INFO  Executor - Running task 0.0 in stage 38.0 (TID 91)
22:03:43.509 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/valid.cram:0+13330
22:03:43.515 INFO  Executor - Finished task 0.0 in stage 38.0 (TID 91). 3736 bytes result sent to driver
22:03:43.516 INFO  TaskSetManager - Finished task 0.0 in stage 38.0 (TID 91) in 38 ms on localhost (executor driver) (1/1)
22:03:43.517 INFO  DAGScheduler - ResultStage 38 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.054 s
22:03:43.517 INFO  DAGScheduler - Job 29 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:43.517 INFO  TaskSchedulerImpl - Removed TaskSet 38.0, whose tasks have all completed, from pool 
22:03:43.517 INFO  TaskSchedulerImpl - Killing all running tasks in stage 38: Stage finished
22:03:43.517 INFO  DAGScheduler - Job 29 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.056414 s
22:03:43.524 INFO  MemoryStore - Block broadcast_58 stored as values in memory (estimated size 297.2 KiB, free 1915.4 MiB)
22:03:43.531 INFO  MemoryStore - Block broadcast_58_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1915.4 MiB)
22:03:43.531 INFO  BlockManagerInfo - Added broadcast_58_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1919.1 MiB)
22:03:43.532 INFO  SparkContext - Created broadcast 58 from newAPIHadoopFile at PathSplitSource.java:96
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 130, Read name 809R9ABXX101220:5:6:17918:145992, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 130, Read name 809R9ABXX101220:5:6:17918:145992, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 130, Read name 809R9ABXX101220:5:6:17918:145992, The unaligned mate start position is 69400, should be 0
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 275, Read name 809R9ABXX101220:5:8:7119:101555, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 275, Read name 809R9ABXX101220:5:8:7119:101555, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 275, Read name 809R9ABXX101220:5:8:7119:101555, The unaligned mate start position is 69471, should be 0
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 419, Read name 809R9ABXX101220:5:48:20204:50350, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 419, Read name 809R9ABXX101220:5:48:20204:50350, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 419, Read name 809R9ABXX101220:5:48:20204:50350, The unaligned mate start position is 69569, should be 0
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 440, Read name 809R9ABXX101220:5:44:13776:49360, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 440, Read name 809R9ABXX101220:5:44:13776:49360, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 440, Read name 809R9ABXX101220:5:44:13776:49360, The unaligned mate start position is 69592, should be 0
22:03:43.562 INFO  MemoryStore - Block broadcast_59 stored as values in memory (estimated size 297.2 KiB, free 1915.1 MiB)
22:03:43.569 INFO  MemoryStore - Block broadcast_59_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1915.0 MiB)
22:03:43.569 INFO  BlockManagerInfo - Added broadcast_59_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1919.1 MiB)
22:03:43.570 INFO  SparkContext - Created broadcast 59 from newAPIHadoopFile at PathSplitSource.java:96
22:03:43.595 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
22:03:43.596 INFO  DAGScheduler - Got job 30 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
22:03:43.596 INFO  DAGScheduler - Final stage: ResultStage 39 (collect at ReadsSparkSourceUnitTest.java:111)
22:03:43.596 INFO  DAGScheduler - Parents of final stage: List()
22:03:43.596 INFO  DAGScheduler - Missing parents: List()
22:03:43.596 INFO  DAGScheduler - Submitting ResultStage 39 (ParallelCollectionRDD[130] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
22:03:43.597 INFO  MemoryStore - Block broadcast_60 stored as values in memory (estimated size 3.0 KiB, free 1915.0 MiB)
22:03:43.597 INFO  MemoryStore - Block broadcast_60_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1915.0 MiB)
22:03:43.598 INFO  BlockManagerInfo - Added broadcast_60_piece0 in memory on localhost:41281 (size: 1780.0 B, free: 1919.1 MiB)
22:03:43.598 INFO  SparkContext - Created broadcast 60 from broadcast at DAGScheduler.scala:1580
22:03:43.598 INFO  DAGScheduler - Submitting 4 missing tasks from ResultStage 39 (ParallelCollectionRDD[130] at parallelize at ReadsSparkSourceUnitTest.java:310) (first 15 tasks are for partitions Vector(0, 1, 2, 3))
22:03:43.598 INFO  TaskSchedulerImpl - Adding task set 39.0 with 4 tasks resource profile 0
22:03:43.599 INFO  TaskSetManager - Starting task 0.0 in stage 39.0 (TID 92) (localhost, executor driver, partition 0, PROCESS_LOCAL, 47080 bytes) 
22:03:43.600 INFO  TaskSetManager - Starting task 1.0 in stage 39.0 (TID 93) (localhost, executor driver, partition 1, PROCESS_LOCAL, 47194 bytes) 
22:03:43.600 INFO  TaskSetManager - Starting task 2.0 in stage 39.0 (TID 94) (localhost, executor driver, partition 2, PROCESS_LOCAL, 47105 bytes) 
22:03:43.601 INFO  TaskSetManager - Starting task 3.0 in stage 39.0 (TID 95) (localhost, executor driver, partition 3, PROCESS_LOCAL, 47530 bytes) 
22:03:43.601 INFO  Executor - Running task 2.0 in stage 39.0 (TID 94)
22:03:43.601 INFO  Executor - Running task 0.0 in stage 39.0 (TID 92)
22:03:43.602 INFO  Executor - Running task 3.0 in stage 39.0 (TID 95)
22:03:43.603 INFO  Executor - Running task 1.0 in stage 39.0 (TID 93)
22:03:43.604 INFO  Executor - Finished task 3.0 in stage 39.0 (TID 95). 40805 bytes result sent to driver
22:03:43.605 INFO  Executor - Finished task 2.0 in stage 39.0 (TID 94). 40380 bytes result sent to driver
22:03:43.605 INFO  Executor - Finished task 1.0 in stage 39.0 (TID 93). 40469 bytes result sent to driver
22:03:43.606 INFO  TaskSetManager - Finished task 3.0 in stage 39.0 (TID 95) in 5 ms on localhost (executor driver) (1/4)
22:03:43.606 INFO  TaskSetManager - Finished task 2.0 in stage 39.0 (TID 94) in 6 ms on localhost (executor driver) (2/4)
22:03:43.607 INFO  TaskSetManager - Finished task 1.0 in stage 39.0 (TID 93) in 7 ms on localhost (executor driver) (3/4)
22:03:43.607 INFO  Executor - Finished task 0.0 in stage 39.0 (TID 92). 40355 bytes result sent to driver
22:03:43.608 INFO  TaskSetManager - Finished task 0.0 in stage 39.0 (TID 92) in 9 ms on localhost (executor driver) (4/4)
22:03:43.608 INFO  TaskSchedulerImpl - Removed TaskSet 39.0, whose tasks have all completed, from pool 
22:03:43.609 INFO  DAGScheduler - ResultStage 39 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.013 s
22:03:43.609 INFO  DAGScheduler - Job 30 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:43.609 INFO  TaskSchedulerImpl - Killing all running tasks in stage 39: Stage finished
22:03:43.609 INFO  DAGScheduler - Job 30 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.013928 s
22:03:43.611 INFO  FileInputFormat - Total input files to process : 1
22:03:43.650 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
22:03:43.650 INFO  DAGScheduler - Got job 31 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
22:03:43.651 INFO  DAGScheduler - Final stage: ResultStage 40 (collect at ReadsSparkSourceUnitTest.java:112)
22:03:43.651 INFO  DAGScheduler - Parents of final stage: List()
22:03:43.651 INFO  DAGScheduler - Missing parents: List()
22:03:43.651 INFO  DAGScheduler - Submitting ResultStage 40 (MapPartitionsRDD[137] at filter at ReadsSparkSource.java:96), which has no missing parents
22:03:43.669 INFO  MemoryStore - Block broadcast_61 stored as values in memory (estimated size 425.0 KiB, free 1914.6 MiB)
22:03:43.671 INFO  MemoryStore - Block broadcast_61_piece0 stored as bytes in memory (estimated size 152.7 KiB, free 1914.5 MiB)
22:03:43.671 INFO  BlockManagerInfo - Added broadcast_61_piece0 in memory on localhost:41281 (size: 152.7 KiB, free: 1918.9 MiB)
22:03:43.671 INFO  SparkContext - Created broadcast 61 from broadcast at DAGScheduler.scala:1580
22:03:43.672 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 40 (MapPartitionsRDD[137] at filter at ReadsSparkSource.java:96) (first 15 tasks are for partitions Vector(0))
22:03:43.672 INFO  TaskSchedulerImpl - Adding task set 40.0 with 1 tasks resource profile 0
22:03:43.673 INFO  TaskSetManager - Starting task 0.0 in stage 40.0 (TID 96) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7831 bytes) 
22:03:43.673 INFO  Executor - Running task 0.0 in stage 40.0 (TID 96)
22:03:43.714 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam:0+57538
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 130, Read name 809R9ABXX101220:5:6:17918:145992, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 130, Read name 809R9ABXX101220:5:6:17918:145992, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 130, Read name 809R9ABXX101220:5:6:17918:145992, The unaligned mate start position is 69400, should be 0
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 275, Read name 809R9ABXX101220:5:8:7119:101555, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 275, Read name 809R9ABXX101220:5:8:7119:101555, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 275, Read name 809R9ABXX101220:5:8:7119:101555, The unaligned mate start position is 69471, should be 0
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 419, Read name 809R9ABXX101220:5:48:20204:50350, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 419, Read name 809R9ABXX101220:5:48:20204:50350, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 419, Read name 809R9ABXX101220:5:48:20204:50350, The unaligned mate start position is 69569, should be 0
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 440, Read name 809R9ABXX101220:5:44:13776:49360, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 440, Read name 809R9ABXX101220:5:44:13776:49360, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 440, Read name 809R9ABXX101220:5:44:13776:49360, The unaligned mate start position is 69592, should be 0
22:03:43.725 INFO  Executor - Finished task 0.0 in stage 40.0 (TID 96). 159615 bytes result sent to driver
22:03:43.727 INFO  TaskSetManager - Finished task 0.0 in stage 40.0 (TID 96) in 54 ms on localhost (executor driver) (1/1)
22:03:43.727 INFO  TaskSchedulerImpl - Removed TaskSet 40.0, whose tasks have all completed, from pool 
22:03:43.727 INFO  DAGScheduler - ResultStage 40 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.076 s
22:03:43.727 INFO  DAGScheduler - Job 31 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:43.727 INFO  TaskSchedulerImpl - Killing all running tasks in stage 40: Stage finished
22:03:43.728 INFO  DAGScheduler - Job 31 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.077565 s
22:03:43.733 INFO  MemoryStore - Block broadcast_62 stored as values in memory (estimated size 528.0 B, free 1914.5 MiB)
22:03:43.734 INFO  MemoryStore - Block broadcast_62_piece0 stored as bytes in memory (estimated size 183.0 B, free 1914.5 MiB)
22:03:43.734 INFO  BlockManagerInfo - Added broadcast_62_piece0 in memory on localhost:41281 (size: 183.0 B, free: 1918.9 MiB)
22:03:43.735 INFO  SparkContext - Created broadcast 62 from broadcast at CramSource.java:114
22:03:43.737 INFO  MemoryStore - Block broadcast_63 stored as values in memory (estimated size 297.2 KiB, free 1914.2 MiB)
22:03:43.745 INFO  MemoryStore - Block broadcast_63_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1914.1 MiB)
22:03:43.745 INFO  BlockManagerInfo - Added broadcast_63_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1918.9 MiB)
22:03:43.745 INFO  SparkContext - Created broadcast 63 from newAPIHadoopFile at PathSplitSource.java:96
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 129, Read name 809R9ABXX101220:5:6:17918:145992, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 129, Read name 809R9ABXX101220:5:6:17918:145992, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 129, Read name 809R9ABXX101220:5:6:17918:145992, The unaligned mate start position is 69400, should be 0
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 274, Read name 809R9ABXX101220:5:8:7119:101555, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 274, Read name 809R9ABXX101220:5:8:7119:101555, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 274, Read name 809R9ABXX101220:5:8:7119:101555, The unaligned mate start position is 69471, should be 0
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 418, Read name 809R9ABXX101220:5:48:20204:50350, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 418, Read name 809R9ABXX101220:5:48:20204:50350, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 418, Read name 809R9ABXX101220:5:48:20204:50350, The unaligned mate start position is 69569, should be 0
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 439, Read name 809R9ABXX101220:5:44:13776:49360, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 439, Read name 809R9ABXX101220:5:44:13776:49360, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 439, Read name 809R9ABXX101220:5:44:13776:49360, The unaligned mate start position is 69592, should be 0
22:03:43.775 INFO  MemoryStore - Block broadcast_64 stored as values in memory (estimated size 528.0 B, free 1914.1 MiB)
22:03:43.776 INFO  MemoryStore - Block broadcast_64_piece0 stored as bytes in memory (estimated size 183.0 B, free 1914.1 MiB)
22:03:43.776 INFO  BlockManagerInfo - Added broadcast_64_piece0 in memory on localhost:41281 (size: 183.0 B, free: 1918.9 MiB)
22:03:43.777 INFO  SparkContext - Created broadcast 64 from broadcast at CramSource.java:114
22:03:43.780 INFO  MemoryStore - Block broadcast_65 stored as values in memory (estimated size 297.2 KiB, free 1913.8 MiB)
22:03:43.787 INFO  MemoryStore - Block broadcast_65_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1913.8 MiB)
22:03:43.787 INFO  BlockManagerInfo - Added broadcast_65_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1918.8 MiB)
22:03:43.788 INFO  SparkContext - Created broadcast 65 from newAPIHadoopFile at PathSplitSource.java:96
22:03:43.807 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
22:03:43.807 INFO  DAGScheduler - Got job 32 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
22:03:43.807 INFO  DAGScheduler - Final stage: ResultStage 41 (collect at ReadsSparkSourceUnitTest.java:111)
22:03:43.807 INFO  DAGScheduler - Parents of final stage: List()
22:03:43.807 INFO  DAGScheduler - Missing parents: List()
22:03:43.808 INFO  DAGScheduler - Submitting ResultStage 41 (ParallelCollectionRDD[142] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
22:03:43.808 INFO  MemoryStore - Block broadcast_66 stored as values in memory (estimated size 3.0 KiB, free 1913.8 MiB)
22:03:43.809 INFO  MemoryStore - Block broadcast_66_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1913.8 MiB)
22:03:43.809 INFO  BlockManagerInfo - Added broadcast_66_piece0 in memory on localhost:41281 (size: 1780.0 B, free: 1918.8 MiB)
22:03:43.810 INFO  SparkContext - Created broadcast 66 from broadcast at DAGScheduler.scala:1580
22:03:43.810 INFO  DAGScheduler - Submitting 4 missing tasks from ResultStage 41 (ParallelCollectionRDD[142] at parallelize at ReadsSparkSourceUnitTest.java:310) (first 15 tasks are for partitions Vector(0, 1, 2, 3))
22:03:43.810 INFO  TaskSchedulerImpl - Adding task set 41.0 with 4 tasks resource profile 0
22:03:43.812 INFO  TaskSetManager - Starting task 0.0 in stage 41.0 (TID 97) (localhost, executor driver, partition 0, PROCESS_LOCAL, 45675 bytes) 
22:03:43.813 INFO  TaskSetManager - Starting task 1.0 in stage 41.0 (TID 98) (localhost, executor driver, partition 1, PROCESS_LOCAL, 45855 bytes) 
22:03:43.815 INFO  TaskSetManager - Starting task 2.0 in stage 41.0 (TID 99) (localhost, executor driver, partition 2, PROCESS_LOCAL, 45795 bytes) 
22:03:43.815 INFO  TaskSetManager - Starting task 3.0 in stage 41.0 (TID 100) (localhost, executor driver, partition 3, PROCESS_LOCAL, 46068 bytes) 
22:03:43.816 INFO  Executor - Running task 0.0 in stage 41.0 (TID 97)
22:03:43.817 INFO  Executor - Running task 3.0 in stage 41.0 (TID 100)
22:03:43.819 INFO  Executor - Finished task 0.0 in stage 41.0 (TID 97). 38950 bytes result sent to driver
22:03:43.819 INFO  Executor - Finished task 3.0 in stage 41.0 (TID 100). 39300 bytes result sent to driver
22:03:43.819 INFO  Executor - Running task 2.0 in stage 41.0 (TID 99)
22:03:43.820 INFO  Executor - Running task 1.0 in stage 41.0 (TID 98)
22:03:43.820 INFO  TaskSetManager - Finished task 3.0 in stage 41.0 (TID 100) in 5 ms on localhost (executor driver) (1/4)
22:03:43.821 INFO  TaskSetManager - Finished task 0.0 in stage 41.0 (TID 97) in 10 ms on localhost (executor driver) (2/4)
22:03:43.823 INFO  Executor - Finished task 2.0 in stage 41.0 (TID 99). 39070 bytes result sent to driver
22:03:43.823 INFO  TaskSetManager - Finished task 2.0 in stage 41.0 (TID 99) in 10 ms on localhost (executor driver) (3/4)
22:03:43.824 INFO  Executor - Finished task 1.0 in stage 41.0 (TID 98). 39173 bytes result sent to driver
22:03:43.825 INFO  TaskSetManager - Finished task 1.0 in stage 41.0 (TID 98) in 13 ms on localhost (executor driver) (4/4)
22:03:43.825 INFO  DAGScheduler - ResultStage 41 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.017 s
22:03:43.825 INFO  DAGScheduler - Job 32 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:43.825 INFO  TaskSchedulerImpl - Removed TaskSet 41.0, whose tasks have all completed, from pool 
22:03:43.825 INFO  TaskSchedulerImpl - Killing all running tasks in stage 41: Stage finished
22:03:43.826 INFO  DAGScheduler - Job 32 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.018710 s
22:03:43.827 INFO  FileInputFormat - Total input files to process : 1
22:03:43.847 INFO  BlockManagerInfo - Removed broadcast_39_piece0 on localhost:41281 in memory (size: 50.1 KiB, free: 1918.9 MiB)
22:03:43.849 INFO  BlockManagerInfo - Removed broadcast_62_piece0 on localhost:41281 in memory (size: 183.0 B, free: 1918.9 MiB)
22:03:43.850 INFO  BlockManagerInfo - Removed broadcast_41_piece0 on localhost:41281 in memory (size: 152.7 KiB, free: 1919.0 MiB)
22:03:43.852 INFO  BlockManagerInfo - Removed broadcast_45_piece0 on localhost:41281 in memory (size: 152.7 KiB, free: 1919.2 MiB)
22:03:43.854 INFO  BlockManagerInfo - Removed broadcast_66_piece0 on localhost:41281 in memory (size: 1780.0 B, free: 1919.2 MiB)
22:03:43.855 INFO  BlockManagerInfo - Removed broadcast_51_piece0 on localhost:41281 in memory (size: 103.1 KiB, free: 1919.3 MiB)
22:03:43.861 INFO  BlockManagerInfo - Removed broadcast_60_piece0 on localhost:41281 in memory (size: 1780.0 B, free: 1919.3 MiB)
22:03:43.864 INFO  BlockManagerInfo - Removed broadcast_46_piece0 on localhost:41281 in memory (size: 183.0 B, free: 1919.3 MiB)
22:03:43.872 INFO  BlockManagerInfo - Removed broadcast_50_piece0 on localhost:41281 in memory (size: 1780.0 B, free: 1919.3 MiB)
22:03:43.874 INFO  BlockManagerInfo - Removed broadcast_48_piece0 on localhost:41281 in memory (size: 183.0 B, free: 1919.3 MiB)
22:03:43.883 INFO  BlockManagerInfo - Removed broadcast_63_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1919.3 MiB)
22:03:43.891 INFO  BlockManagerInfo - Removed broadcast_54_piece0 on localhost:41281 in memory (size: 202.0 B, free: 1919.3 MiB)
22:03:43.894 INFO  BlockManagerInfo - Removed broadcast_59_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1919.4 MiB)
22:03:43.894 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
22:03:43.896 INFO  DAGScheduler - Got job 33 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
22:03:43.896 INFO  DAGScheduler - Final stage: ResultStage 42 (collect at ReadsSparkSourceUnitTest.java:112)
22:03:43.896 INFO  DAGScheduler - Parents of final stage: List()
22:03:43.897 INFO  DAGScheduler - Missing parents: List()
22:03:43.898 INFO  DAGScheduler - Submitting ResultStage 42 (MapPartitionsRDD[148] at filter at ReadsSparkSource.java:96), which has no missing parents
22:03:43.904 INFO  BlockManagerInfo - Removed broadcast_57_piece0 on localhost:41281 in memory (size: 103.1 KiB, free: 1919.5 MiB)
22:03:43.908 INFO  BlockManagerInfo - Removed broadcast_49_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1919.5 MiB)
22:03:43.909 INFO  BlockManagerInfo - Removed broadcast_44_piece0 on localhost:41281 in memory (size: 1780.0 B, free: 1919.5 MiB)
22:03:43.911 INFO  BlockManagerInfo - Removed broadcast_47_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1919.6 MiB)
22:03:43.914 INFO  BlockManagerInfo - Removed broadcast_52_piece0 on localhost:41281 in memory (size: 202.0 B, free: 1919.6 MiB)
22:03:43.914 INFO  BlockManagerInfo - Removed broadcast_55_piece0 on localhost:41281 in memory (size: 50.1 KiB, free: 1919.6 MiB)
22:03:43.915 INFO  BlockManagerInfo - Removed broadcast_43_piece0 on localhost:41281 in memory (size: 50.1 KiB, free: 1919.7 MiB)
22:03:43.917 INFO  BlockManagerInfo - Removed broadcast_58_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1919.7 MiB)
22:03:43.920 INFO  BlockManagerInfo - Removed broadcast_61_piece0 on localhost:41281 in memory (size: 152.7 KiB, free: 1919.9 MiB)
22:03:43.921 INFO  BlockManagerInfo - Removed broadcast_56_piece0 on localhost:41281 in memory (size: 1780.0 B, free: 1919.9 MiB)
22:03:43.923 INFO  BlockManagerInfo - Removed broadcast_53_piece0 on localhost:41281 in memory (size: 50.1 KiB, free: 1919.9 MiB)
22:03:43.924 INFO  MemoryStore - Block broadcast_67 stored as values in memory (estimated size 286.0 KiB, free 1919.0 MiB)
22:03:43.924 INFO  BlockManagerInfo - Removed broadcast_42_piece0 on localhost:41281 in memory (size: 50.1 KiB, free: 1920.0 MiB)
22:03:43.925 INFO  MemoryStore - Block broadcast_67_piece0 stored as bytes in memory (estimated size 103.1 KiB, free 1919.3 MiB)
22:03:43.925 INFO  BlockManagerInfo - Added broadcast_67_piece0 in memory on localhost:41281 (size: 103.1 KiB, free: 1919.9 MiB)
22:03:43.926 INFO  SparkContext - Created broadcast 67 from broadcast at DAGScheduler.scala:1580
22:03:43.926 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 42 (MapPartitionsRDD[148] at filter at ReadsSparkSource.java:96) (first 15 tasks are for partitions Vector(0))
22:03:43.926 INFO  TaskSchedulerImpl - Adding task set 42.0 with 1 tasks resource profile 0
22:03:43.927 INFO  TaskSetManager - Starting task 0.0 in stage 42.0 (TID 101) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7832 bytes) 
22:03:43.928 INFO  Executor - Running task 0.0 in stage 42.0 (TID 101)
22:03:43.956 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram:0+50619
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 129, Read name 809R9ABXX101220:5:6:17918:145992, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 129, Read name 809R9ABXX101220:5:6:17918:145992, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 129, Read name 809R9ABXX101220:5:6:17918:145992, The unaligned mate start position is 69400, should be 0
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 274, Read name 809R9ABXX101220:5:8:7119:101555, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 274, Read name 809R9ABXX101220:5:8:7119:101555, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 274, Read name 809R9ABXX101220:5:8:7119:101555, The unaligned mate start position is 69471, should be 0
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 418, Read name 809R9ABXX101220:5:48:20204:50350, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 418, Read name 809R9ABXX101220:5:48:20204:50350, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 418, Read name 809R9ABXX101220:5:48:20204:50350, The unaligned mate start position is 69569, should be 0
Ignoring SAM validation error: ERROR::INVALID_ALIGNMENT_START:Record 439, Read name 809R9ABXX101220:5:44:13776:49360, Mate Alignment start should be 0 because reference name = *.
Ignoring SAM validation error: ERROR::INVALID_FLAG_MATE_UNMAPPED:Record 439, Read name 809R9ABXX101220:5:44:13776:49360, Mapped mate should have mate reference name
Ignoring SAM validation error: ERROR::INVALID_UNALIGNED_MATE_START:Record 439, Read name 809R9ABXX101220:5:44:13776:49360, The unaligned mate start position is 69592, should be 0
22:03:43.971 INFO  Executor - Finished task 0.0 in stage 42.0 (TID 101). 154101 bytes result sent to driver
22:03:43.972 INFO  TaskSetManager - Finished task 0.0 in stage 42.0 (TID 101) in 45 ms on localhost (executor driver) (1/1)
22:03:43.972 INFO  TaskSchedulerImpl - Removed TaskSet 42.0, whose tasks have all completed, from pool 
22:03:43.972 INFO  DAGScheduler - ResultStage 42 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.073 s
22:03:43.972 INFO  DAGScheduler - Job 33 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:43.972 INFO  TaskSchedulerImpl - Killing all running tasks in stage 42: Stage finished
22:03:43.972 INFO  DAGScheduler - Job 33 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.076728 s
22:03:43.978 INFO  MemoryStore - Block broadcast_68 stored as values in memory (estimated size 297.2 KiB, free 1919.0 MiB)
22:03:43.985 INFO  MemoryStore - Block broadcast_68_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1918.9 MiB)
22:03:43.985 INFO  BlockManagerInfo - Added broadcast_68_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1919.8 MiB)
22:03:43.985 INFO  SparkContext - Created broadcast 68 from newAPIHadoopFile at PathSplitSource.java:96
22:03:44.014 INFO  MemoryStore - Block broadcast_69 stored as values in memory (estimated size 297.2 KiB, free 1918.7 MiB)
22:03:44.021 INFO  MemoryStore - Block broadcast_69_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1918.6 MiB)
22:03:44.021 INFO  BlockManagerInfo - Added broadcast_69_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1919.8 MiB)
22:03:44.021 INFO  SparkContext - Created broadcast 69 from newAPIHadoopFile at PathSplitSource.java:96
22:03:44.048 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
22:03:44.048 INFO  DAGScheduler - Got job 34 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
22:03:44.048 INFO  DAGScheduler - Final stage: ResultStage 43 (collect at ReadsSparkSourceUnitTest.java:111)
22:03:44.048 INFO  DAGScheduler - Parents of final stage: List()
22:03:44.048 INFO  DAGScheduler - Missing parents: List()
22:03:44.049 INFO  DAGScheduler - Submitting ResultStage 43 (ParallelCollectionRDD[154] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
22:03:44.050 INFO  MemoryStore - Block broadcast_70 stored as values in memory (estimated size 3.0 KiB, free 1918.6 MiB)
22:03:44.051 INFO  MemoryStore - Block broadcast_70_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1918.6 MiB)
22:03:44.051 INFO  BlockManagerInfo - Added broadcast_70_piece0 in memory on localhost:41281 (size: 1780.0 B, free: 1919.8 MiB)
22:03:44.052 INFO  SparkContext - Created broadcast 70 from broadcast at DAGScheduler.scala:1580
22:03:44.052 INFO  DAGScheduler - Submitting 4 missing tasks from ResultStage 43 (ParallelCollectionRDD[154] at parallelize at ReadsSparkSourceUnitTest.java:310) (first 15 tasks are for partitions Vector(0, 1, 2, 3))
22:03:44.052 INFO  TaskSchedulerImpl - Adding task set 43.0 with 4 tasks resource profile 0
22:03:44.053 INFO  TaskSetManager - Starting task 0.0 in stage 43.0 (TID 102) (localhost, executor driver, partition 0, PROCESS_LOCAL, 47080 bytes) 
22:03:44.053 INFO  TaskSetManager - Starting task 1.0 in stage 43.0 (TID 103) (localhost, executor driver, partition 1, PROCESS_LOCAL, 47194 bytes) 
22:03:44.054 INFO  TaskSetManager - Starting task 2.0 in stage 43.0 (TID 104) (localhost, executor driver, partition 2, PROCESS_LOCAL, 47105 bytes) 
22:03:44.054 INFO  TaskSetManager - Starting task 3.0 in stage 43.0 (TID 105) (localhost, executor driver, partition 3, PROCESS_LOCAL, 47530 bytes) 
22:03:44.055 INFO  Executor - Running task 2.0 in stage 43.0 (TID 104)
22:03:44.055 INFO  Executor - Running task 0.0 in stage 43.0 (TID 102)
22:03:44.056 INFO  Executor - Running task 3.0 in stage 43.0 (TID 105)
22:03:44.057 INFO  Executor - Running task 1.0 in stage 43.0 (TID 103)
22:03:44.058 INFO  Executor - Finished task 3.0 in stage 43.0 (TID 105). 40762 bytes result sent to driver
22:03:44.059 INFO  Executor - Finished task 1.0 in stage 43.0 (TID 103). 40426 bytes result sent to driver
22:03:44.060 INFO  Executor - Finished task 0.0 in stage 43.0 (TID 102). 40355 bytes result sent to driver
22:03:44.060 INFO  Executor - Finished task 2.0 in stage 43.0 (TID 104). 40380 bytes result sent to driver
22:03:44.061 INFO  TaskSetManager - Finished task 3.0 in stage 43.0 (TID 105) in 7 ms on localhost (executor driver) (1/4)
22:03:44.062 INFO  TaskSetManager - Finished task 1.0 in stage 43.0 (TID 103) in 9 ms on localhost (executor driver) (2/4)
22:03:44.062 INFO  TaskSetManager - Finished task 0.0 in stage 43.0 (TID 102) in 9 ms on localhost (executor driver) (3/4)
22:03:44.063 INFO  TaskSetManager - Finished task 2.0 in stage 43.0 (TID 104) in 9 ms on localhost (executor driver) (4/4)
22:03:44.063 INFO  TaskSchedulerImpl - Removed TaskSet 43.0, whose tasks have all completed, from pool 
22:03:44.063 INFO  DAGScheduler - ResultStage 43 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.014 s
22:03:44.063 INFO  DAGScheduler - Job 34 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:44.063 INFO  TaskSchedulerImpl - Killing all running tasks in stage 43: Stage finished
22:03:44.064 INFO  DAGScheduler - Job 34 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.015506 s
22:03:44.065 INFO  FileInputFormat - Total input files to process : 1
22:03:44.104 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
22:03:44.105 INFO  DAGScheduler - Got job 35 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
22:03:44.105 INFO  DAGScheduler - Final stage: ResultStage 44 (collect at ReadsSparkSourceUnitTest.java:112)
22:03:44.105 INFO  DAGScheduler - Parents of final stage: List()
22:03:44.105 INFO  DAGScheduler - Missing parents: List()
22:03:44.106 INFO  DAGScheduler - Submitting ResultStage 44 (MapPartitionsRDD[161] at filter at ReadsSparkSource.java:96), which has no missing parents
22:03:44.125 INFO  MemoryStore - Block broadcast_71 stored as values in memory (estimated size 425.0 KiB, free 1918.2 MiB)
22:03:44.127 INFO  MemoryStore - Block broadcast_71_piece0 stored as bytes in memory (estimated size 152.7 KiB, free 1918.0 MiB)
22:03:44.127 INFO  BlockManagerInfo - Added broadcast_71_piece0 in memory on localhost:41281 (size: 152.7 KiB, free: 1919.6 MiB)
22:03:44.127 INFO  SparkContext - Created broadcast 71 from broadcast at DAGScheduler.scala:1580
22:03:44.128 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 44 (MapPartitionsRDD[161] at filter at ReadsSparkSource.java:96) (first 15 tasks are for partitions Vector(0))
22:03:44.128 INFO  TaskSchedulerImpl - Adding task set 44.0 with 1 tasks resource profile 0
22:03:44.129 INFO  TaskSetManager - Starting task 0.0 in stage 44.0 (TID 106) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7831 bytes) 
22:03:44.129 INFO  Executor - Running task 0.0 in stage 44.0 (TID 106)
22:03:44.165 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam:0+57538
22:03:44.173 INFO  Executor - Finished task 0.0 in stage 44.0 (TID 106). 159572 bytes result sent to driver
22:03:44.175 INFO  TaskSetManager - Finished task 0.0 in stage 44.0 (TID 106) in 47 ms on localhost (executor driver) (1/1)
22:03:44.175 INFO  TaskSchedulerImpl - Removed TaskSet 44.0, whose tasks have all completed, from pool 
22:03:44.175 INFO  DAGScheduler - ResultStage 44 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.069 s
22:03:44.175 INFO  DAGScheduler - Job 35 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:44.175 INFO  TaskSchedulerImpl - Killing all running tasks in stage 44: Stage finished
22:03:44.176 INFO  DAGScheduler - Job 35 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.071610 s
22:03:44.181 INFO  MemoryStore - Block broadcast_72 stored as values in memory (estimated size 528.0 B, free 1918.0 MiB)
22:03:44.182 INFO  MemoryStore - Block broadcast_72_piece0 stored as bytes in memory (estimated size 183.0 B, free 1918.0 MiB)
22:03:44.182 INFO  BlockManagerInfo - Added broadcast_72_piece0 in memory on localhost:41281 (size: 183.0 B, free: 1919.6 MiB)
22:03:44.182 INFO  SparkContext - Created broadcast 72 from broadcast at CramSource.java:114
22:03:44.184 INFO  MemoryStore - Block broadcast_73 stored as values in memory (estimated size 297.2 KiB, free 1917.7 MiB)
22:03:44.191 INFO  MemoryStore - Block broadcast_73_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1917.7 MiB)
22:03:44.191 INFO  BlockManagerInfo - Added broadcast_73_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1919.6 MiB)
22:03:44.192 INFO  SparkContext - Created broadcast 73 from newAPIHadoopFile at PathSplitSource.java:96
22:03:44.218 INFO  MemoryStore - Block broadcast_74 stored as values in memory (estimated size 528.0 B, free 1917.7 MiB)
22:03:44.219 INFO  MemoryStore - Block broadcast_74_piece0 stored as bytes in memory (estimated size 183.0 B, free 1917.7 MiB)
22:03:44.219 INFO  BlockManagerInfo - Added broadcast_74_piece0 in memory on localhost:41281 (size: 183.0 B, free: 1919.6 MiB)
22:03:44.220 INFO  SparkContext - Created broadcast 74 from broadcast at CramSource.java:114
22:03:44.222 INFO  MemoryStore - Block broadcast_75 stored as values in memory (estimated size 297.2 KiB, free 1917.4 MiB)
22:03:44.229 INFO  MemoryStore - Block broadcast_75_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1917.4 MiB)
22:03:44.229 INFO  BlockManagerInfo - Added broadcast_75_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1919.5 MiB)
22:03:44.229 INFO  SparkContext - Created broadcast 75 from newAPIHadoopFile at PathSplitSource.java:96
22:03:44.249 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
22:03:44.249 INFO  DAGScheduler - Got job 36 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
22:03:44.249 INFO  DAGScheduler - Final stage: ResultStage 45 (collect at ReadsSparkSourceUnitTest.java:111)
22:03:44.249 INFO  DAGScheduler - Parents of final stage: List()
22:03:44.249 INFO  DAGScheduler - Missing parents: List()
22:03:44.249 INFO  DAGScheduler - Submitting ResultStage 45 (ParallelCollectionRDD[166] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
22:03:44.250 INFO  MemoryStore - Block broadcast_76 stored as values in memory (estimated size 3.0 KiB, free 1917.4 MiB)
22:03:44.251 INFO  MemoryStore - Block broadcast_76_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1917.3 MiB)
22:03:44.251 INFO  BlockManagerInfo - Added broadcast_76_piece0 in memory on localhost:41281 (size: 1780.0 B, free: 1919.5 MiB)
22:03:44.252 INFO  SparkContext - Created broadcast 76 from broadcast at DAGScheduler.scala:1580
22:03:44.252 INFO  DAGScheduler - Submitting 4 missing tasks from ResultStage 45 (ParallelCollectionRDD[166] at parallelize at ReadsSparkSourceUnitTest.java:310) (first 15 tasks are for partitions Vector(0, 1, 2, 3))
22:03:44.252 INFO  TaskSchedulerImpl - Adding task set 45.0 with 4 tasks resource profile 0
22:03:44.253 INFO  TaskSetManager - Starting task 0.0 in stage 45.0 (TID 107) (localhost, executor driver, partition 0, PROCESS_LOCAL, 45675 bytes) 
22:03:44.254 INFO  TaskSetManager - Starting task 1.0 in stage 45.0 (TID 108) (localhost, executor driver, partition 1, PROCESS_LOCAL, 45855 bytes) 
22:03:44.256 INFO  TaskSetManager - Starting task 2.0 in stage 45.0 (TID 109) (localhost, executor driver, partition 2, PROCESS_LOCAL, 45795 bytes) 
22:03:44.257 INFO  TaskSetManager - Starting task 3.0 in stage 45.0 (TID 110) (localhost, executor driver, partition 3, PROCESS_LOCAL, 46068 bytes) 
22:03:44.257 INFO  Executor - Running task 3.0 in stage 45.0 (TID 110)
22:03:44.257 INFO  Executor - Running task 0.0 in stage 45.0 (TID 107)
22:03:44.257 INFO  Executor - Running task 2.0 in stage 45.0 (TID 109)
22:03:44.258 INFO  Executor - Running task 1.0 in stage 45.0 (TID 108)
22:03:44.261 INFO  Executor - Finished task 1.0 in stage 45.0 (TID 108). 39130 bytes result sent to driver
22:03:44.262 INFO  TaskSetManager - Finished task 1.0 in stage 45.0 (TID 108) in 8 ms on localhost (executor driver) (1/4)
22:03:44.263 INFO  Executor - Finished task 0.0 in stage 45.0 (TID 107). 38993 bytes result sent to driver
22:03:44.263 INFO  TaskSetManager - Finished task 0.0 in stage 45.0 (TID 107) in 10 ms on localhost (executor driver) (2/4)
22:03:44.264 INFO  Executor - Finished task 2.0 in stage 45.0 (TID 109). 39113 bytes result sent to driver
22:03:44.265 INFO  TaskSetManager - Finished task 2.0 in stage 45.0 (TID 109) in 10 ms on localhost (executor driver) (3/4)
22:03:44.265 INFO  Executor - Finished task 3.0 in stage 45.0 (TID 110). 39343 bytes result sent to driver
22:03:44.266 INFO  TaskSetManager - Finished task 3.0 in stage 45.0 (TID 110) in 10 ms on localhost (executor driver) (4/4)
22:03:44.267 INFO  TaskSchedulerImpl - Removed TaskSet 45.0, whose tasks have all completed, from pool 
22:03:44.267 INFO  DAGScheduler - ResultStage 45 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.017 s
22:03:44.267 INFO  DAGScheduler - Job 36 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:44.267 INFO  TaskSchedulerImpl - Killing all running tasks in stage 45: Stage finished
22:03:44.267 INFO  DAGScheduler - Job 36 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.018591 s
22:03:44.269 INFO  FileInputFormat - Total input files to process : 1
22:03:44.295 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
22:03:44.295 INFO  DAGScheduler - Got job 37 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
22:03:44.295 INFO  DAGScheduler - Final stage: ResultStage 46 (collect at ReadsSparkSourceUnitTest.java:112)
22:03:44.295 INFO  DAGScheduler - Parents of final stage: List()
22:03:44.296 INFO  DAGScheduler - Missing parents: List()
22:03:44.296 INFO  DAGScheduler - Submitting ResultStage 46 (MapPartitionsRDD[172] at filter at ReadsSparkSource.java:96), which has no missing parents
22:03:44.309 INFO  MemoryStore - Block broadcast_77 stored as values in memory (estimated size 286.0 KiB, free 1917.1 MiB)
22:03:44.310 INFO  MemoryStore - Block broadcast_77_piece0 stored as bytes in memory (estimated size 103.1 KiB, free 1917.0 MiB)
22:03:44.311 INFO  BlockManagerInfo - Added broadcast_77_piece0 in memory on localhost:41281 (size: 103.1 KiB, free: 1919.4 MiB)
22:03:44.311 INFO  SparkContext - Created broadcast 77 from broadcast at DAGScheduler.scala:1580
22:03:44.311 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 46 (MapPartitionsRDD[172] at filter at ReadsSparkSource.java:96) (first 15 tasks are for partitions Vector(0))
22:03:44.311 INFO  TaskSchedulerImpl - Adding task set 46.0 with 1 tasks resource profile 0
22:03:44.312 INFO  TaskSetManager - Starting task 0.0 in stage 46.0 (TID 111) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7832 bytes) 
22:03:44.313 INFO  Executor - Running task 0.0 in stage 46.0 (TID 111)
22:03:44.338 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram:0+50619
22:03:44.350 INFO  Executor - Finished task 0.0 in stage 46.0 (TID 111). 154101 bytes result sent to driver
22:03:44.352 INFO  TaskSetManager - Finished task 0.0 in stage 46.0 (TID 111) in 40 ms on localhost (executor driver) (1/1)
22:03:44.352 INFO  TaskSchedulerImpl - Removed TaskSet 46.0, whose tasks have all completed, from pool 
22:03:44.352 INFO  DAGScheduler - ResultStage 46 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.055 s
22:03:44.352 INFO  DAGScheduler - Job 37 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:44.352 INFO  TaskSchedulerImpl - Killing all running tasks in stage 46: Stage finished
22:03:44.353 INFO  DAGScheduler - Job 37 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.057713 s
22:03:44.358 INFO  MemoryStore - Block broadcast_78 stored as values in memory (estimated size 297.2 KiB, free 1916.7 MiB)
22:03:44.364 INFO  MemoryStore - Block broadcast_78_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1916.6 MiB)
22:03:44.365 INFO  BlockManagerInfo - Added broadcast_78_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1919.4 MiB)
22:03:44.365 INFO  SparkContext - Created broadcast 78 from newAPIHadoopFile at PathSplitSource.java:96
22:03:44.391 INFO  MemoryStore - Block broadcast_79 stored as values in memory (estimated size 528.0 B, free 1916.6 MiB)
22:03:44.392 INFO  MemoryStore - Block broadcast_79_piece0 stored as bytes in memory (estimated size 183.0 B, free 1916.6 MiB)
22:03:44.392 INFO  BlockManagerInfo - Added broadcast_79_piece0 in memory on localhost:41281 (size: 183.0 B, free: 1919.4 MiB)
22:03:44.393 INFO  SparkContext - Created broadcast 79 from broadcast at CramSource.java:114
22:03:44.396 INFO  MemoryStore - Block broadcast_80 stored as values in memory (estimated size 297.2 KiB, free 1916.3 MiB)
22:03:44.407 INFO  MemoryStore - Block broadcast_80_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1916.3 MiB)
22:03:44.407 INFO  BlockManagerInfo - Added broadcast_80_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1919.3 MiB)
22:03:44.408 INFO  SparkContext - Created broadcast 80 from newAPIHadoopFile at PathSplitSource.java:96
22:03:44.460 WARN  FileSystem - Failed to initialize filesystem hdfs://bogus/path.bam: java.lang.IllegalArgumentException: java.net.UnknownHostException: bogus
22:03:44.468 INFO  MemoryStore - Block broadcast_81 stored as values in memory (estimated size 297.3 KiB, free 1916.0 MiB)
22:03:44.479 INFO  MemoryStore - Block broadcast_81_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1916.0 MiB)
22:03:44.479 INFO  BlockManagerInfo - Added broadcast_81_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1919.3 MiB)
22:03:44.480 INFO  SparkContext - Created broadcast 81 from newAPIHadoopFile at PathSplitSource.java:96
22:03:44.530 INFO  MemoryStore - Block broadcast_82 stored as values in memory (estimated size 297.3 KiB, free 1915.7 MiB)
22:03:44.541 INFO  MemoryStore - Block broadcast_82_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1915.6 MiB)
22:03:44.541 INFO  BlockManagerInfo - Added broadcast_82_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1919.2 MiB)
22:03:44.542 INFO  SparkContext - Created broadcast 82 from newAPIHadoopFile at PathSplitSource.java:96
22:03:44.572 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:154
22:03:44.573 INFO  DAGScheduler - Got job 38 (collect at ReadsSparkSourceUnitTest.java:154) with 4 output partitions
22:03:44.573 INFO  DAGScheduler - Final stage: ResultStage 47 (collect at ReadsSparkSourceUnitTest.java:154)
22:03:44.573 INFO  DAGScheduler - Parents of final stage: List()
22:03:44.573 INFO  DAGScheduler - Missing parents: List()
22:03:44.573 INFO  DAGScheduler - Submitting ResultStage 47 (ParallelCollectionRDD[187] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
22:03:44.574 INFO  MemoryStore - Block broadcast_83 stored as values in memory (estimated size 3.0 KiB, free 1915.6 MiB)
22:03:44.575 INFO  MemoryStore - Block broadcast_83_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1915.6 MiB)
22:03:44.575 INFO  BlockManagerInfo - Added broadcast_83_piece0 in memory on localhost:41281 (size: 1780.0 B, free: 1919.2 MiB)
22:03:44.576 INFO  SparkContext - Created broadcast 83 from broadcast at DAGScheduler.scala:1580
22:03:44.576 INFO  DAGScheduler - Submitting 4 missing tasks from ResultStage 47 (ParallelCollectionRDD[187] at parallelize at ReadsSparkSourceUnitTest.java:310) (first 15 tasks are for partitions Vector(0, 1, 2, 3))
22:03:44.576 INFO  TaskSchedulerImpl - Adding task set 47.0 with 4 tasks resource profile 0
22:03:44.577 INFO  TaskSetManager - Starting task 0.0 in stage 47.0 (TID 112) (localhost, executor driver, partition 0, PROCESS_LOCAL, 169886 bytes) 
22:03:44.578 INFO  TaskSetManager - Starting task 1.0 in stage 47.0 (TID 113) (localhost, executor driver, partition 1, PROCESS_LOCAL, 170093 bytes) 
22:03:44.578 INFO  TaskSetManager - Starting task 2.0 in stage 47.0 (TID 114) (localhost, executor driver, partition 2, PROCESS_LOCAL, 170081 bytes) 
22:03:44.579 INFO  TaskSetManager - Starting task 3.0 in stage 47.0 (TID 115) (localhost, executor driver, partition 3, PROCESS_LOCAL, 169419 bytes) 
22:03:44.579 INFO  Executor - Running task 1.0 in stage 47.0 (TID 113)
22:03:44.579 INFO  Executor - Running task 3.0 in stage 47.0 (TID 115)
22:03:44.581 INFO  Executor - Running task 2.0 in stage 47.0 (TID 114)
22:03:44.582 INFO  Executor - Running task 0.0 in stage 47.0 (TID 112)
22:03:44.582 INFO  Executor - Finished task 3.0 in stage 47.0 (TID 115). 162694 bytes result sent to driver
22:03:44.584 INFO  Executor - Finished task 1.0 in stage 47.0 (TID 113). 163368 bytes result sent to driver
22:03:44.585 INFO  Executor - Finished task 0.0 in stage 47.0 (TID 112). 163161 bytes result sent to driver
22:03:44.585 INFO  TaskSetManager - Finished task 3.0 in stage 47.0 (TID 115) in 7 ms on localhost (executor driver) (1/4)
22:03:44.585 INFO  Executor - Finished task 2.0 in stage 47.0 (TID 114). 163399 bytes result sent to driver
22:03:44.586 INFO  TaskSetManager - Finished task 1.0 in stage 47.0 (TID 113) in 9 ms on localhost (executor driver) (2/4)
22:03:44.586 INFO  TaskSetManager - Finished task 2.0 in stage 47.0 (TID 114) in 8 ms on localhost (executor driver) (3/4)
22:03:44.587 INFO  TaskSetManager - Finished task 0.0 in stage 47.0 (TID 112) in 10 ms on localhost (executor driver) (4/4)
22:03:44.587 INFO  TaskSchedulerImpl - Removed TaskSet 47.0, whose tasks have all completed, from pool 
22:03:44.587 INFO  DAGScheduler - ResultStage 47 (collect at ReadsSparkSourceUnitTest.java:154) finished in 0.014 s
22:03:44.587 INFO  DAGScheduler - Job 38 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:44.587 INFO  TaskSchedulerImpl - Killing all running tasks in stage 47: Stage finished
22:03:44.587 INFO  DAGScheduler - Job 38 finished: collect at ReadsSparkSourceUnitTest.java:154, took 0.014636 s
22:03:44.596 INFO  FileInputFormat - Total input files to process : 2
22:03:44.641 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:155
22:03:44.641 INFO  DAGScheduler - Got job 39 (collect at ReadsSparkSourceUnitTest.java:155) with 2 output partitions
22:03:44.641 INFO  DAGScheduler - Final stage: ResultStage 48 (collect at ReadsSparkSourceUnitTest.java:155)
22:03:44.641 INFO  DAGScheduler - Parents of final stage: List()
22:03:44.641 INFO  DAGScheduler - Missing parents: List()
22:03:44.642 INFO  DAGScheduler - Submitting ResultStage 48 (MapPartitionsRDD[194] at filter at ReadsSparkSource.java:96), which has no missing parents
22:03:44.659 INFO  MemoryStore - Block broadcast_84 stored as values in memory (estimated size 425.0 KiB, free 1915.2 MiB)
22:03:44.661 INFO  MemoryStore - Block broadcast_84_piece0 stored as bytes in memory (estimated size 152.7 KiB, free 1915.0 MiB)
22:03:44.661 INFO  BlockManagerInfo - Added broadcast_84_piece0 in memory on localhost:41281 (size: 152.7 KiB, free: 1919.1 MiB)
22:03:44.661 INFO  SparkContext - Created broadcast 84 from broadcast at DAGScheduler.scala:1580
22:03:44.662 INFO  DAGScheduler - Submitting 2 missing tasks from ResultStage 48 (MapPartitionsRDD[194] at filter at ReadsSparkSource.java:96) (first 15 tasks are for partitions Vector(0, 1))
22:03:44.662 INFO  TaskSchedulerImpl - Adding task set 48.0 with 2 tasks resource profile 0
22:03:44.663 INFO  TaskSetManager - Starting task 0.0 in stage 48.0 (TID 116) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7921 bytes) 
22:03:44.663 INFO  TaskSetManager - Starting task 1.0 in stage 48.0 (TID 117) (localhost, executor driver, partition 1, PROCESS_LOCAL, 7921 bytes) 
22:03:44.663 INFO  Executor - Running task 0.0 in stage 48.0 (TID 116)
22:03:44.663 INFO  Executor - Running task 1.0 in stage 48.0 (TID 117)
22:03:44.700 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/HiSeq.1mb.1RG.2k_lines.alternate.recalibrated.DIQ.sharded.bam/part-r-00000.bam:0+131967
22:03:44.710 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/HiSeq.1mb.1RG.2k_lines.alternate.recalibrated.DIQ.sharded.bam/part-r-00001.bam:0+131967
22:03:44.716 INFO  Executor - Finished task 1.0 in stage 48.0 (TID 117). 325633 bytes result sent to driver
22:03:44.718 INFO  TaskSetManager - Finished task 1.0 in stage 48.0 (TID 117) in 55 ms on localhost (executor driver) (1/2)
22:03:44.729 INFO  Executor - Finished task 0.0 in stage 48.0 (TID 116). 325590 bytes result sent to driver
22:03:44.731 INFO  TaskSetManager - Finished task 0.0 in stage 48.0 (TID 116) in 69 ms on localhost (executor driver) (2/2)
22:03:44.731 INFO  TaskSchedulerImpl - Removed TaskSet 48.0, whose tasks have all completed, from pool 
22:03:44.731 INFO  DAGScheduler - ResultStage 48 (collect at ReadsSparkSourceUnitTest.java:155) finished in 0.089 s
22:03:44.731 INFO  DAGScheduler - Job 39 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:44.731 INFO  TaskSchedulerImpl - Killing all running tasks in stage 48: Stage finished
22:03:44.731 INFO  DAGScheduler - Job 39 finished: collect at ReadsSparkSourceUnitTest.java:155, took 0.090674 s
22:03:44.737 INFO  MemoryStore - Block broadcast_85 stored as values in memory (estimated size 297.2 KiB, free 1914.8 MiB)
22:03:44.743 INFO  MemoryStore - Block broadcast_85_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1914.7 MiB)
22:03:44.744 INFO  BlockManagerInfo - Added broadcast_85_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1919.0 MiB)
22:03:44.744 INFO  SparkContext - Created broadcast 85 from newAPIHadoopFile at PathSplitSource.java:96
22:03:44.769 INFO  MemoryStore - Block broadcast_86 stored as values in memory (estimated size 297.3 KiB, free 1914.4 MiB)
22:03:44.776 INFO  MemoryStore - Block broadcast_86_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1914.4 MiB)
22:03:44.776 INFO  BlockManagerInfo - Added broadcast_86_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1919.0 MiB)
22:03:44.776 INFO  SparkContext - Created broadcast 86 from newAPIHadoopFile at PathSplitSource.java:96
22:03:44.801 INFO  MemoryStore - Block broadcast_87 stored as values in memory (estimated size 297.3 KiB, free 1914.1 MiB)
22:03:44.808 INFO  MemoryStore - Block broadcast_87_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1914.0 MiB)
22:03:44.808 INFO  BlockManagerInfo - Added broadcast_87_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1918.9 MiB)
22:03:44.808 INFO  SparkContext - Created broadcast 87 from newAPIHadoopFile at PathSplitSource.java:96
22:03:44.832 INFO  MemoryStore - Block broadcast_88 stored as values in memory (estimated size 528.0 B, free 1914.0 MiB)
22:03:44.833 INFO  MemoryStore - Block broadcast_88_piece0 stored as bytes in memory (estimated size 183.0 B, free 1914.0 MiB)
22:03:44.833 INFO  BlockManagerInfo - Added broadcast_88_piece0 in memory on localhost:41281 (size: 183.0 B, free: 1918.9 MiB)
22:03:44.834 INFO  SparkContext - Created broadcast 88 from broadcast at CramSource.java:114
22:03:44.836 INFO  MemoryStore - Block broadcast_89 stored as values in memory (estimated size 297.2 KiB, free 1913.7 MiB)
22:03:44.842 INFO  MemoryStore - Block broadcast_89_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1913.7 MiB)
22:03:44.843 INFO  BlockManagerInfo - Added broadcast_89_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1918.9 MiB)
22:03:44.843 INFO  SparkContext - Created broadcast 89 from newAPIHadoopFile at PathSplitSource.java:96
22:03:44.860 INFO  MemoryStore - Block broadcast_90 stored as values in memory (estimated size 600.0 B, free 1913.7 MiB)
22:03:44.861 INFO  MemoryStore - Block broadcast_90_piece0 stored as bytes in memory (estimated size 202.0 B, free 1913.7 MiB)
22:03:44.861 INFO  BlockManagerInfo - Added broadcast_90_piece0 in memory on localhost:41281 (size: 202.0 B, free: 1918.9 MiB)
22:03:44.861 INFO  SparkContext - Created broadcast 90 from broadcast at CramSource.java:114
22:03:44.863 INFO  MemoryStore - Block broadcast_91 stored as values in memory (estimated size 297.3 KiB, free 1913.4 MiB)
22:03:44.869 INFO  MemoryStore - Block broadcast_91_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1913.3 MiB)
22:03:44.869 INFO  BlockManagerInfo - Added broadcast_91_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1918.8 MiB)
22:03:44.869 INFO  SparkContext - Created broadcast 91 from newAPIHadoopFile at PathSplitSource.java:96
22:03:44.888 INFO  MemoryStore - Block broadcast_92 stored as values in memory (estimated size 297.3 KiB, free 1913.1 MiB)
22:03:44.895 INFO  MemoryStore - Block broadcast_92_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1913.0 MiB)
22:03:44.895 INFO  BlockManagerInfo - Added broadcast_92_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1918.8 MiB)
22:03:44.896 INFO  SparkContext - Created broadcast 92 from newAPIHadoopFile at PathSplitSource.java:96
22:03:44.920 INFO  FileInputFormat - Total input files to process : 1
22:03:44.943 INFO  BlockManagerInfo - Removed broadcast_65_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1918.8 MiB)
22:03:44.944 INFO  BlockManagerInfo - Removed broadcast_69_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1918.9 MiB)
22:03:44.945 INFO  BlockManagerInfo - Removed broadcast_79_piece0 on localhost:41281 in memory (size: 183.0 B, free: 1918.9 MiB)
22:03:44.946 INFO  BlockManagerInfo - Removed broadcast_80_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1918.9 MiB)
22:03:44.947 INFO  BlockManagerInfo - Removed broadcast_75_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1919.0 MiB)
22:03:44.947 INFO  BlockManagerInfo - Removed broadcast_77_piece0 on localhost:41281 in memory (size: 103.1 KiB, free: 1919.1 MiB)
22:03:44.948 INFO  BlockManagerInfo - Removed broadcast_90_piece0 on localhost:41281 in memory (size: 202.0 B, free: 1919.1 MiB)
22:03:44.949 INFO  BlockManagerInfo - Removed broadcast_84_piece0 on localhost:41281 in memory (size: 152.7 KiB, free: 1919.2 MiB)
22:03:44.949 INFO  BlockManagerInfo - Removed broadcast_72_piece0 on localhost:41281 in memory (size: 183.0 B, free: 1919.2 MiB)
22:03:44.950 INFO  BlockManagerInfo - Removed broadcast_85_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1919.3 MiB)
22:03:44.951 INFO  BlockManagerInfo - Removed broadcast_76_piece0 on localhost:41281 in memory (size: 1780.0 B, free: 1919.3 MiB)
22:03:44.951 INFO  BlockManagerInfo - Removed broadcast_82_piece0 on localhost:41281 in memory (size: 50.1 KiB, free: 1919.3 MiB)
22:03:44.952 INFO  BlockManagerInfo - Removed broadcast_73_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1919.4 MiB)
22:03:44.953 INFO  BlockManagerInfo - Removed broadcast_91_piece0 on localhost:41281 in memory (size: 50.1 KiB, free: 1919.4 MiB)
22:03:44.954 INFO  BlockManagerInfo - Removed broadcast_64_piece0 on localhost:41281 in memory (size: 183.0 B, free: 1919.4 MiB)
22:03:44.955 INFO  BlockManagerInfo - Removed broadcast_81_piece0 on localhost:41281 in memory (size: 50.1 KiB, free: 1919.5 MiB)
22:03:44.956 INFO  BlockManagerInfo - Removed broadcast_67_piece0 on localhost:41281 in memory (size: 103.1 KiB, free: 1919.6 MiB)
22:03:44.957 INFO  BlockManagerInfo - Removed broadcast_70_piece0 on localhost:41281 in memory (size: 1780.0 B, free: 1919.6 MiB)
22:03:44.958 INFO  BlockManagerInfo - Removed broadcast_86_piece0 on localhost:41281 in memory (size: 50.1 KiB, free: 1919.6 MiB)
22:03:44.959 INFO  BlockManagerInfo - Removed broadcast_74_piece0 on localhost:41281 in memory (size: 183.0 B, free: 1919.6 MiB)
22:03:44.959 INFO  BlockManagerInfo - Removed broadcast_88_piece0 on localhost:41281 in memory (size: 183.0 B, free: 1919.6 MiB)
22:03:44.960 INFO  BlockManagerInfo - Removed broadcast_89_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1919.7 MiB)
22:03:44.961 INFO  BlockManagerInfo - Removed broadcast_68_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1919.7 MiB)
22:03:44.962 INFO  BlockManagerInfo - Removed broadcast_87_piece0 on localhost:41281 in memory (size: 50.1 KiB, free: 1919.8 MiB)
22:03:44.963 INFO  BlockManagerInfo - Removed broadcast_78_piece0 on localhost:41281 in memory (size: 50.0 KiB, free: 1919.8 MiB)
22:03:44.963 INFO  BlockManagerInfo - Removed broadcast_71_piece0 on localhost:41281 in memory (size: 152.7 KiB, free: 1919.9 MiB)
22:03:44.964 INFO  BlockManagerInfo - Removed broadcast_83_piece0 on localhost:41281 in memory (size: 1780.0 B, free: 1920.0 MiB)
22:03:44.984 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:163
22:03:44.984 INFO  DAGScheduler - Got job 40 (collect at ReadsSparkSourceUnitTest.java:163) with 1 output partitions
22:03:44.984 INFO  DAGScheduler - Final stage: ResultStage 49 (collect at ReadsSparkSourceUnitTest.java:163)
22:03:44.984 INFO  DAGScheduler - Parents of final stage: List()
22:03:44.984 INFO  DAGScheduler - Missing parents: List()
22:03:44.985 INFO  DAGScheduler - Submitting ResultStage 49 (MapPartitionsRDD[224] at filter at ReadsSparkSource.java:96), which has no missing parents
22:03:45.008 INFO  MemoryStore - Block broadcast_93 stored as values in memory (estimated size 425.0 KiB, free 1919.2 MiB)
22:03:45.009 INFO  MemoryStore - Block broadcast_93_piece0 stored as bytes in memory (estimated size 152.7 KiB, free 1919.1 MiB)
22:03:45.009 INFO  BlockManagerInfo - Added broadcast_93_piece0 in memory on localhost:41281 (size: 152.7 KiB, free: 1919.8 MiB)
22:03:45.009 INFO  SparkContext - Created broadcast 93 from broadcast at DAGScheduler.scala:1580
22:03:45.010 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 49 (MapPartitionsRDD[224] at filter at ReadsSparkSource.java:96) (first 15 tasks are for partitions Vector(0))
22:03:45.010 INFO  TaskSchedulerImpl - Adding task set 49.0 with 1 tasks resource profile 0
22:03:45.011 INFO  TaskSetManager - Starting task 0.0 in stage 49.0 (TID 118) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7875 bytes) 
22:03:45.011 INFO  Executor - Running task 0.0 in stage 49.0 (TID 118)
22:03:45.044 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/HiSeq.1mb.1RG.2k_lines.alternate.bam:0+221635
22:03:45.059 INFO  Executor - Finished task 0.0 in stage 49.0 (TID 118). 650184 bytes result sent to driver
22:03:45.062 INFO  TaskSetManager - Finished task 0.0 in stage 49.0 (TID 118) in 52 ms on localhost (executor driver) (1/1)
22:03:45.062 INFO  TaskSchedulerImpl - Removed TaskSet 49.0, whose tasks have all completed, from pool 
22:03:45.062 INFO  DAGScheduler - ResultStage 49 (collect at ReadsSparkSourceUnitTest.java:163) finished in 0.077 s
22:03:45.062 INFO  DAGScheduler - Job 40 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:45.062 INFO  TaskSchedulerImpl - Killing all running tasks in stage 49: Stage finished
22:03:45.063 INFO  DAGScheduler - Job 40 finished: collect at ReadsSparkSourceUnitTest.java:163, took 0.078794 s
22:03:45.067 INFO  MemoryStore - Block broadcast_94 stored as values in memory (estimated size 208.0 B, free 1919.1 MiB)
22:03:45.069 INFO  MemoryStore - Block broadcast_94_piece0 stored as bytes in memory (estimated size 239.0 B, free 1919.1 MiB)
22:03:45.069 INFO  BlockManagerInfo - Added broadcast_94_piece0 in memory on localhost:41281 (size: 239.0 B, free: 1919.8 MiB)
22:03:45.069 INFO  SparkContext - Created broadcast 94 from broadcast at AbstractBinarySamSource.java:82
22:03:45.072 INFO  MemoryStore - Block broadcast_95 stored as values in memory (estimated size 297.2 KiB, free 1918.8 MiB)
22:03:45.078 INFO  MemoryStore - Block broadcast_95_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1918.8 MiB)
22:03:45.078 INFO  BlockManagerInfo - Added broadcast_95_piece0 in memory on localhost:41281 (size: 50.0 KiB, free: 1919.8 MiB)
22:03:45.079 INFO  SparkContext - Created broadcast 95 from newAPIHadoopFile at PathSplitSource.java:96
22:03:45.107 INFO  FileInputFormat - Total input files to process : 1
22:03:45.110 INFO  SparkContext - Starting job: count at ReadsSparkSourceUnitTest.java:265
22:03:45.111 INFO  DAGScheduler - Got job 41 (count at ReadsSparkSourceUnitTest.java:265) with 1 output partitions
22:03:45.111 INFO  DAGScheduler - Final stage: ResultStage 50 (count at ReadsSparkSourceUnitTest.java:265)
22:03:45.111 INFO  DAGScheduler - Parents of final stage: List()
22:03:45.111 INFO  DAGScheduler - Missing parents: List()
22:03:45.111 INFO  DAGScheduler - Submitting ResultStage 50 (MapPartitionsRDD[231] at filter at ReadsSparkSource.java:96), which has no missing parents
22:03:45.136 INFO  MemoryStore - Block broadcast_96 stored as values in memory (estimated size 424.9 KiB, free 1918.3 MiB)
22:03:45.137 INFO  MemoryStore - Block broadcast_96_piece0 stored as bytes in memory (estimated size 152.8 KiB, free 1918.2 MiB)
22:03:45.138 INFO  BlockManagerInfo - Added broadcast_96_piece0 in memory on localhost:41281 (size: 152.8 KiB, free: 1919.6 MiB)
22:03:45.138 INFO  SparkContext - Created broadcast 96 from broadcast at DAGScheduler.scala:1580
22:03:45.138 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 50 (MapPartitionsRDD[231] at filter at ReadsSparkSource.java:96) (first 15 tasks are for partitions Vector(0))
22:03:45.138 INFO  TaskSchedulerImpl - Adding task set 50.0 with 1 tasks resource profile 0
22:03:45.139 INFO  TaskSetManager - Starting task 0.0 in stage 50.0 (TID 119) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7831 bytes) 
22:03:45.139 INFO  Executor - Running task 0.0 in stage 50.0 (TID 119)
22:03:45.174 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam:0+57538
22:03:45.180 INFO  Executor - Finished task 0.0 in stage 50.0 (TID 119). 989 bytes result sent to driver
22:03:45.180 INFO  TaskSetManager - Finished task 0.0 in stage 50.0 (TID 119) in 41 ms on localhost (executor driver) (1/1)
22:03:45.180 INFO  TaskSchedulerImpl - Removed TaskSet 50.0, whose tasks have all completed, from pool 
22:03:45.180 INFO  DAGScheduler - ResultStage 50 (count at ReadsSparkSourceUnitTest.java:265) finished in 0.068 s
22:03:45.181 INFO  DAGScheduler - Job 41 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:45.181 INFO  TaskSchedulerImpl - Killing all running tasks in stage 50: Stage finished
22:03:45.181 INFO  DAGScheduler - Job 41 finished: count at ReadsSparkSourceUnitTest.java:265, took 0.070452 s
22:03:45.184 INFO  MemoryStore - Block broadcast_97 stored as values in memory (estimated size 160.0 B, free 1918.2 MiB)
22:03:45.186 INFO  MemoryStore - Block broadcast_97_piece0 stored as bytes in memory (estimated size 229.0 B, free 1918.2 MiB)
22:03:45.186 INFO  BlockManagerInfo - Added broadcast_97_piece0 in memory on localhost:41281 (size: 229.0 B, free: 1919.6 MiB)
22:03:45.186 INFO  SparkContext - Created broadcast 97 from broadcast at AbstractBinarySamSource.java:82
22:03:45.188 INFO  MemoryStore - Block broadcast_98 stored as values in memory (estimated size 297.3 KiB, free 1917.9 MiB)
22:03:45.194 INFO  MemoryStore - Block broadcast_98_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1917.9 MiB)
22:03:45.194 INFO  BlockManagerInfo - Added broadcast_98_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1919.6 MiB)
22:03:45.195 INFO  SparkContext - Created broadcast 98 from newAPIHadoopFile at PathSplitSource.java:96
22:03:45.221 INFO  FileInputFormat - Total input files to process : 1
22:03:45.224 INFO  SparkContext - Starting job: count at ReadsSparkSourceUnitTest.java:286
22:03:45.224 INFO  DAGScheduler - Got job 42 (count at ReadsSparkSourceUnitTest.java:286) with 1 output partitions
22:03:45.224 INFO  DAGScheduler - Final stage: ResultStage 51 (count at ReadsSparkSourceUnitTest.java:286)
22:03:45.224 INFO  DAGScheduler - Parents of final stage: List()
22:03:45.224 INFO  DAGScheduler - Missing parents: List()
22:03:45.225 INFO  DAGScheduler - Submitting ResultStage 51 (MapPartitionsRDD[238] at filter at ReadsSparkSource.java:96), which has no missing parents
22:03:45.243 INFO  MemoryStore - Block broadcast_99 stored as values in memory (estimated size 424.9 KiB, free 1917.4 MiB)
22:03:45.245 INFO  MemoryStore - Block broadcast_99_piece0 stored as bytes in memory (estimated size 152.8 KiB, free 1917.3 MiB)
22:03:45.245 INFO  BlockManagerInfo - Added broadcast_99_piece0 in memory on localhost:41281 (size: 152.8 KiB, free: 1919.4 MiB)
22:03:45.246 INFO  SparkContext - Created broadcast 99 from broadcast at DAGScheduler.scala:1580
22:03:45.246 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 51 (MapPartitionsRDD[238] at filter at ReadsSparkSource.java:96) (first 15 tasks are for partitions Vector(0))
22:03:45.246 INFO  TaskSchedulerImpl - Adding task set 51.0 with 1 tasks resource profile 0
22:03:45.247 INFO  TaskSetManager - Starting task 0.0 in stage 51.0 (TID 120) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7891 bytes) 
22:03:45.247 INFO  Executor - Running task 0.0 in stage 51.0 (TID 120)
22:03:45.280 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/engine/CEUTrio.HiSeq.WGS.b37.NA12878.snippet_with_unmapped.bam:0+2184
22:03:45.287 INFO  Executor - Finished task 0.0 in stage 51.0 (TID 120). 989 bytes result sent to driver
22:03:45.287 INFO  TaskSetManager - Finished task 0.0 in stage 51.0 (TID 120) in 41 ms on localhost (executor driver) (1/1)
22:03:45.287 INFO  TaskSchedulerImpl - Removed TaskSet 51.0, whose tasks have all completed, from pool 
22:03:45.288 INFO  DAGScheduler - ResultStage 51 (count at ReadsSparkSourceUnitTest.java:286) finished in 0.062 s
22:03:45.288 INFO  DAGScheduler - Job 42 is finished. Cancelling potential speculative or zombie tasks for this job
22:03:45.288 INFO  TaskSchedulerImpl - Killing all running tasks in stage 51: Stage finished
22:03:45.288 INFO  DAGScheduler - Job 42 finished: count at ReadsSparkSourceUnitTest.java:286, took 0.063923 s
22:03:45.294 INFO  MemoryStore - Block broadcast_100 stored as values in memory (estimated size 297.3 KiB, free 1917.0 MiB)
22:03:45.305 INFO  MemoryStore - Block broadcast_100_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1916.9 MiB)
22:03:45.306 INFO  BlockManagerInfo - Added broadcast_100_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1919.4 MiB)
22:03:45.306 INFO  SparkContext - Created broadcast 100 from newAPIHadoopFile at PathSplitSource.java:96
22:03:45.347 INFO  MemoryStore - Block broadcast_101 stored as values in memory (estimated size 297.4 KiB, free 1916.7 MiB)
22:03:45.358 INFO  MemoryStore - Block broadcast_101_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1916.6 MiB)
22:03:45.359 INFO  BlockManagerInfo - Added broadcast_101_piece0 in memory on localhost:41281 (size: 50.1 KiB, free: 1919.3 MiB)
22:03:45.359 INFO  SparkContext - Created broadcast 101 from newAPIHadoopFile at PathSplitSource.java:96
22:03:45.394 INFO  FileInputFormat - Total input files to process : 1
22:03:45.395 INFO  FileInputFormat - Total input files to process : 1